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 2017/07/18 13:30:15 UTC
[JENKINS] Lucene-Solr-Tests-7.x - Build # 67 - Unstable
Build: https://builds.apache.org/job/Lucene-Solr-Tests-7.x/67/
2 tests failed.
FAILED: org.apache.solr.update.AutoCommitTest.testMaxDocs
Error Message:
Exception during query
Stack Trace:
java.lang.RuntimeException: Exception during query
at __randomizedtesting.SeedInfo.seed([FC3E4DC7BAFE367A:45BF9B18961432F0]:0)
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:878)
at org.apache.solr.update.AutoCommitTest.testMaxDocs(AutoCommitTest.java:225)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=1]
xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><result name="response" numFound="0" start="0"></result>
</response>
request was:q=id:14&qt=&start=0&rows=20&version=2.2
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:871)
... 40 more
FAILED: org.apache.solr.update.AutoCommitTest.testCommitWithin
Error Message:
Exception during query
Stack Trace:
java.lang.RuntimeException: Exception during query
at __randomizedtesting.SeedInfo.seed([FC3E4DC7BAFE367A:46EC22BF39D0D86F]:0)
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:878)
at org.apache.solr.update.AutoCommitTest.testCommitWithin(AutoCommitTest.java:353)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=1]
xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><result name="response" numFound="0" start="0"></result>
</response>
request was:q=id:529&qt=&start=0&rows=20&version=2.2
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:871)
... 40 more
Build Log:
[...truncated 11824 lines...]
[junit4] Suite: org.apache.solr.update.AutoCommitTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.update.AutoCommitTest_FC3E4DC7BAFE367A-001/init-core-data-001
[junit4] 2> 970942 WARN (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=866 numCloses=866
[junit4] 2> 970942 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 970943 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 970944 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
[junit4] 2> 970944 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/lib, /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 970969 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0
[junit4] 2> 970994 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ ] o.a.s.s.IndexSchema [null] Schema name=test
[junit4] 2> 971103 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 971153 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@74cfd1fe
[junit4] 2> 971158 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@74cfd1fe
[junit4] 2> 971158 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@74cfd1fe
[junit4] 2> 971160 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/lib, /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 971204 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0
[junit4] 2> 971224 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 971335 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 971340 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1, trusted=true
[junit4] 2> 971341 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@74cfd1fe
[junit4] 2> 971341 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 971341 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.update.AutoCommitTest_FC3E4DC7BAFE367A-001/init-core-data-001/]
[junit4] 2> 971342 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=12, maxMergedSegmentMB=59.8857421875, floorSegmentMB=1.15625, forceMergeDeletesPctAllowed=10.918429594007101, segmentsPerTier=14.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 971378 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 971379 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 971379 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 971379 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 971380 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=12.7705078125, floorSegmentMB=0.423828125, forceMergeDeletesPctAllowed=24.354643491910043, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8768479587619658
[junit4] 2> 971380 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@37146447[collection1] main]
[junit4] 2> 971381 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 971618 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 971647 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 971647 INFO (searcherExecutor-4060-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 971647 INFO (searcherExecutor-4060-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 971647 INFO (searcherExecutor-4060-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 971647 INFO (searcherExecutor-4060-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 971647 INFO (searcherExecutor-4060-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 971648 INFO (searcherExecutor-4060-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 971648 INFO (searcherExecutor-4060-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 971648 INFO (searcherExecutor-4060-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 971648 INFO (searcherExecutor-4060-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 971649 INFO (searcherExecutor-4060-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@37146447[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 971649 INFO (coreLoadExecutor-4059-thread-1) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1573264681442738176
[junit4] 2> 971652 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end
[junit4] 2> 971655 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMaxDocs
[junit4] 2> 971655 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 971656 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@55782dcb[collection1] realtime]
[junit4] 2> 971656 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:* (-9223372036854775807)} 0 1
[junit4] 2> 971657 ERROR (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ ] o.a.s.c.CorePropertiesLocator Couldn't load core descriptor from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/core.properties:java.nio.file.NoSuchFileException: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/core.properties
[junit4] 2> 971657 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/lib, /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 971683 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0
[junit4] 2> 971705 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 971858 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 971883 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1
[junit4] 2> 971904 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@74cfd1fe
[junit4] 2> 971904 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.update.AutoCommitTest_FC3E4DC7BAFE367A-001/init-core-data-001/]
[junit4] 2> 972002 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 972002 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 972003 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@674be407[collection1] main]
[junit4] 2> 972004 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 972004 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 972006 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 972006 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1573264681817079808
[junit4] 2> 972008 INFO (searcherExecutor-4065-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 972009 INFO (searcherExecutor-4065-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 972009 INFO (searcherExecutor-4065-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 972009 INFO (searcherExecutor-4065-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 972009 INFO (searcherExecutor-4065-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 972009 INFO (searcherExecutor-4065-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 972010 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=631093240, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 972010 INFO (searcherExecutor-4065-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 972010 INFO (searcherExecutor-4065-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 972011 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 972011 INFO (searcherExecutor-4065-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 972012 INFO (searcherExecutor-4065-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@674be407[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 972013 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3149c524[collection1] main]
[junit4] 2> 972013 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@71dda519
[junit4] 2> 972013 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=1910351129
[junit4] 2> 972020 INFO (searcherExecutor-4065-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3149c524[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 972023 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[0 (1573264681830711296)]} 0 4
[junit4] 2> 972023 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[1 (1573264681834905600)]} 0 4
[junit4] 2> 972024 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[2 (1573264681834905601)]} 0 5
[junit4] 2> 972024 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[3 (1573264681835954176)]} 0 5
[junit4] 2> 972024 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[4 (1573264681835954177)]} 0 5
[junit4] 2> 972024 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[5 (1573264681835954178)]} 0 5
[junit4] 2> 972025 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[6 (1573264681835954179)]} 0 6
[junit4] 2> 972029 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[7 (1573264681837002752)]} 0 10
[junit4] 2> 972029 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[8 (1573264681841197056)]} 0 10
[junit4] 2> 972029 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[9 (1573264681841197057)]} 0 10
[junit4] 2> 972030 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[10 (1573264681842245632)]} 0 11
[junit4] 2> 972030 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[11 (1573264681842245633)]} 0 11
[junit4] 2> 972030 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[12 (1573264681842245634)]} 0 11
[junit4] 2> 972030 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[13 (1573264681842245635)]} 0 11
[junit4] 2> 972031 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:1&qt=&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 972041 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[14 (1573264681844342784)]} 0 22
[junit4] 2> 972042 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[15 (1573264681853779968)]} 0 23
[junit4] 2> 972042 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:14&qt=&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 972042 ERROR (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.SolrTestCaseJ4 REQUEST FAILED: xpath=//result[@numFound=1]
[junit4] 2> xml response was: <?xml version="1.0" encoding="UTF-8"?>
[junit4] 2> <response>
[junit4] 2> <lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><result name="response" numFound="0" start="0"></result>
[junit4] 2> </response>
[junit4] 2>
[junit4] 2> request was:q=id:14&qt=&start=0&rows=20&version=2.2
[junit4] 2> 972042 ERROR (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.SolrTestCaseJ4 REQUEST FAILED: q=id:14&qt=&start=0&rows=20&version=2.2:java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=1]
[junit4] 2> xml response was: <?xml version="1.0" encoding="UTF-8"?>
[junit4] 2> <response>
[junit4] 2> <lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><result name="response" numFound="0" start="0"></result>
[junit4] 2> </response>
[junit4] 2>
[junit4] 2> request was:q=id:14&qt=&start=0&rows=20&version=2.2
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:871)
[junit4] 2> at org.apache.solr.update.AutoCommitTest.testMaxDocs(AutoCommitTest.java:225)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:498)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 972043 INFO (TEST-AutoCommitTest.testMaxDocs-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.SolrTestCaseJ4 ###Ending testMaxDocs
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=AutoCommitTest -Dtests.method=testMaxDocs -Dtests.seed=FC3E4DC7BAFE367A -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=is-IS -Dtests.timezone=Europe/Andorra -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.39s J1 | AutoCommitTest.testMaxDocs <<<
[junit4] > Throwable #1: java.lang.RuntimeException: Exception during query
[junit4] > at __randomizedtesting.SeedInfo.seed([FC3E4DC7BAFE367A:45BF9B18961432F0]:0)
[junit4] > at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:878)
[junit4] > at org.apache.solr.update.AutoCommitTest.testMaxDocs(AutoCommitTest.java:225)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] > Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=1]
[junit4] > xml response was: <?xml version="1.0" encoding="UTF-8"?>
[junit4] > <response>
[junit4] > <lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><result name="response" numFound="0" start="0"></result>
[junit4] > </response>
[junit4] > request was:q=id:14&qt=&start=0&rows=20&version=2.2
[junit4] > at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:871)
[junit4] > ... 40 more
[junit4] 2> 972045 INFO (commitScheduler-4068-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 972047 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.SolrTestCaseJ4 ###Starting testCommitWithin
[junit4] 2> 972050 INFO (commitScheduler-4068-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@25bcf69c[collection1] main]
[junit4] 2> 972051 INFO (searcherExecutor-4065-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@25bcf69c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.1.0):C16)))}
[junit4] 2> 972051 INFO (commitScheduler-4068-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 972051 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 972052 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@174365f4[collection1] realtime]
[junit4] 2> 972052 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:* (-9223372036854775807)} 0 4
[junit4] 2> 972052 ERROR (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.CorePropertiesLocator Couldn't load core descriptor from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/core.properties:java.nio.file.NoSuchFileException: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/core.properties
[junit4] 2> 972052 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/lib, /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 972077 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0
[junit4] 2> 972098 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 972243 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 972254 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1
[junit4] 2> 972270 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@74cfd1fe
[junit4] 2> 972271 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.update.AutoCommitTest_FC3E4DC7BAFE367A-001/init-core-data-001/]
[junit4] 2> 972333 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 972333 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 972335 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@203add8e[collection1] main]
[junit4] 2> 972335 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 972336 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 972339 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 972343 INFO (searcherExecutor-4069-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 972343 INFO (searcherExecutor-4069-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 972343 INFO (searcherExecutor-4069-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 972343 INFO (searcherExecutor-4069-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 972344 INFO (searcherExecutor-4069-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 972344 INFO (searcherExecutor-4069-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 972344 INFO (searcherExecutor-4069-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 972344 INFO (searcherExecutor-4069-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 972345 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=38, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=28.7666015625, floorSegmentMB=1.7998046875, forceMergeDeletesPctAllowed=10.79199692906615, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 972345 INFO (searcherExecutor-4069-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 972347 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 972349 INFO (searcherExecutor-4069-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@203add8e[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 972349 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@63ed59c8[collection1] main]
[junit4] 2> 972349 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@28551fe4
[junit4] 2> 972350 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=676667364
[junit4] 2> 972355 INFO (searcherExecutor-4069-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@63ed59c8[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 972356 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[529 (1573264682180935680)]} 0 2
[junit4] 2> 972356 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:529&qt=&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 972356 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[530 (1573264682184081408)]} 0 3
[junit4] 2> 972356 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:530&qt=&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 972357 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {delete=[529 (-1573264682185129984)]} 0 4
[junit4] 2> 972357 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:529&qt=&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 972357 ERROR (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.SolrTestCaseJ4 REQUEST FAILED: xpath=//result[@numFound=1]
[junit4] 2> xml response was: <?xml version="1.0" encoding="UTF-8"?>
[junit4] 2> <response>
[junit4] 2> <lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><result name="response" numFound="0" start="0"></result>
[junit4] 2> </response>
[junit4] 2>
[junit4] 2> request was:q=id:529&qt=&start=0&rows=20&version=2.2
[junit4] 2> 972358 ERROR (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.SolrTestCaseJ4 REQUEST FAILED: q=id:529&qt=&start=0&rows=20&version=2.2:java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=1]
[junit4] 2> xml response was: <?xml version="1.0" encoding="UTF-8"?>
[junit4] 2> <response>
[junit4] 2> <lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><result name="response" numFound="0" start="0"></result>
[junit4] 2> </response>
[junit4] 2>
[junit4] 2> request was:q=id:529&qt=&start=0&rows=20&version=2.2
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:871)
[junit4] 2> at org.apache.solr.update.AutoCommitTest.testCommitWithin(AutoCommitTest.java:353)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:498)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 972358 INFO (TEST-AutoCommitTest.testCommitWithin-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.SolrTestCaseJ4 ###Ending testCommitWithin
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=AutoCommitTest -Dtests.method=testCommitWithin -Dtests.seed=FC3E4DC7BAFE367A -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=is-IS -Dtests.timezone=Europe/Andorra -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.32s J1 | AutoCommitTest.testCommitWithin <<<
[junit4] > Throwable #1: java.lang.RuntimeException: Exception during query
[junit4] > at __randomizedtesting.SeedInfo.seed([FC3E4DC7BAFE367A:46EC22BF39D0D86F]:0)
[junit4] > at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:878)
[junit4] > at org.apache.solr.update.AutoCommitTest.testCommitWithin(AutoCommitTest.java:353)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] > Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=1]
[junit4] > xml response was: <?xml version="1.0" encoding="UTF-8"?>
[junit4] > <response>
[junit4] > <lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><result name="response" numFound="0" start="0"></result>
[junit4] > </response>
[junit4] > request was:q=id:529&qt=&start=0&rows=20&version=2.2
[junit4] > at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:871)
[junit4] > ... 40 more
[junit4] 2> 972367 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.SolrTestCaseJ4 ###Starting testMaxTime
[junit4] 2> 972368 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 972368 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@48856008[collection1] realtime]
[junit4] 2> 972368 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:* (-9223372036854775807)} 0 1
[junit4] 2> 972368 ERROR (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.CorePropertiesLocator Couldn't load core descriptor from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/core.properties:java.nio.file.NoSuchFileException: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/core.properties
[junit4] 2> 972369 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/lib, /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 973097 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0
[junit4] 2> 973130 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 973276 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 973284 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1
[junit4] 2> 973300 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@74cfd1fe
[junit4] 2> 973300 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/core/src/test-files/solr/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.update.AutoCommitTest_FC3E4DC7BAFE367A-001/init-core-data-001/]
[junit4] 2> 973354 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 973354 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 973356 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@43f2a647[collection1] main]
[junit4] 2> 973356 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 973357 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 973360 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 973363 INFO (searcherExecutor-4073-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 973363 INFO (searcherExecutor-4073-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 973363 INFO (searcherExecutor-4073-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 973363 INFO (searcherExecutor-4073-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 973363 INFO (searcherExecutor-4073-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 973364 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=12, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=96.2158203125, floorSegmentMB=1.064453125, forceMergeDeletesPctAllowed=28.457753112042315, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5110215696514285
[junit4] 2> 973364 INFO (searcherExecutor-4073-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 973364 INFO (searcherExecutor-4073-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 973365 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 973365 INFO (searcherExecutor-4073-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 973365 INFO (searcherExecutor-4073-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 973367 INFO (searcherExecutor-4073-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@43f2a647[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 973368 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1ad2b166[collection1] main]
[junit4] 2> 973368 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1ff9454
[junit4] 2> 973369 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=33526868
[junit4] 2> 973371 INFO (searcherExecutor-4073-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1ad2b166[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 973379 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[529 (1573264683253628928)]} 0 2
[junit4] 2> 973379 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:529&qt=&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 974879 INFO (commitScheduler-4076-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 974881 INFO (commitScheduler-4076-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@93fc35d[collection1] main]
[junit4] 2> 974881 INFO (commitScheduler-4076-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 974882 INFO (searcherExecutor-4073-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@93fc35d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(7.1.0):C1)))}
[junit4] 2> 974885 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[530 (1573264684835930112)]} 0 1509
[junit4] 2> 974885 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:529&qt=&start=0&rows=20&version=2.2} hits=1 status=0 QTime=0
[junit4] 2> 974886 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:530&qt=&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 974887 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{delete=[529 (-1573264684838027264)]} 0 0
[junit4] 2> 974887 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:529&qt=&start=0&rows=20&version=2.2} hits=1 status=0 QTime=0
[junit4] 2> 976385 INFO (commitScheduler-4076-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 976387 INFO (commitScheduler-4076-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@263eb6ea[collection1] main]
[junit4] 2> 976387 INFO (commitScheduler-4076-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 976388 INFO (searcherExecutor-4073-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@263eb6ea[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_3(7.1.0):C1)))}
[junit4] 2> 976389 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[550 (1573264686412988416)]} 0 3013
[junit4] 2> 976389 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:529&qt=&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 976390 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[500 (1573264686414036992)]} 0 3013
[junit4] 2> 976390 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[500 (1573264686414036993)]} 0 3013
[junit4] 2> 976390 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[500 (1573264686414036994)]} 0 3014
[junit4] 2> 976390 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[500 (1573264686414036995)]} 0 3014
[junit4] 2> 976390 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[500 (1573264686414036996)]} 0 3014
[junit4] 2> 976390 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[500 (1573264686414036997)]} 0 3014
[junit4] 2> 976391 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[500 (1573264686414036998)]} 0 3014
[junit4] 2> 976391 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[500 (1573264686415085568)]} 0 3014
[junit4] 2> 976391 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[500 (1573264686415085569)]} 0 3014
[junit4] 2> 976391 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[500 (1573264686415085570)]} 0 3014
[junit4] 2> 976391 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:500&qt=&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 977889 INFO (commitScheduler-4076-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 977891 INFO (commitScheduler-4076-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@18494902[collection1] main]
[junit4] 2> 977891 INFO (commitScheduler-4076-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 977893 INFO (searcherExecutor-4073-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@18494902[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_3(7.1.0):C1) Uninverting(_4(7.1.0):C11/9:delGen=1)))}
[junit4] 2> 977893 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[531 (1573264687990046720)]} 0 4517
[junit4] 2> 977894 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:500&qt=&start=0&rows=20&version=2.2} hits=1 status=0 QTime=0
[junit4] 2> 977894 INFO (TEST-AutoCommitTest.testMaxTime-seed#[FC3E4DC7BAFE367A]) [ x:collection1] o.a.s.SolrTestCaseJ4 ###Ending testMaxTime
[junit4] 2> 977894 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ x:collection1] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> 977894 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ x:collection1] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1330235027
[junit4] 2> 977894 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 977895 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 977896 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 977896 INFO (SUITE-AutoCommitTest-seed#[FC3E4DC7BAFE367A]-worker) [ x:collection1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 977896 INFO (coreCloseExecutor-4077-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@520a5abf
[junit4] 2> 977897 INFO (coreCloseExecutor-4077-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter close.
[junit4] 2> 977897 INFO (coreCloseExecutor-4077-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@79111444 commitCommandVersion:0
[junit4] 2> 977899 INFO (coreCloseExecutor-4077-thread-1-processing-x:collection1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=1376410303
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.update.AutoCommitTest_FC3E4DC7BAFE367A-001
[junit4] 2> NOTE: test params are: codec=FastCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST, chunkSize=4, maxDocsPerChunk=463, blockSize=371), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST, chunkSize=4, blockSize=371)), sim=RandomSimilarity(queryNorm=false): {}, locale=is-IS, timezone=Europe/Andorra
[junit4] 2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation 1.8.0_131 (64-bit)/cpus=4,threads=1,free=295709048,total=532152320
[junit4] 2> NOTE: All tests run in this JVM: [TestClusterProperties, TestFiltering, ZkCLITest, TestTestInjection, CloneFieldUpdateProcessorFactoryTest, SharedFSAutoReplicaFailoverUtilsTest, FileUtilsTest, DistributedQueryComponentCustomSortTest, LeaderInitiatedRecoveryOnCommitTest, ClassificationUpdateProcessorFactoryTest, RequestLoggingTest, TestConfigOverlay, TestJsonFacetRefinement, SOLR749Test, TestOrdValues, TestSolrJ, TestXIncludeConfig, TestInitParams, SliceStateTest, TestEmbeddedSolrServerSchemaAPI, TestStressCloudBlindAtomicUpdates, IndexSchemaTest, TestFuzzyAnalyzedSuggestions, TestPartialUpdateDeduplication, HdfsBasicDistributedZkTest, TestRandomRequestDistribution, TestQueryTypes, DistributedMLTComponentTest, SpellCheckComponentTest, HdfsRecoveryZkTest, OverseerTaskQueueTest, TestHashPartitioner, ConfigSetsAPITest, CollectionsAPIDistributedZkTest, SpatialRPTFieldTypeTest, ClusterStateUpdateTest, NoCacheHeaderTest, HdfsWriteToMultipleCollectionsTest, ZkSolrClientTest, BadComponentTest, TestInPlaceUpdatesStandalone, DocValuesTest, TestSchemalessBufferedUpdates, SuggestComponentTest, TestAuthorizationFramework, LargeFieldTest, TestSolrIndexConfig, TestShardHandlerFactory, TestMiniSolrCloudClusterSSL, TestHashQParserPlugin, ChaosMonkeySafeLeaderTest, QueryParsingTest, TestManagedSchemaThreadSafety, TestLockTree, SolrJmxReporterTest, HdfsThreadLeakTest, MoveReplicaTest, ParsingFieldUpdateProcessorsTest, CoreAdminCreateDiscoverTest, IndexSchemaRuntimeFieldTest, HdfsCollectionsAPIDistributedZkTest, DirectSolrConnectionTest, TestReqParamsAPI, CSVRequestHandlerTest, AlternateDirectoryTest, HLLUtilTest, ManagedSchemaRoundRobinCloudTest, TestSearchPerf, ShufflingReplicaListTransformerTest, DeleteNodeTest, DocValuesNotIndexedTest, FileBasedSpellCheckerTest, TestSolrQueryResponse, TestDocTermOrds, DistribJoinFromCollectionTest, CacheHeaderTest, TestStressRecovery, TestReloadDeadlock, TestCloudDeleteByQuery, LeaderElectionContextKeyTest, TestCoreDiscovery, TestGeoJSONResponseWriter, TestLegacyNumericUtils, InfoHandlerTest, LoggingHandlerTest, AsyncCallRequestStatusResponseTest, UUIDUpdateProcessorFallbackTest, TestComplexPhraseLeadingWildcard, ScriptEngineTest, TestFieldTypeCollectionResource, TestHighFrequencyDictionaryFactory, TestFastLRUCache, TestSolrCloudWithHadoopAuthPlugin, SecurityConfHandlerTest, TestTrieFacet, ActionThrottleTest, DistributedTermsComponentTest, RuleEngineTest, AutoScalingHandlerTest, SoftAutoCommitTest, TestLeaderElectionZkExpiry, PrimUtilsTest, CdcrReplicationDistributedZkTest, HdfsDirectoryFactoryTest, TestLRUCache, BasicFunctionalityTest, ConjunctionSolrSpellCheckerTest, TestPullReplica, TestSerializedLuceneMatchVersion, TestSolrCloudWithDelegationTokens, DeleteStatusTest, OverseerModifyCollectionTest, CoreAdminHandlerTest, TestDFISimilarityFactory, TestPayloadScoreQParserPlugin, BasicAuthIntegrationTest, TestApiFramework, TestAtomicUpdateErrorCases, OpenCloseCoreStressTest, OverseerTest, ShardRoutingTest, FullSolrCloudDistribCmdsTest, TestRandomFaceting, TestRandomDVFaceting, AutoCommitTest]
[junit4] Completed [308/728 (1!)] on J1 in 6.97s, 3 tests, 2 errors <<< FAILURES!
[...truncated 44693 lines...]
[JENKINS] Lucene-Solr-Tests-7.x - Build # 68 - Still Unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-7.x/68/
1 tests failed.
FAILED: org.apache.solr.client.solrj.TestSolrJErrorHandling.testWithXml
Error Message:
expected:<832> but was:<822>
Stack Trace:
java.lang.AssertionError: expected:<832> but was:<822>
at __randomizedtesting.SeedInfo.seed([97962D1F089FB2EC:3C7494E98A99AB81]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.client.solrj.TestSolrJErrorHandling.doThreads(TestSolrJErrorHandling.java:185)
at org.apache.solr.client.solrj.TestSolrJErrorHandling.doIt(TestSolrJErrorHandling.java:200)
at org.apache.solr.client.solrj.TestSolrJErrorHandling.testWithXml(TestSolrJErrorHandling.java:110)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 13751 lines...]
[junit4] Suite: org.apache.solr.client.solrj.TestSolrJErrorHandling
[junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/init-core-data-001
[junit4] 2> 62583 WARN (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=120 numCloses=120
[junit4] 2> 62584 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 62585 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=https://issues.apache.org/jira/browse/SOLR-5776)
[junit4] 2> 63592 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
[junit4] 2> 63592 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end
[junit4] 2> 63593 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-002/cores/core
[junit4] 2> 63594 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 63609 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5e0d9fef{/solr,null,AVAILABLE}
[junit4] 2> 63610 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2b4acaaf{HTTP/1.1,[http/1.1]}{127.0.0.1:41383}
[junit4] 2> 63610 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.e.j.s.Server Started @72925ms
[junit4] 2> 63610 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41383, configSetBaseDir=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001, coreRootDirectory=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-002/cores}
[junit4] 2> 63610 ERROR (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 63610 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.1.0
[junit4] 2> 63610 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 63610 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 63610 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-07-18T16:54:20.942Z
[junit4] 2> 63610 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/solr.xml
[junit4] 2> 64010 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001
[junit4] 2> 64010 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 64368 WARN (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../contrib/extraction/lib filtered by .*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../contrib/extraction/lib
[junit4] 2> 64416 WARN (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../dist filtered by solr-cell-\d.*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../dist
[junit4] 2> 64416 WARN (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../contrib/clustering/lib filtered by .*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../contrib/clustering/lib
[junit4] 2> 64416 WARN (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../dist filtered by solr-clustering-\d.*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../dist
[junit4] 2> 64417 WARN (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../contrib/langid/lib filtered by .*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../contrib/langid/lib
[junit4] 2> 64417 WARN (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../dist filtered by solr-langid-\d.*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../dist
[junit4] 2> 64418 WARN (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../contrib/ltr/lib filtered by .*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../contrib/ltr/lib
[junit4] 2> 64418 WARN (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../dist filtered by solr-ltr-\d.*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../dist
[junit4] 2> 64419 WARN (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../contrib/velocity/lib filtered by .*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../contrib/velocity/lib
[junit4] 2> 64419 WARN (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../dist filtered by solr-velocity-\d.*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/../../../../dist
[junit4] 2> 64468 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.SolrIndexConfig IndexWriter infoStream solr logging is enabled
[junit4] 2> 64514 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0
[junit4] 2> 64839 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=example
[junit4] 2> 66400 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.RestManager Registered ManagedResource impl org.apache.solr.rest.schema.analysis.ManagedWordSetResource for path /schema/analysis/stopwords/english
[junit4] 2> 66400 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.RestManager Registered ManagedResource impl org.apache.solr.rest.schema.analysis.ManagedSynonymGraphFilterFactory$SynonymManager for path /schema/analysis/synonyms/english
[junit4] 2> 66400 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.RestManager Added observer of type org.apache.solr.rest.schema.analysis.ManagedStopFilterFactory to existing ManagedResource /schema/analysis/stopwords/english
[junit4] 2> 66400 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.RestManager Added observer of type org.apache.solr.rest.schema.analysis.ManagedSynonymGraphFilterFactory to existing ManagedResource /schema/analysis/synonyms/english
[junit4] 2> 66401 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema example/1.6 with uniqueid field id
[junit4] 2> 66401 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.RestManager Added observer of type org.apache.solr.rest.schema.analysis.ManagedStopFilterFactory to existing ManagedResource /schema/analysis/stopwords/english
[junit4] 2> 66401 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.RestManager Added observer of type org.apache.solr.rest.schema.analysis.ManagedSynonymGraphFilterFactory to existing ManagedResource /schema/analysis/synonyms/english
[junit4] 2> 66401 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.RestManager Added observer of type org.apache.solr.rest.schema.analysis.ManagedStopFilterFactory to existing ManagedResource /schema/analysis/stopwords/english
[junit4] 2> 66401 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.RestManager Added observer of type org.apache.solr.rest.schema.analysis.ManagedSynonymGraphFilterFactory to existing ManagedResource /schema/analysis/synonyms/english
[junit4] 2> 66645 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1, trusted=true
[junit4] 2> 66646 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 66646 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/data/]
[junit4] 2> 66663 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-33-thread-1]: init: current segments file is "segments"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@5503dafa
[junit4] 2> 66663 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-33-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 66663 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-33-thread-1]: 0 msec to checkpoint
[junit4] 2> 66663 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: init: create=true
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]:
[junit4] 2> dir=MockDirectoryWrapper(RAMDirectory@55ae16c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@65c7ed2d)
[junit4] 2> index=
[junit4] 2> version=7.1.0
[junit4] 2> analyzer=org.apache.solr.update.SolrIndexConfig$DelayedSchemaAnalyzer
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> mergedSegmentWarmer=null
[junit4] 2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
[junit4] 2> commit=null
[junit4] 2> openMode=CREATE
[junit4] 2> similarity=org.apache.solr.search.similarities.SchemaSimilarityFactory$SchemaSimilarity
[junit4] 2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, maxMergeCount=-1, ioThrottle=true
[junit4] 2> codec=Lucene70
[junit4] 2> infoStream=org.apache.solr.update.LoggingInfoStream
[junit4] 2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
[junit4] 2> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@7e70062d
[junit4] 2> readerPooling=true
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2> commitOnClose=true
[junit4] 2> indexSort=null
[junit4] 2> writer=org.apache.solr.update.SolrIndexWriter@5b4d0727
[junit4] 2>
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: MMapDirectory.UNMAP_SUPPORTED=true
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: now flush at close
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: start flush: applyAllDeletes=true
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: index before flush
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-33-thread-1]: startFullFlush
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-33-thread-1]: coreLoadExecutor-33-thread-1 finishFullFlush success=true
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: now apply all deletes for all segments buffered updates bytesUsed=0 reader pool bytesUsed=0
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][coreLoadExecutor-33-thread-1]: waitApply: no deletes to apply
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [MS][coreLoadExecutor-33-thread-1]: initDynamicDefaults spins=false maxThreadCount=1 maxMergeCount=6
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [MS][coreLoadExecutor-33-thread-1]: updateMergeThreads ioThrottle=true targetMBPerSec=10240.0 MB/sec
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [MS][coreLoadExecutor-33-thread-1]: now merge
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [MS][coreLoadExecutor-33-thread-1]: index:
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [MS][coreLoadExecutor-33-thread-1]: no more merges pending; now return
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: waitForMerges
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: waitForMerges done
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: commit: start
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: commit: enter lock
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: commit: now prepare
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: prepareCommit: flush
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: index before flush
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-33-thread-1]: startFullFlush
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: now apply all deletes for all segments buffered updates bytesUsed=0 reader pool bytesUsed=0
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][coreLoadExecutor-33-thread-1]: waitApply: no deletes to apply
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-33-thread-1]: coreLoadExecutor-33-thread-1 finishFullFlush success=true
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: startCommit(): start
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: startCommit index= changeCount=2
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: startCommit: wrote pending segments file "pending_segments_1"
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: done all syncs: []
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: commit: pendingCommit != null
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: commit: done writing segments file "segments_1"
[junit4] 2> 66664 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-33-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 66665 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-33-thread-1]: 0 msec to checkpoint
[junit4] 2> 66665 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: commit: took 0.4 msec
[junit4] 2> 66665 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: commit: done
[junit4] 2> 66665 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: rollback
[junit4] 2> 66665 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: all running merges have aborted
[junit4] 2> 66665 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: rollback: done finish merges
[junit4] 2> 66665 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-33-thread-1]: abort
[junit4] 2> 66665 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-33-thread-1]: done abort success=true
[junit4] 2> 66665 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: rollback: infos=
[junit4] 2> 66665 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-33-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 66665 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-33-thread-1]: 0 msec to checkpoint
[junit4] 2> 66692 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.XSLTResponseWriter xsltCacheLifetimeSeconds=5
[junit4] 2> 67022 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 67022 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 67023 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 67023 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 67024 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-33-thread-1]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@5503dafa
[junit4] 2> 67024 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-33-thread-1]: init: load commit "segments_1"
[junit4] 2> 67024 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-33-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 67024 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-33-thread-1]: 0 msec to checkpoint
[junit4] 2> 67024 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: init: create=false
[junit4] 2> 67024 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]:
[junit4] 2> dir=MockDirectoryWrapper(RAMDirectory@55ae16c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@65c7ed2d)
[junit4] 2> index=
[junit4] 2> version=7.1.0
[junit4] 2> analyzer=org.apache.solr.update.SolrIndexConfig$DelayedSchemaAnalyzer
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> mergedSegmentWarmer=null
[junit4] 2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
[junit4] 2> commit=null
[junit4] 2> openMode=APPEND
[junit4] 2> similarity=org.apache.solr.search.similarities.SchemaSimilarityFactory$SchemaSimilarity
[junit4] 2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, maxMergeCount=-1, ioThrottle=true
[junit4] 2> codec=Lucene70
[junit4] 2> infoStream=org.apache.solr.update.LoggingInfoStream
[junit4] 2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
[junit4] 2> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@4efb288b
[junit4] 2> readerPooling=true
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2> commitOnClose=true
[junit4] 2> indexSort=null
[junit4] 2> writer=org.apache.solr.update.SolrIndexWriter@636f27f
[junit4] 2>
[junit4] 2> 67024 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: MMapDirectory.UNMAP_SUPPORTED=true
[junit4] 2> 67024 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: flush at getReader
[junit4] 2> 67024 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-33-thread-1]: startFullFlush
[junit4] 2> 67025 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: now apply all deletes for all segments buffered updates bytesUsed=0 reader pool bytesUsed=0
[junit4] 2> 67025 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][coreLoadExecutor-33-thread-1]: waitApply: no deletes to apply
[junit4] 2> 67025 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: incRefDeleter for NRT reader version=2 segments=
[junit4] 2> 67025 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: return reader version=2 reader=StandardDirectoryReader(segments_1:2:nrt)
[junit4] 2> 67025 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-33-thread-1]: coreLoadExecutor-33-thread-1 finishFullFlush success=true
[junit4] 2> 67025 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-33-thread-1]: getReader took 1 msec
[junit4] 2> 67025 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4951c10b[collection1] main]
[junit4] 2> 67040 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/conf
[junit4] 2> 67040 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage Loaded LinkedHashMap at path _rest_managed.json using file:dir=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/conf
[junit4] 2> 67040 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.ManagedResource Loaded initArgs {} for /rest/managed
[junit4] 2> 67040 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage Loaded LinkedHashMap at path _schema_analysis_stopwords_english.json using file:dir=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/conf
[junit4] 2> 67053 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.ManagedResource Loaded initArgs {ignoreCase=true} for /schema/analysis/stopwords/english
[junit4] 2> 67053 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.s.a.ManagedWordSetResource Loaded 35 words for /schema/analysis/stopwords/english
[junit4] 2> 67054 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.ManagedResource Notified 4 observers of /schema/analysis/stopwords/english
[junit4] 2> 67054 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage Loaded LinkedHashMap at path _schema_analysis_synonyms_english.json using file:dir=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/conf
[junit4] 2> 67054 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.ManagedResource Loaded initArgs {ignoreCase=true,format=solr} for /schema/analysis/synonyms/english
[junit4] 2> 67054 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.s.a.ManagedSynonymGraphFilterFactory Loaded 3 synonym mappings for /schema/analysis/synonyms/english
[junit4] 2> 67148 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.r.ManagedResource Notified 4 observers of /schema/analysis/synonyms/english
[junit4] 2> 67148 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 67148 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=default,field=text,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
[junit4] 2> 67149 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.h.c.SuggestComponent Initializing SuggestComponent
[junit4] 2> 67149 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.s.s.SolrSuggester init: {name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string,buildOnStartup=false}
[junit4] 2> 67149 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.s.s.SolrSuggester Dictionary loaded with params: {name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string,buildOnStartup=false}
[junit4] 2> 67149 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.h.c.QueryElevationComponent Loading QueryElevation from: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001/tempDir-001/collection1/conf/elevate.xml
[junit4] 2> 67245 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 67245 INFO (searcherExecutor-34-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.QuerySenderListener QuerySenderListener sending requests to Searcher@4951c10b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 67246 INFO (searcherExecutor-34-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=static+firstSearcher+warming+in+solrconfig.xml&distrib=false&event=firstSearcher} hits=0 status=0 QTime=0
[junit4] 2> 67246 INFO (searcherExecutor-34-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.QuerySenderListener QuerySenderListener done.
[junit4] 2> 67246 INFO (searcherExecutor-34-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 67246 INFO (searcherExecutor-34-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 67247 INFO (searcherExecutor-34-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4951c10b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 67247 INFO (coreLoadExecutor-33-thread-1) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1573280142672789504
[junit4] 2> 67301 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.SolrJettyTestBase Jetty Assigned Port#41383
[junit4] 2> 67708 INFO (TEST-TestSolrJErrorHandling.testRawSocket-seed#[97962D1F089FB2EC]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testRawSocket
[junit4] 2> 68093 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={}{} 0 60
[junit4] 2> 68093 ERROR (qtp763919426-151) [ x:collection1] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: ERROR: [doc=0] unknown field 'unknown_field_0'
[junit4] 2> at org.apache.solr.update.DocumentBuilder.toDocument(DocumentBuilder.java:214)
[junit4] 2> at org.apache.solr.update.AddUpdateCommand.getLuceneDocument(AddUpdateCommand.java:100)
[junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.updateDocument(DirectUpdateHandler2.java:957)
[junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.updateDocOrDocValues(DirectUpdateHandler2.java:948)
[junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.doNormalUpdate(DirectUpdateHandler2.java:329)
[junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.addDoc0(DirectUpdateHandler2.java:266)
[junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.addDoc(DirectUpdateHandler2.java:216)
[junit4] 2> at org.apache.solr.update.processor.RunUpdateProcessor.processAdd(RunUpdateProcessorFactory.java:67)
[junit4] 2> at org.apache.solr.update.processor.UpdateRequestProcessor.processAdd(UpdateRequestProcessor.java:55)
[junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.doLocalAdd(DistributedUpdateProcessor.java:990)
[junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.versionAdd(DistributedUpdateProcessor.java:1206)
[junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.processAdd(DistributedUpdateProcessor.java:752)
[junit4] 2> at org.apache.solr.update.processor.LogUpdateProcessorFactory$LogUpdateProcessor.processAdd(LogUpdateProcessorFactory.java:103)
[junit4] 2> at org.apache.solr.handler.loader.JsonLoader$SingleThreadedJsonLoader.handleAdds(JsonLoader.java:501)
[junit4] 2> at org.apache.solr.handler.loader.JsonLoader$SingleThreadedJsonLoader.processUpdate(JsonLoader.java:145)
[junit4] 2> at org.apache.solr.handler.loader.JsonLoader$SingleThreadedJsonLoader.load(JsonLoader.java:121)
[junit4] 2> at org.apache.solr.handler.loader.JsonLoader.load(JsonLoader.java:84)
[junit4] 2> at org.apache.solr.handler.UpdateRequestHandler$1.load(UpdateRequestHandler.java:97)
[junit4] 2> at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:68)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:177)
[junit4] 2> at org.apache.solr.core.SolrCore.execute(SolrCore.java:2473)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.execute(HttpSolrCall.java:720)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:526)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:378)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:322)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:395)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
[junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 71603 INFO (TEST-TestSolrJErrorHandling.testRawSocket-seed#[97962D1F089FB2EC]) [ ] o.a.s.c.s.TestSolrJErrorHandling BUFFER=HTTP/1.1 400 Bad Request
[junit4] 2> Date: Tue, 18 Jul 2017 16:54:25 GMT
[junit4] 2> Content-Type: text/plain;charset=utf-8
[junit4] 2> Content-Length: 245
[junit4] 2> Server: Jetty(9.3.14.v20161028)
[junit4] 2>
[junit4] 2> {"responseHeader":{"status":400,"QTime":73},"error":{"metadata":["error-class","org.apache.solr.common.SolrException","root-error-class","org.apache.solr.common.SolrException"],"msg":"ERROR: [doc=0] unknown field 'unknown_field_0'","code":400}}
[junit4] 2>
[junit4] 2> 71603 INFO (TEST-TestSolrJErrorHandling.testRawSocket-seed#[97962D1F089FB2EC]) [ ] o.a.s.c.s.TestSolrJErrorHandling RESPONSE BODY:HTTP/1.1 400 Bad Request
[junit4] 2> Date: Tue, 18 Jul 2017 16:54:25 GMT
[junit4] 2> Content-Type: text/plain;charset=utf-8
[junit4] 2> Content-Length: 245
[junit4] 2> Server: Jetty(9.3.14.v20161028)
[junit4] 2>
[junit4] 2> {"responseHeader":{"status":400,"QTime":73},"error":{"metadata":["error-class","org.apache.solr.common.SolrException","root-error-class","org.apache.solr.common.SolrException"],"msg":"ERROR: [doc=0] unknown field 'unknown_field_0'","code":400}}
[junit4] 2>
[junit4] 2> 71603 INFO (TEST-TestSolrJErrorHandling.testRawSocket-seed#[97962D1F089FB2EC]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testRawSocket
[junit4] 2> 71721 INFO (TEST-TestSolrJErrorHandling.testHttpURLConnection-seed#[97962D1F089FB2EC]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testHttpURLConnection
[junit4] 2> 72152 INFO (qtp763919426-149) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={}{} 0 0
[junit4] 2> 72152 ERROR (qtp763919426-149) [ x:collection1] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: ERROR: [doc=0] unknown field 'unknown_field_0'
[junit4] 2> at org.apache.solr.update.DocumentBuilder.toDocument(DocumentBuilder.java:214)
[junit4] 2> at org.apache.solr.update.AddUpdateCommand.getLuceneDocument(AddUpdateCommand.java:100)
[junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.updateDocument(DirectUpdateHandler2.java:957)
[junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.updateDocOrDocValues(DirectUpdateHandler2.java:948)
[junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.doNormalUpdate(DirectUpdateHandler2.java:329)
[junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.addDoc0(DirectUpdateHandler2.java:266)
[junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.addDoc(DirectUpdateHandler2.java:216)
[junit4] 2> at org.apache.solr.update.processor.RunUpdateProcessor.processAdd(RunUpdateProcessorFactory.java:67)
[junit4] 2> at org.apache.solr.update.processor.UpdateRequestProcessor.processAdd(UpdateRequestProcessor.java:55)
[junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.doLocalAdd(DistributedUpdateProcessor.java:990)
[junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.versionAdd(DistributedUpdateProcessor.java:1206)
[junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.processAdd(DistributedUpdateProcessor.java:752)
[junit4] 2> at org.apache.solr.update.processor.LogUpdateProcessorFactory$LogUpdateProcessor.processAdd(LogUpdateProcessorFactory.java:103)
[junit4] 2> at org.apache.solr.handler.loader.JsonLoader$SingleThreadedJsonLoader.handleAdds(JsonLoader.java:501)
[junit4] 2> at org.apache.solr.handler.loader.JsonLoader$SingleThreadedJsonLoader.processUpdate(JsonLoader.java:145)
[junit4] 2> at org.apache.solr.handler.loader.JsonLoader$SingleThreadedJsonLoader.load(JsonLoader.java:121)
[junit4] 2> at org.apache.solr.handler.loader.JsonLoader.load(JsonLoader.java:84)
[junit4] 2> at org.apache.solr.handler.UpdateRequestHandler$1.load(UpdateRequestHandler.java:97)
[junit4] 2> at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:68)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:177)
[junit4] 2> at org.apache.solr.core.SolrCore.execute(SolrCore.java:2473)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.execute(HttpSolrCall.java:720)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:526)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:378)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:322)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:395)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
[junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.execute(ExecuteProduceConsume.java:100)
[junit4] 2> at org.eclipse.jetty.io.ManagedSelector.run(ManagedSelector.java:147)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 73710 INFO (TEST-TestSolrJErrorHandling.testHttpURLConnection-seed#[97962D1F089FB2EC]) [ ] o.a.s.c.s.TestSolrJErrorHandling CODE=400
[junit4] 2> 73710 INFO (TEST-TestSolrJErrorHandling.testHttpURLConnection-seed#[97962D1F089FB2EC]) [ ] o.a.s.c.s.TestSolrJErrorHandling Attempting to get error stream.
[junit4] 2> 73712 INFO (TEST-TestSolrJErrorHandling.testHttpURLConnection-seed#[97962D1F089FB2EC]) [ ] o.a.s.c.s.TestSolrJErrorHandling RESPONSE BODY:{"responseHeader":{"status":400,"QTime":1},"error":{"metadata":["error-class","org.apache.solr.common.SolrException","root-error-class","org.apache.solr.common.SolrException"],"msg":"ERROR: [doc=0] unknown field 'unknown_field_0'","code":400}}
[junit4] 2>
[junit4] 2> 73712 INFO (TEST-TestSolrJErrorHandling.testHttpURLConnection-seed#[97962D1F089FB2EC]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testHttpURLConnection
[junit4] 2> 73731 INFO (TEST-TestSolrJErrorHandling.testWithXml-seed#[97962D1F089FB2EC]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testWithXml
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][qtp763919426-148]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][qtp763919426-148]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][qtp763919426-148]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][qtp763919426-148]: flush at getReader
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][qtp763919426-148]: startFullFlush
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][qtp763919426-148]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][qtp763919426-148]: qtp763919426-148: flush naked frozen global deletes
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][qtp763919426-148]: compressed 76 to 48 bytes (63.16%) for deletes/updates; private segment null
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][qtp763919426-148]: push new packet (delGen=1 numDeleteQuerys=1 bytesUsed=48), packetCount=1, bytesUsed=0.000 MB
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][qtp763919426-148]: flush: push buffered updates: delGen=1 numDeleteQuerys=1 bytesUsed=48
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][qtp763919426-148]: packet matches no segments
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][qtp763919426-148]: finished packet delGen=1 now completedDelGen=1
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][qtp763919426-148]: done apply del packet (delGen=1 numDeleteQuerys=1 bytesUsed=48) to 0 segments; 0 new deletes/updates; took 0.000 sec; 0 packets remain
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][qtp763919426-148]: now apply all deletes for all segments buffered updates bytesUsed=0 reader pool bytesUsed=0
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][qtp763919426-148]: waitApply: no deletes to apply
[junit4] 2> 73735 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][qtp763919426-148]: incRefDeleter for NRT reader version=2 segments=
[junit4] 2> 73736 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][qtp763919426-148]: return reader version=2 reader=StandardDirectoryReader(segments_1:2:nrt)
[junit4] 2> 73736 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][qtp763919426-148]: qtp763919426-148 finishFullFlush success=true
[junit4] 2> 73736 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][qtp763919426-148]: getReader took 1 msec
[junit4] 2> 73736 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][qtp763919426-148]: decRefDeleter for NRT reader version=2 segments=
[junit4] 2> 73736 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1573280149474902016)} 0 2
[junit4] 2> 73737 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][qtp763919426-151]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 73737 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][qtp763919426-151]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 73737 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][qtp763919426-151]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 73737 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][qtp763919426-151]: flush at getReader
[junit4] 2> 73737 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][qtp763919426-151]: startFullFlush
[junit4] 2> 73737 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][qtp763919426-151]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 73737 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][qtp763919426-151]: qtp763919426-151: flush naked frozen global deletes
[junit4] 2> 73737 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][qtp763919426-151]: compressed 76 to 48 bytes (63.16%) for deletes/updates; private segment null
[junit4] 2> 73737 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][qtp763919426-151]: push new packet (delGen=2 numDeleteQuerys=1 bytesUsed=48), packetCount=1, bytesUsed=0.000 MB
[junit4] 2> 73737 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][qtp763919426-151]: flush: push buffered updates: delGen=2 numDeleteQuerys=1 bytesUsed=48
[junit4] 2> 73737 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][qtp763919426-151]: packet matches no segments
[junit4] 2> 73738 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][qtp763919426-151]: finished packet delGen=2 now completedDelGen=2
[junit4] 2> 73738 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][qtp763919426-151]: done apply del packet (delGen=2 numDeleteQuerys=1 bytesUsed=48) to 0 segments; 0 new deletes/updates; took 0.000 sec; 0 packets remain
[junit4] 2> 73738 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][qtp763919426-151]: now apply all deletes for all segments buffered updates bytesUsed=0 reader pool bytesUsed=0
[junit4] 2> 73738 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][qtp763919426-151]: waitApply: no deletes to apply
[junit4] 2> 73738 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][qtp763919426-151]: incRefDeleter for NRT reader version=2 segments=
[junit4] 2> 73738 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][qtp763919426-151]: return reader version=2 reader=StandardDirectoryReader(segments_1:2:nrt)
[junit4] 2> 73738 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][qtp763919426-151]: qtp763919426-151 finishFullFlush success=true
[junit4] 2> 73738 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][qtp763919426-151]: getReader took 1 msec
[junit4] 2> 73738 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][qtp763919426-151]: decRefDeleter for NRT reader version=2 segments=
[junit4] 2> 73738 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1573280149478047744)} 0 1
[junit4] 2> 73946 INFO (qtp763919426-154) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149620654080)]} 0 73
[junit4] 2> 73946 INFO (qtp763919426-154) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 73953 INFO (qtp763919426-149) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149697200129)]} 0 45
[junit4] 2> 73953 INFO (qtp763919426-149) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 73953 INFO (qtp763919426-179) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149704540160)]} 0 30
[junit4] 2> 73953 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149704540162)]} 0 30
[junit4] 2> 73954 INFO (qtp763919426-151) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 73954 INFO (qtp763919426-153) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149704540164)]} 0 47
[junit4] 2> 73954 INFO (qtp763919426-153) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 73958 INFO (qtp763919426-181) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149705588737)]} 0 4
[junit4] 2> 73958 INFO (qtp763919426-181) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 73970 INFO (qtp763919426-179) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 73978 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149730754560)]} 0 72
[junit4] 2> 73978 INFO (qtp763919426-148) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 73986 INFO (qtp763919426-152) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149739143168)]} 0 81
[junit4] 2> 73987 INFO (qtp763919426-152) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74019 INFO (qtp763919426-183) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149773746176)]} 0 73
[junit4] 2> 74019 INFO (qtp763919426-183) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74035 INFO (qtp763919426-184) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149790523392)]} 0 21
[junit4] 2> 74035 INFO (qtp763919426-184) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74061 INFO (qtp763919426-155) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149712928768)]} 0 154
[junit4] 2> 74062 INFO (qtp763919426-155) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74114 INFO (qtp763919426-180) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149872312320)]} 0 0
[junit4] 2> 74133 INFO (qtp763919426-180) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74136 INFO (qtp763919426-153) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149895380992)]} 0 0
[junit4] 2> 74136 INFO (qtp763919426-153) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74137 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149897478144)]} 0 0
[junit4] 2> 74137 INFO (qtp763919426-151) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74166 INFO (qtp763919426-185) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149926838272)]} 0 29
[junit4] 2> 74166 INFO (qtp763919426-185) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74186 INFO (qtp763919426-152) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149948858368)]} 0 0
[junit4] 2> 74187 INFO (qtp763919426-152) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74187 INFO (qtp763919426-184) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149948858370)]} 0 0
[junit4] 2> 74187 INFO (qtp763919426-184) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74188 INFO (qtp763919426-179) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149949906945)]} 0 1
[junit4] 2> 74188 INFO (qtp763919426-179) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74235 INFO (qtp763919426-154) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280149968781312)]} 0 30
[junit4] 2> 74236 INFO (qtp763919426-154) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74238 INFO (qtp763919426-181) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150002335744)]} 0 51
[junit4] 2> 74238 INFO (qtp763919426-181) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74251 INFO (qtp763919426-149) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150015967232)]} 0 17
[junit4] 2> 74251 INFO (qtp763919426-149) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74251 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150017015809)]} 0 0
[junit4] 2> 74251 INFO (qtp763919426-148) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74267 INFO (qtp763919426-180) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150033793024)]} 0 0
[junit4] 2> 74268 INFO (qtp763919426-180) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74286 INFO (qtp763919426-155) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150053715968)]} 0 0
[junit4] 2> 74286 INFO (qtp763919426-155) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74410 INFO (qtp763919426-185) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150182690816)]} 0 0
[junit4] 2> 74410 INFO (qtp763919426-185) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74414 INFO (qtp763919426-149) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150186885120)]} 0 0
[junit4] 2> 74414 INFO (qtp763919426-149) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74427 INFO (qtp763919426-183) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150200516608)]} 0 0
[junit4] 2> 74427 INFO (qtp763919426-183) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74430 INFO (qtp763919426-180) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150204710912)]} 0 0
[junit4] 2> 74430 INFO (qtp763919426-180) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74433 INFO (qtp763919426-152) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150207856640)]} 0 0
[junit4] 2> 74463 INFO (qtp763919426-152) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74460 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150235119616)]} 0 0
[junit4] 2> 74478 INFO (qtp763919426-148) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74495 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150272868352)]} 0 0
[junit4] 2> 74495 INFO (qtp763919426-151) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74515 INFO (qtp763919426-184) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150293839872)]} 0 0
[junit4] 2> 74596 INFO (qtp763919426-184) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74657 INFO (qtp763919426-179) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150425960448)]} 0 16
[junit4] 2> 74657 INFO (qtp763919426-179) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74665 INFO (qtp763919426-153) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150451126272)]} 0 20
[junit4] 2> 74665 INFO (qtp763919426-153) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74674 INFO (qtp763919426-155) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150460563456)]} 0 55
[junit4] 2> 74674 INFO (qtp763919426-155) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74689 INFO (qtp763919426-180) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150459514880)]} 0 45
[junit4] 2> 74690 INFO (qtp763919426-180) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74690 INFO (qtp763919426-149) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150477340672)]} 0 0
[junit4] 2> 74690 INFO (qtp763919426-149) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74727 INFO (qtp763919426-184) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150515089408)]} 0 0
[junit4] 2> 74727 INFO (qtp763919426-184) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74746 INFO (qtp763919426-181) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150501457920)]} 0 33
[junit4] 2> 74779 INFO (qtp763919426-153) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150570663936)]} 0 12
[junit4] 2> 74794 INFO (qtp763919426-153) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74763 INFO (qtp763919426-185) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150553886720)]} 0 0
[junit4] 2> 74795 INFO (qtp763919426-185) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74807 INFO (qtp763919426-181) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74808 INFO (qtp763919426-155) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150601072640)]} 0 0
[junit4] 2> 74808 INFO (qtp763919426-155) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74810 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150603169792)]} 0 0
[junit4] 2> 74810 INFO (qtp763919426-151) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74759 INFO (qtp763919426-154) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150549692416)]} 0 0
[junit4] 2> 74811 INFO (qtp763919426-154) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74871 INFO (qtp763919426-152) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150665035776)]} 0 2
[junit4] 2> 74872 INFO (qtp763919426-152) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74885 INFO (qtp763919426-179) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150681812992)]} 0 0
[junit4] 2> 74885 INFO (qtp763919426-179) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74983 INFO (qtp763919426-183) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150783524864)]} 0 0
[junit4] 2> 74983 INFO (qtp763919426-183) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74997 INFO (qtp763919426-149) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150799253504)]} 0 0
[junit4] 2> 74997 INFO (qtp763919426-149) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 74999 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150753116160)]} 0 45
[junit4] 2> 74999 INFO (qtp763919426-148) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75032 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150834905088)]} 0 0
[junit4] 2> 75032 INFO (qtp763919426-151) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75035 INFO (qtp763919426-181) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150762553344)]} 0 73
[junit4] 2> 75035 INFO (qtp763919426-181) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75062 INFO (qtp763919426-184) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150867410944)]} 0 0
[junit4] 2> 75062 INFO (qtp763919426-184) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75064 INFO (qtp763919426-180) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150869508096)]} 0 0
[junit4] 2> 75064 INFO (qtp763919426-180) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75150 INFO (qtp763919426-155) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150959685632)]} 0 52
[junit4] 2> 75150 INFO (qtp763919426-155) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75165 INFO (qtp763919426-179) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280150890479616)]} 0 81
[junit4] 2> 75165 INFO (qtp763919426-179) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75190 INFO (qtp763919426-154) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151001628672)]} 0 0
[junit4] 2> 75190 INFO (qtp763919426-154) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75198 INFO (qtp763919426-153) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151010017280)]} 0 0
[junit4] 2> 75198 INFO (qtp763919426-153) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75243 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151057203200)]} 0 0
[junit4] 2> 75243 INFO (qtp763919426-148) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75246 INFO (qtp763919426-185) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151059300352)]} 0 0
[junit4] 2> 75246 INFO (qtp763919426-185) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75277 INFO (qtp763919426-152) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151092854784)]} 0 0
[junit4] 2> 75278 INFO (qtp763919426-152) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75319 INFO (qtp763919426-181) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151136894976)]} 0 0
[junit4] 2> 75338 INFO (qtp763919426-154) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151155769344)]} 0 0
[junit4] 2> 75338 INFO (qtp763919426-154) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75354 INFO (qtp763919426-181) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75374 INFO (qtp763919426-183) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151194566656)]} 0 0
[junit4] 2> 75374 INFO (qtp763919426-183) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75434 INFO (qtp763919426-149) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151257481216)]} 0 0
[junit4] 2> 75435 INFO (qtp763919426-149) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75439 INFO (qtp763919426-180) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151262724096)]} 0 0
[junit4] 2> 75439 INFO (qtp763919426-180) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75455 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151279501312)]} 0 0
[junit4] 2> 75455 INFO (qtp763919426-151) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75506 INFO (qtp763919426-184) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151332978688)]} 0 0
[junit4] 2> 75506 INFO (qtp763919426-184) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75520 INFO (qtp763919426-155) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151347658752)]} 0 0
[junit4] 2> 75520 INFO (qtp763919426-155) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75589 INFO (qtp763919426-152) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151420010496)]} 0 0
[junit4] 2> 75589 INFO (qtp763919426-152) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75601 INFO (qtp763919426-153) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151432593408)]} 0 0
[junit4] 2> 75601 INFO (qtp763919426-153) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75869 INFO (qtp763919426-185) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151713611776)]} 0 0
[junit4] 2> 75870 INFO (qtp763919426-185) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75887 INFO (qtp763919426-148) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151731437568)]} 0 0
[junit4] 2> 75887 INFO (qtp763919426-148) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75962 INFO (qtp763919426-154) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151811129344)]} 0 16
[junit4] 2> 75963 INFO (qtp763919426-154) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75978 INFO (qtp763919426-183) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151827906560)]} 0 41
[junit4] 2> 75979 INFO (qtp763919426-183) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 75996 INFO (qtp763919426-180) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151780720640)]} 0 62
[junit4] 2> 75996 INFO (qtp763919426-180) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 76012 INFO (qtp763919426-149) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151862509568)]} 0 0
[junit4] 2> 76012 INFO (qtp763919426-149) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 76047 INFO (qtp763919426-151) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151900258304)]} 0 0
[junit4] 2> 76055 INFO (qtp763919426-181) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151908646912)]} 0 0
[junit4] 2> 76068 INFO (qtp763919426-181) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 76077 INFO (qtp763919426-152) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151931715584)]} 0 0
[junit4] 2> 76078 INFO (qtp763919426-152) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 76109 INFO (qtp763919426-179) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280151965270016)]} 0 0
[junit4] 2> 76110 INFO (qtp763919426-179) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 76141 INFO (qtp763919426-151) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 76143 INFO (qtp763919426-184) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280152000921600)]} 0 0
[junit4] 2> 76143 INFO (qtp763919426-184) [ x:collection1] o.a.s.h.RequestHandlerBase Ignoring exception matching ignore_exception
[junit4] 2> 76152 INFO (qtp763919426-185) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[test (1573280152010358784)]} 0 0
[junit4] 2> 76218 INFO (qtp763919426-185) [ x:collection1] o.a.s.h.RequestHa
[...truncated too long message...]
] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=id:test&fl=count_i&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4] 2> 126973 INFO (qtp763919426-184) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1573280205300039680,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 126973 INFO (qtp763919426-184) [ x:collection1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 126986 INFO (qtp763919426-184) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 126986 INFO (qtp763919426-184) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 13
[junit4] 2> 126987 INFO (qtp763919426-184) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=id:test&fl=count_i&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4] 2> 126987 INFO (TEST-TestSolrJErrorHandling.testWithBinary-seed#[97962D1F089FB2EC]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testWithBinary
[junit4] 2> 127014 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@2b4acaaf{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 127014 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1148478429
[junit4] 2> 127014 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 127014 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 127015 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 127015 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 127015 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@333ef797
[junit4] 2> 127015 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: now flush at close
[junit4] 2> 127015 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: start flush: applyAllDeletes=true
[junit4] 2> 127015 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: index before flush _6(7.1.0):C266/265:delGen=1
[junit4] 2> 127015 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][coreCloseExecutor-39-thread-1]: startFullFlush
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][coreCloseExecutor-39-thread-1]: coreCloseExecutor-39-thread-1 finishFullFlush success=true
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: now apply all deletes for all segments buffered updates bytesUsed=0 reader pool bytesUsed=0
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][coreCloseExecutor-39-thread-1]: waitApply: no deletes to apply
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [MS][coreCloseExecutor-39-thread-1]: updateMergeThreads ioThrottle=true targetMBPerSec=10240.0 MB/sec
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [MS][coreCloseExecutor-39-thread-1]: now merge
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [MS][coreCloseExecutor-39-thread-1]: index: _6(7.1.0):C266/265:delGen=1
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [MS][coreCloseExecutor-39-thread-1]: no more merges pending; now return
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: waitForMerges
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: waitForMerges done
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: commit: start
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: commit: enter lock
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: commit: now prepare
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: prepareCommit: flush
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: index before flush _6(7.1.0):C266/265:delGen=1
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][coreCloseExecutor-39-thread-1]: startFullFlush
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: now apply all deletes for all segments buffered updates bytesUsed=0 reader pool bytesUsed=0
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [BD][coreCloseExecutor-39-thread-1]: waitApply: no deletes to apply
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][coreCloseExecutor-39-thread-1]: coreCloseExecutor-39-thread-1 finishFullFlush success=true
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: startCommit(): start
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: skip startCommit(): no changes pending
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: commit: pendingCommit == null; skip
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: commit: took 0.2 msec
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: commit: done
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: rollback
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: all running merges have aborted
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: rollback: done finish merges
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][coreCloseExecutor-39-thread-1]: abort
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [DW][coreCloseExecutor-39-thread-1]: done abort success=true
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-39-thread-1]: rollback: infos=_6(7.1.0):C266/265:delGen=1
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreCloseExecutor-39-thread-1]: now checkpoint "_6(7.1.0):C266/265:delGen=1" [1 segments ; isCommit = false]
[junit4] 2> 127016 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreCloseExecutor-39-thread-1]: 0 msec to checkpoint
[junit4] 2> 127031 INFO (coreCloseExecutor-39-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=859764631
[junit4] 2> 127145 INFO (SUITE-TestSolrJErrorHandling-seed#[97962D1F089FB2EC]-worker) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5e0d9fef{/solr,null,UNAVAILABLE}
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J1/temp/solr.client.solrj.TestSolrJErrorHandling_97962D1F089FB2EC-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=242, maxMBSortInHeap=7.520520875060283, sim=RandomSimilarity(queryNorm=true): {}, locale=mk, timezone=America/Caracas
[junit4] 2> NOTE: Linux 4.4.0-83-generic amd64/Oracle Corporation 1.8.0_131 (64-bit)/cpus=4,threads=1,free=134753264,total=300941312
[junit4] 2> NOTE: All tests run in this JVM: [GetByIdTest, SolrExampleStreamingBinaryTest, TestToleratedUpdateError, ClientUtilsTest, TestSolrJErrorHandling]
[junit4] Completed [25/135 (1!)] on J1 in 64.73s, 4 tests, 1 failure <<< FAILURES!
[...truncated 42785 lines...]