You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2016/11/22 17:25:03 UTC
[JENKINS] Lucene-Solr-master-MacOSX (64bit/jdk1.8.0) - Build # 3662
- Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/3662/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds
Error Message:
soft529 wasn't fast enough
Stack Trace:
java.lang.AssertionError: soft529 wasn't fast enough
at __randomizedtesting.SeedInfo.seed([E291643744082204:B3459DB7F57B12A3]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNotNull(Assert.java:526)
at org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:111)
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:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:811)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:462)
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:367)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 10575 lines...]
[junit4] Suite: org.apache.solr.update.SoftAutoCommitTest
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest_E291643744082204-001/init-core-data-001
[junit4] 2> 0 INFO (SUITE-SoftAutoCommitTest-seed#[E291643744082204]-worker) [ ] o.e.j.u.log Logging initialized @6057ms
[junit4] 2> 21 INFO (SUITE-SoftAutoCommitTest-seed#[E291643744082204]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 65 INFO (SUITE-SoftAutoCommitTest-seed#[E291643744082204]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
[junit4] 2> 345 INFO (SUITE-SoftAutoCommitTest-seed#[E291643744082204]-worker) [ ] o.a.s.c.SolrResourceLoader Using system property solr.solr.home: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr
[junit4] 2> 361 INFO (SUITE-SoftAutoCommitTest-seed#[E291643744082204]-worker) [ ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib, /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 1426 INFO (SUITE-SoftAutoCommitTest-seed#[E291643744082204]-worker) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1800 INFO (SUITE-SoftAutoCommitTest-seed#[E291643744082204]-worker) [ ] o.a.s.s.IndexSchema [null] Schema name=test
[junit4] 2> 4779 WARN (SUITE-SoftAutoCommitTest-seed#[E291643744082204]-worker) [ ] o.a.s.s.IndexSchema [null] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 4828 INFO (SUITE-SoftAutoCommitTest-seed#[E291643744082204]-worker) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 7929 INFO (coreLoadExecutor-6-thread-1) [ ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib, /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 8090 INFO (coreLoadExecutor-6-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 8173 INFO (coreLoadExecutor-6-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 8407 WARN (coreLoadExecutor-6-thread-1) [ ] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 8412 INFO (coreLoadExecutor-6-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 8476 INFO (coreLoadExecutor-6-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1
[junit4] 2> 9051 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest_E291643744082204-001/init-core-data-001/]
[junit4] 2> 9312 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 14441 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 14441 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 14477 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 14477 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 14479 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=10.85546875, floorSegmentMB=1.27734375, forceMergeDeletesPctAllowed=15.417164278324558, segmentsPerTier=14.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.18809989947688957
[junit4] 2> 14619 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@545ec0ee[collection1] main]
[junit4] 2> 14926 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 15270 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 15633 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 15889 INFO (searcherExecutor-7-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 15895 INFO (searcherExecutor-7-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 15896 INFO (searcherExecutor-7-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 15896 INFO (searcherExecutor-7-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 15899 INFO (searcherExecutor-7-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 15905 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1551714547658653696
[junit4] 2> 15911 INFO (searcherExecutor-7-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 15916 INFO (searcherExecutor-7-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 15919 INFO (searcherExecutor-7-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 15926 INFO (searcherExecutor-7-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 15927 INFO (searcherExecutor-7-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@545ec0ee[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 15934 INFO (SUITE-SoftAutoCommitTest-seed#[E291643744082204]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end
[junit4] 2> 15969 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeMixedAdds
[junit4] 2> 15972 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib, /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 16132 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 16184 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 16345 WARN (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ ] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 16350 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 16392 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1
[junit4] 2> 16394 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest_E291643744082204-001/init-core-data-001/]
[junit4] 2> 16423 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 16424 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 16427 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5bbe45d8[collection1] main]
[junit4] 2> 16428 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 16430 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 16449 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 16450 INFO (searcherExecutor-12-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 16451 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1551714548231176192
[junit4] 2> 16452 INFO (searcherExecutor-12-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 16452 INFO (searcherExecutor-12-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 16452 INFO (searcherExecutor-12-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 16453 INFO (searcherExecutor-12-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 16455 INFO (searcherExecutor-12-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 16456 INFO (searcherExecutor-12-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 16458 INFO (searcherExecutor-12-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 16459 INFO (searcherExecutor-12-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 16459 INFO (searcherExecutor-12-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5bbe45d8[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 16465 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=34, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 16468 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 16468 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@745bc3ef[collection1] main]
[junit4] 2> 16471 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@53bd364b
[junit4] 2> 16488 INFO (searcherExecutor-12-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@745bc3ef[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 17643 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[529 (1551714548913799168)]} 0 1161
[junit4] 2> 18137 INFO (commitScheduler-15-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> 18694 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeMixedAdds
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SoftAutoCommitTest -Dtests.method=testSoftAndHardCommitMaxTimeMixedAdds -Dtests.seed=E291643744082204 -Dtests.slow=true -Dtests.locale=fr-CA -Dtests.timezone=Europe/Zagreb -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 2.79s J0 | SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds <<<
[junit4] > Throwable #1: java.lang.AssertionError: soft529 wasn't fast enough
[junit4] > at __randomizedtesting.SeedInfo.seed([E291643744082204:B3459DB7F57B12A3]:0)
[junit4] > at org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:111)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 18730 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeDelete
[junit4] 2> 18731 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib, /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 18835 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 18845 INFO (commitScheduler-14-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 18903 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 19151 WARN (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 19154 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 19159 INFO (commitScheduler-15-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@69f9bd6b[collection1] main]
[junit4] 2> 19163 INFO (searcherExecutor-12-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@69f9bd6b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):c1)))}
[junit4] 2> 19164 INFO (commitScheduler-14-thread-1) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@fcc658d
[junit4] 2> 19164 INFO (commitScheduler-15-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 19182 INFO (commitScheduler-14-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5ff15167[collection1] main]
[junit4] 2> 19183 INFO (commitScheduler-14-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 19183 INFO (searcherExecutor-12-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5ff15167[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):c1)))}
[junit4] 2> 19187 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1
[junit4] 2> 19188 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest_E291643744082204-001/init-core-data-001/]
[junit4] 2> 19223 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 19223 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 19224 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@231a7722[collection1] main]
[junit4] 2> 19225 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 19229 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 19247 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 19247 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 19251 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 19251 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 19251 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 19253 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 19258 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 19269 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 19276 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 19287 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 19288 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@231a7722[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):c1)))}
[junit4] 2> 19312 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=34, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=37.107421875, floorSegmentMB=1.48046875, forceMergeDeletesPctAllowed=10.072061210110576, segmentsPerTier=41.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 19317 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 19321 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@369aec29[collection1] main]
[junit4] 2> 19321 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3038ce73
[junit4] 2> 19321 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@369aec29[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):c1)))}
[junit4] 2> 19330 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[529 (1551714551245832192)]} 0 4
[junit4] 2> 19331 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 19332 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@55a0348e
[junit4] 2> 19413 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@22342fbf[collection1] main]
[junit4] 2> 19419 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@22342fbf[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(7.0.0):c1)))}
[junit4] 2> 19421 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 19421 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 89
[junit4] 2> 19426 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{delete=[529 (-1551714551347544064)]} 0 2
[junit4] 2> 19928 INFO (commitScheduler-19-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> 19934 INFO (commitScheduler-19-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@47315ae6[collection1] main]
[junit4] 2> 19934 INFO (commitScheduler-19-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 19935 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@47315ae6[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 19942 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[550 (1551714551886512128)]} 0 5
[junit4] 2> 20447 INFO (commitScheduler-19-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> 20478 INFO (commitScheduler-19-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4e0630e8[collection1] main]
[junit4] 2> 20478 INFO (commitScheduler-19-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 20479 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4e0630e8[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(7.0.0):c1)))}
[junit4] 2> 20632 INFO (commitScheduler-18-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 20633 INFO (commitScheduler-18-thread-1) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@55a0348e
[junit4] 2> 20636 INFO (commitScheduler-18-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@743acead[collection1] main]
[junit4] 2> 20638 INFO (commitScheduler-18-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 20638 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@743acead[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(7.0.0):c1)))}
[junit4] 2> 22638 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E291643744082204]) [ x:collection1] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeDelete
[junit4] 2> 22643 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeRapidAdds
[junit4] 2> 22644 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib, /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 22732 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 22799 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 22992 WARN (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 22998 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 23034 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1
[junit4] 2> 23036 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest_E291643744082204-001/init-core-data-001/]
[junit4] 2> 23067 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 23067 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 23068 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@58bdf76c[collection1] main]
[junit4] 2> 23077 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 23091 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 23115 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 23116 INFO (searcherExecutor-20-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 23125 INFO (searcherExecutor-20-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 23125 INFO (searcherExecutor-20-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 23125 INFO (searcherExecutor-20-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 23135 INFO (searcherExecutor-20-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 23136 INFO (searcherExecutor-20-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 23148 INFO (searcherExecutor-20-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 23150 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=11, maxMergedSegmentMB=97.525390625, floorSegmentMB=1.5888671875, forceMergeDeletesPctAllowed=4.749850345915162, segmentsPerTier=33.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5251568337719085
[junit4] 2> 23155 INFO (searcherExecutor-20-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 23161 INFO (searcherExecutor-20-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 23162 INFO (searcherExecutor-20-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@58bdf76c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(7.0.0):c1)))}
[junit4] 2> 23164 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 23169 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@33a6c7d[collection1] main]
[junit4] 2> 23170 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@13a52698
[junit4] 2> 23170 INFO (searcherExecutor-20-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@33a6c7d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(7.0.0):c1)))}
[junit4] 2> 23180 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5000 (1551714555280752640)]} 0 6
[junit4] 2> 23182 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5001 (1551714555288092672)]} 0 1
[junit4] 2> 23184 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5002 (1551714555290189824)]} 0 1
[junit4] 2> 23186 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5003 (1551714555292286976)]} 0 1
[junit4] 2> 23189 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5004 (1551714555295432704)]} 0 1
[junit4] 2> 23190 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E291643744082204]) [ x:collection1] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeRapidAdds
[junit4] 2> 23191 INFO (SUITE-SoftAutoCommitTest-seed#[E291643744082204]-worker) [ x:collection1] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> 23191 INFO (SUITE-SoftAutoCommitTest-seed#[E291643744082204]-worker) [ x:collection1] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1511279125
[junit4] 2> 23194 INFO (coreCloseExecutor-24-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@6f68a292
[junit4] 2> 23202 INFO (coreCloseExecutor-24-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter close.
[junit4] 2> 23204 INFO (coreCloseExecutor-24-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@76b1877c
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest_E291643744082204-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70), sim=RandomSimilarity(queryNorm=true): {}, locale=fr-CA, timezone=Europe/Zagreb
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_102 (64-bit)/cpus=3,threads=1,free=21256288,total=54853632
[junit4] 2> NOTE: All tests run in this JVM: [SoftAutoCommitTest]
[junit4] Completed [3/653 (1!)] on J0 in 26.48s, 3 tests, 1 failure <<< FAILURES!
[...truncated 64451 lines...]
[JENKINS] Lucene-Solr-master-MacOSX (64bit/jdk1.8.0) - Build # 3664
- Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/3664/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication
Error Message:
expected:<1> but was:<0>
Stack Trace:
java.lang.AssertionError: expected:<1> but was:<0>
at __randomizedtesting.SeedInfo.seed([390D5032CECC6C9C:CE7EBE6A0824C37A]: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.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication(TestReplicationHandler.java:1329)
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:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:811)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:462)
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:367)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11638 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/init-core-data-001
[junit4] 2> 1853624 INFO (SUITE-TestReplicationHandler-seed#[390D5032CECC6C9C]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 1853626 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testRateLimitedReplication
[junit4] 2> 1853627 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/collection1
[junit4] 2> 1853661 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1853665 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@369de82a{/solr,null,AVAILABLE}
[junit4] 2> 1853666 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Started ServerConnector@36d8bfca{HTTP/1.1,[http/1.1]}{127.0.0.1:51730}
[junit4] 2> 1853666 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server Started @1863189ms
[junit4] 2> 1853666 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=51730}
[junit4] 2> 1853666 ERROR (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1853666 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 1853666 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1853667 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1853667 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-23T12:35:21.852Z
[junit4] 2> 1853669 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/solr.xml
[junit4] 2> 1853699 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/.
[junit4] 2> 1853699 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1853724 WARN (coreLoadExecutor-6706-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 1853725 INFO (coreLoadExecutor-6706-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1853751 INFO (coreLoadExecutor-6706-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1853756 INFO (coreLoadExecutor-6706-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1853762 INFO (coreLoadExecutor-6706-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/./collection1
[junit4] 2> 1853763 INFO (coreLoadExecutor-6706-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/./collection1/data/]
[junit4] 2> 1853769 INFO (coreLoadExecutor-6706-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=11, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6739785279818982]
[junit4] 2> 1853787 INFO (coreLoadExecutor-6706-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1853787 INFO (coreLoadExecutor-6706-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1853787 INFO (coreLoadExecutor-6706-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=7.009765625, floorSegmentMB=1.6494140625, forceMergeDeletesPctAllowed=2.6814954169616456, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5494746280103859
[junit4] 2> 1853787 INFO (coreLoadExecutor-6706-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@40c8ca3e[collection1] main]
[junit4] 2> 1853788 INFO (coreLoadExecutor-6706-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/collection1/conf
[junit4] 2> 1853789 INFO (coreLoadExecutor-6706-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 1853789 INFO (coreLoadExecutor-6706-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1853789 INFO (searcherExecutor-6707-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@40c8ca3e[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1854207 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/collection1
[junit4] 2> 1854216 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1854219 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6f1dff06{/solr,null,AVAILABLE}
[junit4] 2> 1854220 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Started ServerConnector@50d90001{HTTP/1.1,[http/1.1]}{127.0.0.1:51731}
[junit4] 2> 1854220 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server Started @1863743ms
[junit4] 2> 1854220 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/collection1/data, hostContext=/solr, hostPort=51731}
[junit4] 2> 1854220 ERROR (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1854220 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 1854221 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1854221 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1854221 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-23T12:35:22.406Z
[junit4] 2> 1854221 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/solr.xml
[junit4] 2> 1854235 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/.
[junit4] 2> 1854235 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1854247 WARN (coreLoadExecutor-6716-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 1854248 INFO (coreLoadExecutor-6716-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1854258 INFO (coreLoadExecutor-6716-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1854260 INFO (coreLoadExecutor-6716-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1854262 INFO (coreLoadExecutor-6716-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/./collection1
[junit4] 2> 1854262 INFO (coreLoadExecutor-6716-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/./collection1/data/]
[junit4] 2> 1854263 INFO (coreLoadExecutor-6716-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=11, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6739785279818982]
[junit4] 2> 1854273 INFO (coreLoadExecutor-6716-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1854273 INFO (coreLoadExecutor-6716-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1854275 INFO (coreLoadExecutor-6716-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=7.009765625, floorSegmentMB=1.6494140625, forceMergeDeletesPctAllowed=2.6814954169616456, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5494746280103859
[junit4] 2> 1854275 INFO (coreLoadExecutor-6716-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3b4c78e5[collection1] main]
[junit4] 2> 1854276 INFO (coreLoadExecutor-6716-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/collection1/conf
[junit4] 2> 1854279 INFO (coreLoadExecutor-6716-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms
[junit4] 2> 1854279 INFO (searcherExecutor-6717-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3b4c78e5[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1854503 INFO (qtp31280845-13529) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 1854504 INFO (indexFetcher-6721-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 1854504 INFO (indexFetcher-6721-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 1854504 INFO (indexFetcher-6721-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 1854742 INFO (qtp31280845-13531) [ x:collection1] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 1854743 INFO (qtp31280845-13531) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:*} 0 0
[junit4] 2> 1854746 INFO (qtp1524231795-13546) [ x:collection1] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 1854747 INFO (qtp1524231795-13546) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:*} 0 0
[junit4] 2> 1854748 INFO (qtp31280845-13532) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1854748 INFO (qtp31280845-13532) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@2c9b5287
[junit4] 2> 1854749 INFO (qtp31280845-13532) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6361a35f[collection1] main]
[junit4] 2> 1854750 INFO (qtp31280845-13532) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1854750 INFO (searcherExecutor-6707-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@6361a35f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1854751 INFO (qtp31280845-13532) [ 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 2
[junit4] 2> 1854752 INFO (qtp1524231795-13547) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1854753 INFO (qtp1524231795-13547) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@7c4bedbb
[junit4] 2> 1854754 INFO (qtp1524231795-13547) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@33b10679[collection1] main]
[junit4] 2> 1854754 INFO (qtp1524231795-13547) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1854754 INFO (searcherExecutor-6717-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@33b10679[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1854754 INFO (qtp1524231795-13547) [ 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 2
[junit4] 2> 1854756 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@36d8bfca{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1854757 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=739069488
[junit4] 2> 1854757 INFO (coreCloseExecutor-6722-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@52b0e13c
[junit4] 2> 1854760 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@369de82a{/solr,null,UNAVAILABLE}
[junit4] 2> 1854763 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@50d90001{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1854764 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=426021278
[junit4] 2> 1854765 INFO (coreCloseExecutor-6724-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@37822e27
[junit4] 2> 1854766 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6f1dff06{/solr,null,UNAVAILABLE}
[junit4] 2> 1854772 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1854775 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@592f96e{/solr,null,AVAILABLE}
[junit4] 2> 1854776 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Started ServerConnector@4496e1ea{HTTP/1.1,[http/1.1]}{127.0.0.1:51735}
[junit4] 2> 1854776 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server Started @1864300ms
[junit4] 2> 1854776 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=51735}
[junit4] 2> 1854776 ERROR (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1854778 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 1854778 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1854778 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1854778 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-23T12:35:22.963Z
[junit4] 2> 1854779 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/solr.xml
[junit4] 2> 1854802 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/.
[junit4] 2> 1854802 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1854813 WARN (coreLoadExecutor-6731-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 1854814 INFO (coreLoadExecutor-6731-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1854826 INFO (coreLoadExecutor-6731-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1854828 INFO (coreLoadExecutor-6731-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1854830 INFO (coreLoadExecutor-6731-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/./collection1
[junit4] 2> 1854830 INFO (coreLoadExecutor-6731-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/./collection1/data/]
[junit4] 2> 1854834 INFO (coreLoadExecutor-6731-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=44, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1854852 INFO (coreLoadExecutor-6731-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1854852 INFO (coreLoadExecutor-6731-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1854852 INFO (coreLoadExecutor-6731-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1854853 INFO (coreLoadExecutor-6731-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4abb9335[collection1] main]
[junit4] 2> 1854853 INFO (coreLoadExecutor-6731-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/collection1/conf
[junit4] 2> 1854853 INFO (coreLoadExecutor-6731-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1854854 INFO (searcherExecutor-6732-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4abb9335[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1855314 INFO (qtp410122868-13568) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0]} 0 1
[junit4] 2> 1855316 INFO (qtp410122868-13569) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1]} 0 0
[junit4] 2> 1855317 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2]} 0 0
[junit4] 2> 1855318 INFO (qtp410122868-13571) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[3]} 0 0
[junit4] 2> 1855319 INFO (qtp410122868-13572) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[4]} 0 0
[junit4] 2> 1855320 INFO (qtp410122868-13573) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[5]} 0 0
[junit4] 2> 1855321 INFO (qtp410122868-13566) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[6]} 0 0
[junit4] 2> 1855322 INFO (qtp410122868-13568) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[7]} 0 0
[junit4] 2> 1855323 INFO (qtp410122868-13569) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[8]} 0 0
[junit4] 2> 1855323 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[9]} 0 0
[junit4] 2> 1855324 INFO (qtp410122868-13571) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[10]} 0 0
[junit4] 2> 1855325 INFO (qtp410122868-13572) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[11]} 0 0
[junit4] 2> 1855326 INFO (qtp410122868-13573) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[12]} 0 0
[junit4] 2> 1855327 INFO (qtp410122868-13566) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[13]} 0 0
[junit4] 2> 1855327 INFO (qtp410122868-13568) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[14]} 0 0
[junit4] 2> 1855329 INFO (qtp410122868-13569) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[15]} 0 0
[junit4] 2> 1855330 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[16]} 0 0
[junit4] 2> 1855331 INFO (qtp410122868-13571) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[17]} 0 0
[junit4] 2> 1855331 INFO (qtp410122868-13572) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[18]} 0 0
[junit4] 2> 1855332 INFO (qtp410122868-13573) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[19]} 0 0
[junit4] 2> 1855333 INFO (qtp410122868-13566) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[20]} 0 0
[junit4] 2> 1855334 INFO (qtp410122868-13568) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[21]} 0 0
[junit4] 2> 1855335 INFO (qtp410122868-13569) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[22]} 0 0
[junit4] 2> 1855336 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[23]} 0 0
[junit4] 2> 1855337 INFO (qtp410122868-13571) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[24]} 0 0
[junit4] 2> 1855338 INFO (qtp410122868-13572) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[25]} 0 0
[junit4] 2> 1855339 INFO (qtp410122868-13573) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[26]} 0 0
[junit4] 2> 1855341 INFO (qtp410122868-13566) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[27]} 0 0
[junit4] 2> 1855342 INFO (qtp410122868-13568) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[28]} 0 0
[junit4] 2> 1855342 INFO (qtp410122868-13569) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[29]} 0 0
[junit4] 2> 1855344 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[30]} 0 0
[junit4] 2> 1855345 INFO (qtp410122868-13571) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[31]} 0 0
[junit4] 2> 1855346 INFO (qtp410122868-13572) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[32]} 0 0
[junit4] 2> 1855347 INFO (qtp410122868-13573) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[33]} 0 0
[junit4] 2> 1855348 INFO (qtp410122868-13566) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[34]} 0 0
[junit4] 2> 1855349 INFO (qtp410122868-13568) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[35]} 0 0
[junit4] 2> 1855350 INFO (qtp410122868-13569) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[36]} 0 0
[junit4] 2> 1855351 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[37]} 0 0
[junit4] 2> 1855353 INFO (qtp410122868-13571) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[38]} 0 0
[junit4] 2> 1855354 INFO (qtp410122868-13572) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[39]} 0 0
[junit4] 2> 1855354 INFO (qtp410122868-13573) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[40]} 0 0
[junit4] 2> 1855355 INFO (qtp410122868-13566) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[41]} 0 0
[junit4] 2> 1855357 INFO (qtp410122868-13568) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[42]} 0 0
[junit4] 2> 1855357 INFO (qtp410122868-13569) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[43]} 0 0
[junit4] 2> 1855358 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[44]} 0 0
[junit4] 2> 1855359 INFO (qtp410122868-13571) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[45]} 0 0
[junit4] 2> 1855360 INFO (qtp410122868-13572) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[46]} 0 0
[junit4] 2> 1855361 INFO (qtp410122868-13573) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[47]} 0 0
[junit4] 2> 1855361 INFO (qtp410122868-13566) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[48]} 0 0
[junit4] 2> 1855362 INFO (qtp410122868-13568) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[49]} 0 0
[junit4] 2> 1855363 INFO (qtp410122868-13569) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[50]} 0 0
[junit4] 2> 1855365 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[51]} 0 0
[junit4] 2> 1855365 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[52]} 0 0
[junit4] 2> 1855367 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[53]} 0 0
[junit4] 2> 1855368 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[54]} 0 0
[junit4] 2> 1855369 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[55]} 0 0
[junit4] 2> 1855370 INFO (qtp410122868-13568) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[56]} 0 0
[junit4] 2> 1855371 INFO (qtp410122868-13569) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[57]} 0 0
[junit4] 2> 1855373 INFO (qtp410122868-13571) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[58]} 0 0
[junit4] 2> 1855374 INFO (qtp410122868-13572) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[59]} 0 0
[junit4] 2> 1855374 INFO (qtp410122868-13573) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[60]} 0 0
[junit4] 2> 1855377 INFO (qtp410122868-13566) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[61]} 0 0
[junit4] 2> 1855378 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[62]} 0 0
[junit4] 2> 1855379 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[63]} 0 0
[junit4] 2> 1855380 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[64]} 0 0
[junit4] 2> 1855381 INFO (qtp410122868-13571) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[65]} 0 0
[junit4] 2> 1855382 INFO (qtp410122868-13572) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[66]} 0 0
[junit4] 2> 1855383 INFO (qtp410122868-13573) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[67]} 0 0
[junit4] 2> 1855384 INFO (qtp410122868-13566) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[68]} 0 0
[junit4] 2> 1855385 INFO (qtp410122868-13568) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[69]} 0 0
[junit4] 2> 1855386 INFO (qtp410122868-13569) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[70]} 0 0
[junit4] 2> 1855387 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[71]} 0 0
[junit4] 2> 1855389 INFO (qtp410122868-13571) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[72]} 0 0
[junit4] 2> 1855390 INFO (qtp410122868-13572) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[73]} 0 0
[junit4] 2> 1855399 INFO (qtp410122868-13573) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[74]} 0 8
[junit4] 2> 1855403 INFO (qtp410122868-13566) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[75]} 0 2
[junit4] 2> 1855404 INFO (qtp410122868-13568) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[76]} 0 0
[junit4] 2> 1855405 INFO (qtp410122868-13569) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[77]} 0 0
[junit4] 2> 1855406 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[78]} 0 0
[junit4] 2> 1855407 INFO (qtp410122868-13571) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[79]} 0 0
[junit4] 2> 1855409 INFO (qtp410122868-13572) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[80]} 0 0
[junit4] 2> 1855411 INFO (qtp410122868-13573) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[81]} 0 0
[junit4] 2> 1855412 INFO (qtp410122868-13566) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[82]} 0 0
[junit4] 2> 1855413 INFO (qtp410122868-13568) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[83]} 0 0
[junit4] 2> 1855414 INFO (qtp410122868-13569) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[84]} 0 0
[junit4] 2> 1855415 INFO (qtp410122868-13570) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[85]} 0 0
[junit4] 2> 1855416 INFO (qtp410122868-13571) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[86]} 0 0
[junit4] 2> 1855417 INFO (qtp410122868-13572) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[87]} 0 0
[junit4] 2> 1855418 INFO (qtp410122868-13573) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[88]} 0 0
[junit4] 2> 1855419 INFO (qtp410122868-13566) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[89]} 0 0
[junit4] 2> 1855420 INFO (qtp410122868-13568) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1855420 INFO (qtp410122868-13568) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@4028a864
[junit4] 2> 1855541 INFO (qtp410122868-13568) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6bb32029[collection1] main]
[junit4] 2> 1855541 INFO (qtp410122868-13568) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1855541 INFO (searcherExecutor-6732-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@6bb32029[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):c75) Uninverting(_1(7.0.0):c15)))}
[junit4] 2> 1855542 INFO (qtp410122868-13568) [ 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 121
[junit4] 2> 1855543 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@4496e1ea{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1855543 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=848391411
[junit4] 2> 1855544 INFO (coreCloseExecutor-6736-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@779c05a6
[junit4] 2> 1855546 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@592f96e{/solr,null,UNAVAILABLE}
[junit4] 2> 1855550 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1855553 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2b590b24{/solr,null,AVAILABLE}
[junit4] 2> 1855553 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Started ServerConnector@2ed56cb5{HTTP/1.1,[http/1.1]}{127.0.0.1:51739}
[junit4] 2> 1855553 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server Started @1865077ms
[junit4] 2> 1855554 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=51739}
[junit4] 2> 1855554 ERROR (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1855554 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 1855554 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1855554 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1855555 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-23T12:35:23.739Z
[junit4] 2> 1855555 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/solr.xml
[junit4] 2> 1855579 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/.
[junit4] 2> 1855579 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1855597 WARN (coreLoadExecutor-6743-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 1855598 INFO (coreLoadExecutor-6743-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1855619 INFO (coreLoadExecutor-6743-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1855624 INFO (coreLoadExecutor-6743-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1855634 INFO (coreLoadExecutor-6743-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/./collection1
[junit4] 2> 1855635 INFO (coreLoadExecutor-6743-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/./collection1/data/]
[junit4] 2> 1855655 INFO (coreLoadExecutor-6743-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1855656 INFO (coreLoadExecutor-6743-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1855657 INFO (coreLoadExecutor-6743-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=44, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1855661 INFO (coreLoadExecutor-6743-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@24e80180[collection1] main]
[junit4] 2> 1855662 INFO (coreLoadExecutor-6743-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-001/collection1/conf
[junit4] 2> 1855662 INFO (coreLoadExecutor-6743-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1855663 INFO (searcherExecutor-6744-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@24e80180[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):c75) Uninverting(_1(7.0.0):c15)))}
[junit4] 2> 1856094 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1856105 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3cec49d7{/solr,null,AVAILABLE}
[junit4] 2> 1856106 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Started ServerConnector@f218ca9{HTTP/1.1,[http/1.1]}{127.0.0.1:51740}
[junit4] 2> 1856106 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server Started @1865629ms
[junit4] 2> 1856106 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/collection1/data, hostContext=/solr, hostPort=51740}
[junit4] 2> 1856106 ERROR (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1856106 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 1856107 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1856107 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1856107 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-23T12:35:24.292Z
[junit4] 2> 1856107 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/solr.xml
[junit4] 2> 1856120 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/.
[junit4] 2> 1856120 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1856128 WARN (coreLoadExecutor-6753-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 1856129 INFO (coreLoadExecutor-6753-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1856136 INFO (coreLoadExecutor-6753-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1856137 INFO (coreLoadExecutor-6753-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1856139 INFO (coreLoadExecutor-6753-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/./collection1
[junit4] 2> 1856139 INFO (coreLoadExecutor-6753-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/./collection1/data/]
[junit4] 2> 1856142 INFO (coreLoadExecutor-6753-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=44, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1856159 INFO (coreLoadExecutor-6753-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1856159 INFO (coreLoadExecutor-6753-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1856160 INFO (coreLoadExecutor-6753-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1856161 INFO (coreLoadExecutor-6753-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@58111aec[collection1] main]
[junit4] 2> 1856161 INFO (coreLoadExecutor-6753-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/collection1/conf
[junit4] 2> 1856162 INFO (coreLoadExecutor-6753-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1856162 INFO (searcherExecutor-6754-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@58111aec[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1856640 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 1856645 INFO (qtp182631561-13587) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 1856645 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 2
[junit4] 2> 1856645 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1479904523605
[junit4] 2> 1856645 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 1856645 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 1856654 INFO (qtp182631561-13588) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&wt=javabin&version=2&command=filelist} status=0 QTime=8
[junit4] 2> 1856654 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 7
[junit4] 2> 1856658 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=44, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1856679 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 1856690 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to NRTCachingDirectory(MMapDirectory@/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/collection1/data/index.20161123073524840 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@50e41743; maxCacheMB=48.0 maxMergeSizeMB=4.0)
[junit4] 2> 1856691 INFO (qtp182631561-13589) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.cfe&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1856704 INFO (qtp182631561-13590) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1856718 INFO (qtp182631561-13591) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.cfs&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1861141 INFO (qtp182631561-13592) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_1.cfs&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1862478 INFO (qtp182631561-13585) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_1.cfe&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1862481 INFO (qtp182631561-13587) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_1.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1862484 INFO (qtp182631561-13588) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=segments_2&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1862485 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=599816) : 5 secs (119963 bytes/sec) to NRTCachingDirectory(MMapDirectory@/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-002/collection1/data/index.20161123073524840 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@50e41743; maxCacheMB=48.0 maxMergeSizeMB=4.0)
[junit4] 2> 1862506 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1862580 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 1862594 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@48e85b5c[collection1] main]
[junit4] 2> 1862597 INFO (searcherExecutor-6754-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@48e85b5c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):c75) Uninverting(_1(7.0.0):c15)))}
[junit4] 2> 1862611 INFO (qtp633458236-13604) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:51739/solr/collection1/replication&command=fetchindex} status=0 QTime=5971
[junit4] 2> 1862638 INFO (qtp182631561-13589) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[90]} 0 13
[junit4] 2> 1862640 INFO (qtp633458236-13605) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=*:*&sort=id+desc&wt=javabin&version=2} hits=90 status=0 QTime=0
[junit4] 2> 1862642 INFO (qtp182631561-13590) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[91]} 0 0
[junit4] 2> 1862643 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 90 docs
[junit4] 2> 1862643 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.h.TestReplicationHandler approximateTimeInSeconds = 0.0 timeTakenInSeconds = 6
[junit4] 2> 1862643 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testRateLimitedReplication
[junit4] 2> 1862649 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@2ed56cb5{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1862649 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=768266668
[junit4] 2> 1862656 INFO (coreCloseExecutor-6759-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3ace0281
[junit4] 2> 1862749 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2b590b24{/solr,null,UNAVAILABLE}
[junit4] 2> 1862752 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@f218ca9{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1862752 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=571450474
[junit4] 2> 1862753 INFO (coreCloseExecutor-6761-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@656191a0
[junit4] 2> 1862755 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@3cec49d7{/solr,null,UNAVAILABLE}
[junit4] 2> 1862761 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting doTestHandlerPathUnchanged
[junit4] 2> 1862762 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-003/collection1
[junit4] 2> 1862778 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1862781 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5dcd7a6{/solr,null,AVAILABLE}
[junit4] 2> 1862782 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Started ServerConnector@7b80354c{HTTP/1.1,[http/1.1]}{127.0.0.1:51748}
[junit4] 2> 1862782 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server Started @1872305ms
[junit4] 2> 1862782 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-003/collection1/data, hostContext=/solr, hostPort=51748}
[junit4] 2> 1862782 ERROR (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1862783 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 1862783 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1862783 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1862783 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-23T12:35:30.968Z
[junit4] 2> 1862784 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-003/solr.xml
[junit4] 2> 1862814 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-003/.
[junit4] 2> 1862814 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1862834 WARN (coreLoadExecutor-6768-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 1862835 INFO (coreLoadExecutor-6768-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1862846 INFO (coreLoadExecutor-6768-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1862853 INFO (coreLoadExecutor-6768-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1862863 INFO (coreLoadExecutor-6768-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-003/./collection1
[junit4] 2> 1862863 INFO (coreLoadExecutor-6768-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-003/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-003/./collection1/data/]
[junit4] 2> 1862865 INFO (coreLoadExecutor-6768-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=11, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6739785279818982]
[junit4] 2> 1862890 INFO (coreLoadExecutor-6768-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1862890 INFO (coreLoadExecutor-6768-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1862890 INFO (coreLoadExecutor-6768-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=7.009765625, floorSegmentMB=1.6494140625, forceMergeDeletesPctAllowed=2.6814954169616456, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5494746280103859
[junit4] 2> 1862891 INFO (coreLoadExecutor-6768-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7c8ff549[collection1] main]
[junit4] 2> 1862891 INFO (coreLoadExecutor-6768-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-003/collection1/conf
[junit4] 2> 1862892 INFO (coreLoadExecutor-6768-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 1862892 INFO (coreLoadExecutor-6768-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1862892 INFO (searcherExecutor-6769-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7c8ff549[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1863319 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-004/collection1
[junit4] 2> 1863333 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1863335 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6f93c7d7{/solr,null,AVAILABLE}
[junit4] 2> 1863336 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Started ServerConnector@444dcf16{HTTP/1.1,[http/1.1]}{127.0.0.1:51749}
[junit4] 2> 1863336 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server Started @1872859ms
[junit4] 2> 1863336 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-004/collection1/data, hostContext=/solr, hostPort=51749}
[junit4] 2> 1863336 ERROR (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1863336 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 1863337 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1863337 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1863337 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-23T12:35:31.522Z
[junit4] 2> 1863337 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-004/solr.xml
[junit4] 2> 1863362 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-004/.
[junit4] 2> 1863362 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1863387 WARN (coreLoadExecutor-6778-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 1863388 INFO (coreLoadExecutor-6778-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1863397 INFO (coreLoadExecutor-6778-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1863399 INFO (coreLoadExecutor-6778-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1863401 INFO (coreLoadExecutor-6778-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-004/./collection1
[junit4] 2> 1863401 INFO (coreLoadExecutor-6778-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-004/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-004/./collection1/data/]
[junit4] 2> 1863402 INFO (coreLoadExecutor-6778-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=11, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6739785279818982]
[junit4] 2> 1863412 INFO (coreLoadExecutor-6778-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1863412 INFO (coreLoadExecutor-6778-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1863412 INFO (coreLoadExecutor-6778-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=7.009765625, floorSegmentMB=1.6494140625, forceMergeDeletesPctAllowed=2.6814954169616456, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5494746280103859
[junit4] 2> 1863412 INFO (coreLoadExecutor-6778-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@707788bb[collection1] main]
[junit4] 2> 1863413 INFO (coreLoadExecutor-6778-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-004/collection1/conf
[junit4] 2> 1863414 INFO (coreLoadExecutor-6778-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms
[junit4] 2> 1863415 INFO (searcherExecutor-6779-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@707788bb[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1863419 INFO (qtp102688981-13629) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 1863419 INFO (indexFetcher-6783-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 1863419 INFO (indexFetcher-6783-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 1863419 INFO (indexFetcher-6783-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 1863865 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending doTestHandlerPathUnchanged
[junit4] 2> 1863867 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@7b80354c{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1863867 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1252320786
[junit4] 2> 1863868 INFO (coreCloseExecutor-6784-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3277ca7b
[junit4] 2> 1863869 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5dcd7a6{/solr,null,UNAVAILABLE}
[junit4] 2> 1863871 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@444dcf16{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1863871 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1472313204
[junit4] 2> 1863873 INFO (coreCloseExecutor-6786-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1980ee46
[junit4] 2> 1863875 INFO (TEST-TestReplicationHandler.doTestHandlerPathUnchanged-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6f93c7d7{/solr,null,UNAVAILABLE}
[junit4] 2> 1863878 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting doTestIndexAndConfigAliasReplication
[junit4] 2> 1863889 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-005/collection1
[junit4] 2> 1863897 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1863900 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4a276e13{/solr,null,AVAILABLE}
[junit4] 2> 1863900 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Started ServerConnector@2aeff222{HTTP/1.1,[http/1.1]}{127.0.0.1:51751}
[junit4] 2> 1863900 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.Server Started @1873424ms
[junit4] 2> 1863900 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001/solr-instance-005/collection1/data, hostContext=/solr, hostPort=51751}
[junit4] 2> 1863901 ERROR (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1863901 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 1863901 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[390D5032CECC6C9C]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1863901 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAl
[...truncated too long message...]
ime=0
[junit4] 2> 1977061 INFO (qtp1316866834-14520) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_5.si&checksum=true&compression=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1977062 INFO (qtp1316866834-14522) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_6.cfe&checksum=true&compression=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1977063 INFO (qtp1316866834-14521) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_6.cfs&checksum=true&compression=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1977064 INFO (qtp1316866834-14516) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_6.si&checksum=true&compression=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1977065 INFO (qtp1316866834-14518) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=segments_2&checksum=true&compression=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1977065 INFO (indexFetcher-7351-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=24479) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@67dab74c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b315f50)
[junit4] 2> 1977067 INFO (indexFetcher-7351-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=81.9609375, floorSegmentMB=1.8955078125, forceMergeDeletesPctAllowed=12.197125583551443, segmentsPerTier=33.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7888240707502047
[junit4] 2> 1977069 INFO (indexFetcher-7351-thread-1) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 1977070 INFO (indexFetcher-7351-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@45ad3a[collection1] main]
[junit4] 2> 1977070 INFO (searcherExecutor-7347-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@45ad3a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):c75) Uninverting(_1(7.0.0):c75) Uninverting(_2(7.0.0):c75) Uninverting(_3(7.0.0):c75) Uninverting(_4(7.0.0):c75) Uninverting(_5(7.0.0):c75) Uninverting(_6(7.0.0):c43)))}
[junit4] 2> 1977148 INFO (qtp773705556-14539) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=*:*&sort=id+desc&wt=javabin&version=2} hits=493 status=0 QTime=0
[junit4] 2> 1977149 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[390D5032CECC6C9C]) [ ] o.a.s.h.TestReplicationHandler Waited for 400ms and found 493 docs
[junit4] 2> 1977149 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[390D5032CECC6C9C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending doTestReplicateAfterStartup
[junit4] 2> 1977150 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@79e11c63{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1977150 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1674568989
[junit4] 2> 1977151 INFO (coreCloseExecutor-7353-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@270a687
[junit4] 2> 1977152 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@578a6030{/solr,null,UNAVAILABLE}
[junit4] 2> 1977154 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@41615144{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1977154 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[390D5032CECC6C9C]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=198557999
[junit4] 2> 1977155 INFO (coreCloseExecutor-7355-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@58776c8a
[junit4] 2> 1977156 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[390D5032CECC6C9C]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@212c51a1{/solr,null,UNAVAILABLE}
[junit4] 2> 1977159 INFO (SUITE-TestReplicationHandler-seed#[390D5032CECC6C9C]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_390D5032CECC6C9C-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {name=PostingsFormat(name=MockRandom), id=PostingsFormat(name=MockRandom), newname=PostingsFormat(name=MockRandom)}, docValues:{}, maxPointsInLeafNode=250, maxMBSortInHeap=6.7616248172473785, sim=RandomSimilarity(queryNorm=false): {}, locale=it-IT, timezone=EST
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_102 (64-bit)/cpus=3,threads=1,free=66476592,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [TestObjectReleaseTracker, TestSolrCloudWithSecureImpersonation, CreateCollectionCleanupTest, SuggesterWFSTTest, TestSolrIndexConfig, HighlighterMaxOffsetTest, TestRandomFaceting, OverseerCollectionConfigSetProcessorTest, TestSchemaResource, HighlighterConfigTest, AtomicUpdatesTest, UUIDUpdateProcessorFallbackTest, TestPHPSerializedResponseWriter, ShardSplitTest, CloudMLTQParserTest, ReturnFieldsTest, FieldMutatingUpdateProcessorTest, TestScoreJoinQPScore, TestFiltering, LeaderElectionIntegrationTest, InfoHandlerTest, TestReplicationHandlerBackup, TestSimpleQParserPlugin, ConvertedLegacyTest, TestQueryUtils, DistributedSuggestComponentTest, DistributedQueryComponentCustomSortTest, TestExactStatsCache, CollectionsAPIDistributedZkTest, TestLMJelinekMercerSimilarityFactory, TestSQLHandlerNonCloud, TestPKIAuthenticationPlugin, DirectUpdateHandlerOptimizeTest, TestNumericTerms64, HdfsRestartWhileUpdatingTest, TestComponentsName, TestSystemIdResolver, HdfsThreadLeakTest, RestartWhileUpdatingTest, TestSchemaVersionResource, TestSuggestSpellingConverter, TestValueSourceCache, ReplicaListTransformerTest, TestTrie, TestIntervalFaceting, SolrCoreCheckLockOnStartupTest, AutoCommitTest, TestAnalyzeInfixSuggestions, HttpPartitionTest, TestJoin, AliasIntegrationTest, CSVRequestHandlerTest, TestDistributedGrouping, CollectionTooManyReplicasTest, ExternalFileFieldSortTest, TestReRankQParserPlugin, TestChildDocTransformer, TestDocTermOrds, TestHashQParserPlugin, TestManagedSchema, TestLMDirichletSimilarityFactory, TestClassicSimilarityFactory, TestRestoreCore, URLClassifyProcessorTest, TestFuzzyAnalyzedSuggestions, CurrencyFieldOpenExchangeTest, SuggesterTest, CollectionsAPISolrJTest, BasicDistributedZk2Test, SpatialHeatmapFacetsTest, TestConfig, TestDynamicFieldResource, TestCustomDocTransformer, AddBlockUpdateTest, RAMDirectoryFactoryTest, TestRawTransformer, TestCloudDeleteByQuery, DistributedDebugComponentTest, TestShortCircuitedRequests, TestLeaderElectionWithEmptyReplica, CloneFieldUpdateProcessorFactoryTest, TestFieldCacheVsDocValues, TestConfigSetsAPIExclusivity, DeleteInactiveReplicaTest, SolrCmdDistributorTest, TestFieldCacheReopen, RulesTest, CoreAdminRequestStatusTest, CursorMarkTest, TestWriterPerf, TestConfigReload, QueryResultKeyTest, ConfigSetsAPITest, WrapperMergePolicyFactoryTest, TestCollectionAPI, TestSolrDeletionPolicy2, GraphQueryTest, TestCloudManagedSchema, TestFileDictionaryLookup, TestConfigOverlay, BJQParserTest, SegmentsInfoRequestHandlerTest, SuggesterTSTTest, VersionInfoTest, TestBadConfig, TestXmlQParserPlugin, TermVectorComponentTest, DefaultValueUpdateProcessorTest, TestUniqueKeyFieldResource, RequestHandlersTest, TestFastWriter, ZkSolrClientTest, RequestLoggingTest, CircularListTest, TestFieldTypeResource, TestZkChroot, TestDistributedMissingSort, SolrIndexSplitterTest, PKIAuthenticationIntegrationTest, HdfsCollectionsAPIDistributedZkTest, SpellPossibilityIteratorTest, TestSolrQueryParserDefaultOperatorResource, LeaderFailoverAfterPartitionTest, DistributedVersionInfoTest, TestShardHandlerFactory, BlockJoinFacetRandomTest, PeerSyncWithIndexFingerprintCachingTest, HdfsBasicDistributedZk2Test, TestGeoJSONResponseWriter, EnumFieldTest, IgnoreCommitOptimizeUpdateProcessorFactoryTest, DistributedFacetExistsSmallTest, TestUtils, TestFieldCacheSort, OpenCloseCoreStressTest, SparseHLLTest, ExitableDirectoryReaderTest, BooleanFieldTest, TestLegacyNumericRangeQueryBuilder, UpdateParamsTest, TestDistribDocBasedVersion, BlockDirectoryTest, ZkStateReaderTest, TestCrossCoreJoin, FieldAnalysisRequestHandlerTest, TestFilteredDocIdSet, TestNamedUpdateProcessors, TermVectorComponentDistributedTest, TestCloudRecovery, HdfsChaosMonkeyNothingIsSafeTest, UUIDFieldTest, SolrCLIZkUtilsTest, TestLockTree, TestLuceneMatchVersion, SuggestComponentTest, TestExceedMaxTermLength, TestSolrConfigHandlerConcurrent, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, SyncSliceTest, BasicZkTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler]
[junit4] Completed [330/653 (1!)] on J1 in 123.56s, 15 tests, 1 failure, 1 skipped <<< FAILURES!
[...truncated 63382 lines...]
[JENKINS] Lucene-Solr-master-MacOSX (64bit/jdk1.8.0) - Build # 3663
- Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/3663/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication
Error Message:
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-022/./collection1/data, /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-022/./collection1/data/index.20161123052246603, /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-022/./collection1/data/snapshot_metadata, /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-022/./collection1/data/index.20161123052246695] expected:<3> but was:<4>
Stack Trace:
java.lang.AssertionError: [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-022/./collection1/data, /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-022/./collection1/data/index.20161123052246603, /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-022/./collection1/data/snapshot_metadata, /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-022/./collection1/data/index.20161123052246695] expected:<3> but was:<4>
at __randomizedtesting.SeedInfo.seed([2D12FCFA30364B96:DA6112A2F6DEE470]: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.apache.solr.handler.TestReplicationHandler.checkForSingleIndex(TestReplicationHandler.java:902)
at org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication(TestReplicationHandler.java:1334)
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:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:811)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:462)
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:367)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11629 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/init-core-data-001
[junit4] 2> 1699310 INFO (SUITE-TestReplicationHandler-seed#[2D12FCFA30364B96]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 1699311 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testRateLimitedReplication
[junit4] 2> 1699312 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/collection1
[junit4] 2> 1699393 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1699395 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6762af8e{/solr,null,AVAILABLE}
[junit4] 2> 1699415 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Started ServerConnector@6bb1274d{HTTP/1.1,[http/1.1]}{127.0.0.1:49998}
[junit4] 2> 1699415 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server Started @1706337ms
[junit4] 2> 1699415 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=49998}
[junit4] 2> 1699416 ERROR (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1699417 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0
[junit4] 2> 1699417 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1699418 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1699418 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-23T02:21:56.706Z
[junit4] 2> 1699420 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/solr.xml
[junit4] 2> 1699443 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/.
[junit4] 2> 1699443 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1699458 INFO (coreLoadExecutor-6349-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1699467 INFO (coreLoadExecutor-6349-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1699470 INFO (coreLoadExecutor-6349-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1699476 INFO (coreLoadExecutor-6349-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/./collection1
[junit4] 2> 1699476 INFO (coreLoadExecutor-6349-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/./collection1/data/]
[junit4] 2> 1699477 INFO (coreLoadExecutor-6349-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=16, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.49999524564490694]
[junit4] 2> 1699490 INFO (coreLoadExecutor-6349-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1699490 INFO (coreLoadExecutor-6349-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1699491 INFO (coreLoadExecutor-6349-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1972558896365694]
[junit4] 2> 1699504 INFO (coreLoadExecutor-6349-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6e9373cf[collection1] main]
[junit4] 2> 1699505 INFO (coreLoadExecutor-6349-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/collection1/conf
[junit4] 2> 1699505 INFO (coreLoadExecutor-6349-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 1699505 INFO (coreLoadExecutor-6349-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1699505 INFO (searcherExecutor-6350-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@6e9373cf[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1699955 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/collection1
[junit4] 2> 1699968 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1699970 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6a29707f{/solr,null,AVAILABLE}
[junit4] 2> 1699970 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Started ServerConnector@5f901dc1{HTTP/1.1,[http/1.1]}{127.0.0.1:50010}
[junit4] 2> 1699970 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server Started @1706892ms
[junit4] 2> 1699970 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/collection1/data, hostContext=/solr, hostPort=50010}
[junit4] 2> 1699971 ERROR (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1699971 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0
[junit4] 2> 1699971 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1699971 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1699971 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-23T02:21:57.259Z
[junit4] 2> 1699972 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/solr.xml
[junit4] 2> 1700010 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/.
[junit4] 2> 1700010 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1700017 INFO (coreLoadExecutor-6359-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1700030 INFO (coreLoadExecutor-6359-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1700031 INFO (coreLoadExecutor-6359-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1700032 INFO (coreLoadExecutor-6359-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/./collection1
[junit4] 2> 1700032 INFO (coreLoadExecutor-6359-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/./collection1/data/]
[junit4] 2> 1700033 INFO (coreLoadExecutor-6359-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=16, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.49999524564490694]
[junit4] 2> 1700040 INFO (coreLoadExecutor-6359-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1700040 INFO (coreLoadExecutor-6359-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1700040 INFO (coreLoadExecutor-6359-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1972558896365694]
[junit4] 2> 1700040 INFO (coreLoadExecutor-6359-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@c8ff0ae[collection1] main]
[junit4] 2> 1700041 INFO (coreLoadExecutor-6359-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/collection1/conf
[junit4] 2> 1700043 INFO (coreLoadExecutor-6359-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms
[junit4] 2> 1700043 INFO (searcherExecutor-6360-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@c8ff0ae[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1700526 INFO (qtp1991859808-12298) [ x:collection1] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 1700526 INFO (qtp1991859808-12298) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:*} 0 0
[junit4] 2> 1700529 INFO (qtp115860919-12315) [ x:collection1] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 1700529 INFO (qtp115860919-12315) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:*} 0 0
[junit4] 2> 1700529 INFO (qtp1991859808-12299) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1700530 INFO (qtp1991859808-12299) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@632ba401
[junit4] 2> 1700540 INFO (qtp1991859808-12299) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2cd14c2f[collection1] main]
[junit4] 2> 1700540 INFO (qtp1991859808-12299) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1700540 INFO (searcherExecutor-6350-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2cd14c2f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1700540 INFO (qtp1991859808-12299) [ 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 11
[junit4] 2> 1700541 INFO (qtp115860919-12316) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1700541 INFO (qtp115860919-12316) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@a15aa94
[junit4] 2> 1700542 INFO (qtp115860919-12316) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@45ef5f9d[collection1] main]
[junit4] 2> 1700542 INFO (qtp115860919-12316) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1700542 INFO (searcherExecutor-6360-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@45ef5f9d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1700542 INFO (qtp115860919-12316) [ 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 1
[junit4] 2> 1700543 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@6bb1274d{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1700544 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=107896185
[junit4] 2> 1700544 INFO (coreCloseExecutor-6365-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3be2bc5c
[junit4] 2> 1700550 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6762af8e{/solr,null,UNAVAILABLE}
[junit4] 2> 1700552 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@5f901dc1{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1700552 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1756914433
[junit4] 2> 1700553 INFO (coreCloseExecutor-6367-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@207f984
[junit4] 2> 1700554 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6a29707f{/solr,null,UNAVAILABLE}
[junit4] 2> 1700580 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1700582 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4d07063b{/solr,null,AVAILABLE}
[junit4] 2> 1700583 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Started ServerConnector@36dfdf45{HTTP/1.1,[http/1.1]}{127.0.0.1:50013}
[junit4] 2> 1700583 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server Started @1707505ms
[junit4] 2> 1700583 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=50013}
[junit4] 2> 1700584 ERROR (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1700584 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0
[junit4] 2> 1700584 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1700584 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1700584 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-23T02:21:57.872Z
[junit4] 2> 1700585 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/solr.xml
[junit4] 2> 1700612 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/.
[junit4] 2> 1700612 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1700620 INFO (coreLoadExecutor-6374-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1700627 INFO (coreLoadExecutor-6374-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1700630 INFO (coreLoadExecutor-6374-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1700630 INFO (coreLoadExecutor-6374-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/./collection1
[junit4] 2> 1700631 INFO (coreLoadExecutor-6374-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/./collection1/data/]
[junit4] 2> 1700633 INFO (coreLoadExecutor-6374-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1152232387, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 1700660 INFO (coreLoadExecutor-6374-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1700660 INFO (coreLoadExecutor-6374-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1700660 INFO (coreLoadExecutor-6374-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=37, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3753232950933666]
[junit4] 2> 1700661 INFO (coreLoadExecutor-6374-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@433f073d[collection1] main]
[junit4] 2> 1700661 INFO (coreLoadExecutor-6374-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/collection1/conf
[junit4] 2> 1700661 INFO (coreLoadExecutor-6374-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1700661 INFO (searcherExecutor-6375-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@433f073d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1701123 INFO (qtp229459714-12337) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0]} 0 1
[junit4] 2> 1701124 INFO (qtp229459714-12338) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1]} 0 0
[junit4] 2> 1701125 INFO (qtp229459714-12339) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2]} 0 0
[junit4] 2> 1701126 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[3]} 0 0
[junit4] 2> 1701127 INFO (qtp229459714-12341) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[4]} 0 0
[junit4] 2> 1701128 INFO (qtp229459714-12342) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[5]} 0 0
[junit4] 2> 1701130 INFO (qtp229459714-12342) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[6]} 0 0
[junit4] 2> 1701131 INFO (qtp229459714-12337) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[7]} 0 0
[junit4] 2> 1701132 INFO (qtp229459714-12337) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[8]} 0 0
[junit4] 2> 1701132 INFO (qtp229459714-12337) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[9]} 0 0
[junit4] 2> 1701133 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[10]} 0 0
[junit4] 2> 1701134 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[11]} 0 0
[junit4] 2> 1701136 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[12]} 0 0
[junit4] 2> 1701137 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[13]} 0 0
[junit4] 2> 1701138 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[14]} 0 0
[junit4] 2> 1701139 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[15]} 0 0
[junit4] 2> 1701139 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[16]} 0 0
[junit4] 2> 1701141 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[17]} 0 0
[junit4] 2> 1701141 INFO (qtp229459714-12335) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[18]} 0 0
[junit4] 2> 1701142 INFO (qtp229459714-12335) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[19]} 0 0
[junit4] 2> 1701143 INFO (qtp229459714-12338) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[20]} 0 0
[junit4] 2> 1701144 INFO (qtp229459714-12339) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[21]} 0 0
[junit4] 2> 1701146 INFO (qtp229459714-12337) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[22]} 0 1
[junit4] 2> 1701147 INFO (qtp229459714-12341) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[23]} 0 0
[junit4] 2> 1701148 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[24]} 0 0
[junit4] 2> 1701149 INFO (qtp229459714-12342) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[25]} 0 0
[junit4] 2> 1701150 INFO (qtp229459714-12335) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[26]} 0 0
[junit4] 2> 1701150 INFO (qtp229459714-12338) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[27]} 0 0
[junit4] 2> 1701153 INFO (qtp229459714-12339) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[28]} 0 1
[junit4] 2> 1701154 INFO (qtp229459714-12337) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[29]} 0 0
[junit4] 2> 1701154 INFO (qtp229459714-12341) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[30]} 0 0
[junit4] 2> 1701155 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[31]} 0 0
[junit4] 2> 1701156 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[32]} 0 0
[junit4] 2> 1701157 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[33]} 0 0
[junit4] 2> 1701159 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[34]} 0 0
[junit4] 2> 1701160 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[35]} 0 0
[junit4] 2> 1701171 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[36]} 0 0
[junit4] 2> 1701172 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[37]} 0 0
[junit4] 2> 1701173 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[38]} 0 0
[junit4] 2> 1701175 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[39]} 0 0
[junit4] 2> 1701176 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[40]} 0 0
[junit4] 2> 1701177 INFO (qtp229459714-12339) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[41]} 0 0
[junit4] 2> 1701178 INFO (qtp229459714-12339) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[42]} 0 0
[junit4] 2> 1701179 INFO (qtp229459714-12339) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[43]} 0 0
[junit4] 2> 1701181 INFO (qtp229459714-12339) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[44]} 0 1
[junit4] 2> 1701182 INFO (qtp229459714-12339) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[45]} 0 0
[junit4] 2> 1701183 INFO (qtp229459714-12339) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[46]} 0 0
[junit4] 2> 1701183 INFO (qtp229459714-12339) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[47]} 0 0
[junit4] 2> 1701184 INFO (qtp229459714-12337) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[48]} 0 0
[junit4] 2> 1701185 INFO (qtp229459714-12341) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[49]} 0 0
[junit4] 2> 1701185 INFO (qtp229459714-12342) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[50]} 0 0
[junit4] 2> 1701187 INFO (qtp229459714-12335) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[51]} 0 0
[junit4] 2> 1701188 INFO (qtp229459714-12338) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[52]} 0 0
[junit4] 2> 1701189 INFO (qtp229459714-12340) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[53]} 0 0
[junit4] 2> 1701189 INFO (qtp229459714-12339) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1701189 INFO (qtp229459714-12339) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@7992c253
[junit4] 2> 1701448 INFO (qtp229459714-12339) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3a15714a[collection1] main]
[junit4] 2> 1701448 INFO (qtp229459714-12339) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1701448 INFO (searcherExecutor-6375-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3a15714a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C54)))}
[junit4] 2> 1701448 INFO (qtp229459714-12339) [ 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 258
[junit4] 2> 1701449 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@36dfdf45{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1701449 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=2040239081
[junit4] 2> 1701450 INFO (coreCloseExecutor-6379-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@6a4340bc
[junit4] 2> 1701451 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4d07063b{/solr,null,UNAVAILABLE}
[junit4] 2> 1701454 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1701456 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@60530f28{/solr,null,AVAILABLE}
[junit4] 2> 1701456 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Started ServerConnector@53d684b5{HTTP/1.1,[http/1.1]}{127.0.0.1:50016}
[junit4] 2> 1701456 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server Started @1708378ms
[junit4] 2> 1701456 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=50016}
[junit4] 2> 1701457 ERROR (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1701457 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0
[junit4] 2> 1701458 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1701458 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1701458 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-23T02:21:58.746Z
[junit4] 2> 1701458 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/solr.xml
[junit4] 2> 1701484 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/.
[junit4] 2> 1701485 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1701492 INFO (coreLoadExecutor-6386-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1701499 INFO (coreLoadExecutor-6386-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1701501 INFO (coreLoadExecutor-6386-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1701501 INFO (coreLoadExecutor-6386-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/./collection1
[junit4] 2> 1701502 INFO (coreLoadExecutor-6386-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/./collection1/data/]
[junit4] 2> 1701510 INFO (coreLoadExecutor-6386-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1701510 INFO (coreLoadExecutor-6386-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1701511 INFO (coreLoadExecutor-6386-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1152232387, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 1701514 INFO (coreLoadExecutor-6386-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@39c72262[collection1] main]
[junit4] 2> 1701514 INFO (coreLoadExecutor-6386-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-001/collection1/conf
[junit4] 2> 1701514 INFO (coreLoadExecutor-6386-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1701514 INFO (searcherExecutor-6387-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@39c72262[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C54)))}
[junit4] 2> 1701991 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1701993 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@173fd5e2{/solr,null,AVAILABLE}
[junit4] 2> 1701993 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Started ServerConnector@40c5e2e3{HTTP/1.1,[http/1.1]}{127.0.0.1:50017}
[junit4] 2> 1701993 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server Started @1708915ms
[junit4] 2> 1701993 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/collection1/data, hostContext=/solr, hostPort=50017}
[junit4] 2> 1701994 ERROR (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1701994 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0
[junit4] 2> 1701994 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1701995 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1701995 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-23T02:21:59.283Z
[junit4] 2> 1701995 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/solr.xml
[junit4] 2> 1702007 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/.
[junit4] 2> 1702008 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1702015 INFO (coreLoadExecutor-6396-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1702022 INFO (coreLoadExecutor-6396-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1702024 INFO (coreLoadExecutor-6396-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1702025 INFO (coreLoadExecutor-6396-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/./collection1
[junit4] 2> 1702025 INFO (coreLoadExecutor-6396-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/./collection1/data/]
[junit4] 2> 1702028 INFO (coreLoadExecutor-6396-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1152232387, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 1702038 INFO (coreLoadExecutor-6396-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1702038 INFO (coreLoadExecutor-6396-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1702038 INFO (coreLoadExecutor-6396-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=37, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3753232950933666]
[junit4] 2> 1702038 INFO (coreLoadExecutor-6396-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@f2896ea[collection1] main]
[junit4] 2> 1702039 INFO (coreLoadExecutor-6396-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/collection1/conf
[junit4] 2> 1702039 INFO (coreLoadExecutor-6396-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1702039 INFO (searcherExecutor-6397-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@f2896ea[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1702518 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 1702527 INFO (qtp1820982423-12356) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 1702527 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 2
[junit4] 2> 1702527 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1479867718477
[junit4] 2> 1702528 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 1702528 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 1702530 INFO (qtp1820982423-12357) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&wt=javabin&version=2&command=filelist} status=0 QTime=2
[junit4] 2> 1702530 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 10
[junit4] 2> 1702535 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1152232387, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 1702536 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 1702537 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to NRTCachingDirectory(MMapDirectory@/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/collection1/data/index.20161123052159818 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@74e8cf47; maxCacheMB=48.0 maxMergeSizeMB=4.0)
[junit4] 2> 1702538 INFO (qtp1820982423-12358) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1702540 INFO (qtp1820982423-12359) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_FSTOrd50_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1702543 INFO (qtp1820982423-12360) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_FSTOrd50_0.tix&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1705779 INFO (qtp1820982423-12361) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1705781 INFO (qtp1820982423-12354) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1705782 INFO (qtp1820982423-12356) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1707403 INFO (qtp1820982423-12357) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_FSTOrd50_0.tbk&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1707414 INFO (qtp1820982423-12358) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1707415 INFO (qtp1820982423-12359) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1707417 INFO (qtp1820982423-12360) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=segments_2&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1707418 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=510676) : 4 secs (127669 bytes/sec) to NRTCachingDirectory(MMapDirectory@/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-002/collection1/data/index.20161123052159818 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@74e8cf47; maxCacheMB=48.0 maxMergeSizeMB=4.0)
[junit4] 2> 1707470 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=37, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3753232950933666]
[junit4] 2> 1707471 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 1707474 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@ff5be91[collection1] main]
[junit4] 2> 1707474 INFO (searcherExecutor-6397-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@ff5be91[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C54)))}
[junit4] 2> 1707475 INFO (qtp349930973-12373) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:50016/solr/collection1/replication&command=fetchindex} status=0 QTime=4957
[junit4] 2> 1707488 INFO (qtp349930973-12375) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=*:*&sort=id+desc&wt=javabin&version=2} hits=54 status=0 QTime=0
[junit4] 2> 1707489 INFO (qtp1820982423-12354) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[54]} 0 1
[junit4] 2> 1707490 INFO (qtp1820982423-12356) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[55]} 0 0
[junit4] 2> 1707491 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 54 docs
[junit4] 2> 1707491 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.h.TestReplicationHandler approximateTimeInSeconds = 0.0 timeTakenInSeconds = 4
[junit4] 2> 1707491 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testRateLimitedReplication
[junit4] 2> 1707491 INFO (qtp1820982423-12357) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1707491 INFO (qtp1820982423-12357) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@282702fb
[junit4] 2> 1707492 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@53d684b5{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1707492 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=485276535
[junit4] 2> 1707494 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@60530f28{/solr,null,UNAVAILABLE}
[junit4] 2> 1707575 INFO (qtp1820982423-12357) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3bce7b8[collection1] main]
[junit4] 2> 1707575 INFO (qtp1820982423-12357) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1707575 INFO (searcherExecutor-6387-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3bce7b8[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C54) Uninverting(_1(7.0.0):C2)))}
[junit4] 2> 1707575 INFO (qtp1820982423-12357) [ 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 84
[junit4] 2> 1707575 INFO (qtp1820982423-12357) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@75829e8d
[junit4] 2> 1707578 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@40c5e2e3{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1707578 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=684968268
[junit4] 2> 1707579 INFO (coreCloseExecutor-6404-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@4b957203
[junit4] 2> 1707580 INFO (TEST-TestReplicationHandler.testRateLimitedReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@173fd5e2{/solr,null,UNAVAILABLE}
[junit4] 2> 1707583 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.SolrTestCaseJ4 ###Starting doTestReplicateAfterStartup
[junit4] 2> 1707584 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-003/collection1
[junit4] 2> 1707617 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1707619 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@43f10f03{/solr,null,AVAILABLE}
[junit4] 2> 1707619 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Started ServerConnector@3afa7cec{HTTP/1.1,[http/1.1]}{127.0.0.1:50029}
[junit4] 2> 1707619 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server Started @1714541ms
[junit4] 2> 1707619 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-003/collection1/data, hostContext=/solr, hostPort=50029}
[junit4] 2> 1707620 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1707620 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0
[junit4] 2> 1707620 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1707620 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1707620 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-23T02:22:04.908Z
[junit4] 2> 1707621 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-003/solr.xml
[junit4] 2> 1707693 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-003/.
[junit4] 2> 1707693 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1707707 INFO (coreLoadExecutor-6411-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1707717 INFO (coreLoadExecutor-6411-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1707722 INFO (coreLoadExecutor-6411-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1707725 INFO (coreLoadExecutor-6411-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-003/./collection1
[junit4] 2> 1707726 INFO (coreLoadExecutor-6411-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-003/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-003/./collection1/data/]
[junit4] 2> 1707726 INFO (coreLoadExecutor-6411-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=16, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.49999524564490694]
[junit4] 2> 1707736 INFO (coreLoadExecutor-6411-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1707736 INFO (coreLoadExecutor-6411-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1707736 INFO (coreLoadExecutor-6411-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1972558896365694]
[junit4] 2> 1707736 INFO (coreLoadExecutor-6411-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6d257909[collection1] main]
[junit4] 2> 1707737 INFO (coreLoadExecutor-6411-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-003/collection1/conf
[junit4] 2> 1707737 INFO (coreLoadExecutor-6411-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 1707737 INFO (coreLoadExecutor-6411-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1707737 INFO (searcherExecutor-6412-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@6d257909[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1708196 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-004/collection1
[junit4] 2> 1708201 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1708203 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2ddf7f07{/solr,null,AVAILABLE}
[junit4] 2> 1708203 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Started ServerConnector@6b97a2aa{HTTP/1.1,[http/1.1]}{127.0.0.1:50030}
[junit4] 2> 1708203 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server Started @1715125ms
[junit4] 2> 1708203 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-004/collection1/data, hostContext=/solr, hostPort=50030}
[junit4] 2> 1708204 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1708204 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0
[junit4] 2> 1708204 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1708204 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1708205 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-23T02:22:05.492Z
[junit4] 2> 1708205 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-004/solr.xml
[junit4] 2> 1708227 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-004/.
[junit4] 2> 1708227 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1708243 INFO (coreLoadExecutor-6421-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1708252 INFO (coreLoadExecutor-6421-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1708253 INFO (coreLoadExecutor-6421-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1708255 INFO (coreLoadExecutor-6421-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-004/./collection1
[junit4] 2> 1708255 INFO (coreLoadExecutor-6421-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-004/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-004/./collection1/data/]
[junit4] 2> 1708256 INFO (coreLoadExecutor-6421-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=16, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.49999524564490694]
[junit4] 2> 1708264 INFO (coreLoadExecutor-6421-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1708264 INFO (coreLoadExecutor-6421-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1708265 INFO (coreLoadExecutor-6421-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1972558896365694]
[junit4] 2> 1708265 INFO (coreLoadExecutor-6421-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@767d2225[collection1] main]
[junit4] 2> 1708266 INFO (coreLoadExecutor-6421-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-004/collection1/conf
[junit4] 2> 1708267 INFO (coreLoadExecutor-6421-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms
[junit4] 2> 1708267 INFO (searcherExecutor-6422-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@767d2225[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1708743 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@6b97a2aa{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1708743 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=2140854701
[junit4] 2> 1708743 INFO (coreCloseExecutor-6427-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@401ba4a0
[junit4] 2> 1708744 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2ddf7f07{/solr,null,UNAVAILABLE}
[junit4] 2> 1708748 INFO (qtp1409472159-12398) [ x:collection1] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 1708748 INFO (qtp1409472159-12398) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:*} 0 0
[junit4] 2> 1708749 INFO (qtp1409472159-12399) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1708749 INFO (qtp1409472159-12399) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@16f6021f
[junit4] 2> 1708750 INFO (qtp1409472159-12399) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@590cf48a[collection1] main]
[junit4] 2> 1708750 INFO (qtp1409472159-12399) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1708750 INFO (searcherExecutor-6412-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@590cf48a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1708750 INFO (qtp1409472159-12399) [ 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 1
[junit4] 2> 1708759 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@3afa7cec{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1708759 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=986715332
[junit4] 2> 1708760 INFO (coreCloseExecutor-6429-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3d577ef4
[junit4] 2> 1708761 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@43f10f03{/solr,null,UNAVAILABLE}
[junit4] 2> 1708763 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 1708764 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@de1db56{/solr,null,AVAILABLE}
[junit4] 2> 1708765 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Started ServerConnector@793b4707{HTTP/1.1,[http/1.1]}{127.0.0.1:50032}
[junit4] 2> 1708765 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.Server Started @1715687ms
[junit4] 2> 1708765 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-003/collection1/data, hostContext=/solr, hostPort=50032}
[junit4] 2> 1708766 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1708766 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0
[junit4] 2> 1708766 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 1708766 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1708766 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-23T02:22:06.054Z
[junit4] 2> 1708766 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-003/solr.xml
[junit4] 2> 1708820 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-003/.
[junit4] 2> 1708821 INFO (TEST-TestReplicationHandler.doTestReplicateAfterStartup-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1708827 INFO (coreLoadExecutor-6436-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1708835 INFO (coreLoadExecutor-6436-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1708838 INFO (coreLoadExecutor-6436-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1708839 INFO (coreLoadExecutor-6436-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-003/./collection1
[junit4] 2> 1708839 INFO (coreLoadExecutor-6436-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-003/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-003/./collection1/data/]
[junit4] 2> 1708840 INFO (coreLoadExecutor-6436-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=16, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.49999524564490694]
[junit4] 2> 1708846 INFO (coreLoadExecutor-6436-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1708846 INFO (coreLoadExecutor-6436-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1708846 INFO (coreLoadExecutor-6436-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1972558896365694]
[junit4] 2> 1708846 INFO (coreLoadExecutor-6436-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3f8a46e5[collection1] main]
[junit4] 2> 1708847 INFO (coreLoadExecutor-6436-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001/solr-instance-003/collection1/conf
[junit4] 2> 1708847 INFO (coreLoadExecutor-6436-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml
[junit4] 2> 1708847 INFO (coreLoadExecutor-6436-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1708847 INFO (searcherExecutor-6437-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3f8a46e5[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1709334 INFO (qtp624179956-12436) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0]} 0 0
[junit4] 2> 1709335 INFO (qtp624179956-12437) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1]} 0 0
[j
[...truncated too long message...]
lr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:397)
[junit4] 2> at org.apache.solr.handler.ReplicationHandler.lambda$handleRequestBody$0(ReplicationHandler.java:279)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 1799494 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=37, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3753232950933666]
[junit4] 2> 1799500 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 1799511 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@47a30b81[collection1] main]
[junit4] 2> 1799511 INFO (searcherExecutor-6994-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@47a30b81[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C195) Uninverting(_1(7.0.0):C106) Uninverting(_2(7.0.0):C121) Uninverting(_3(7.0.0):C147) Uninverting(_4(7.0.0):C3) Uninverting(_5(7.0.0):C172) Uninverting(_6(7.0.0):C8) Uninverting(_7(7.0.0):C167)))}
[junit4] 2> 1799512 INFO (qtp1066831090-13248) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:50201/solr/collection1/replication&command=fetchindex} status=0 QTime=11202
[junit4] 2> 1799516 INFO (qtp1066831090-13246) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=*:*&sort=id+desc&wt=javabin&version=2} hits=919 status=0 QTime=0
[junit4] 2> 1799516 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 919 docs
[junit4] 2> 1799528 INFO (qtp1394839426-13271) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=8
[junit4] 2> 1799530 INFO (qtp1394839426-13266) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=1
[junit4] 2> 1799541 INFO (qtp1394839426-13270) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={slave=false&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=1
[junit4] 2> 1799542 INFO (qtp1066831090-13251) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=10
[junit4] 2> 1799542 INFO (qtp1394839426-13269) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 1799543 INFO (qtp1066831090-13252) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 1> [index, snapshot_metadata]
[junit4] 1> [index.20161123052324909, index.properties, replication.properties, snapshot_metadata]
[junit4] 2> 1799544 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.SolrTestCaseJ4 ###Ending doTestStressReplication
[junit4] 2> 1799545 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@610b682{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1799546 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1063016449
[junit4] 2> 1799546 INFO (coreCloseExecutor-7000-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@262ac575
[junit4] 2> 1799548 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1671cf39{/solr,null,UNAVAILABLE}
[junit4] 2> 1799549 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@30f26cb4{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1799549 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[2D12FCFA30364B96]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=956235774
[junit4] 2> 1799550 INFO (coreCloseExecutor-7002-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1951ee8
[junit4] 2> 1799552 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[2D12FCFA30364B96]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@70e343c4{/solr,null,UNAVAILABLE}
[junit4] 2> 1799554 INFO (SUITE-TestReplicationHandler-seed#[2D12FCFA30364B96]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_2D12FCFA30364B96-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {name=FSTOrd50, id=FSTOrd50, newname=FSTOrd50}, docValues:{}, maxPointsInLeafNode=1682, maxMBSortInHeap=6.032462356600124, sim=RandomSimilarity(queryNorm=true): {}, locale=sq-AL, timezone=Indian/Antananarivo
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_102 (64-bit)/cpus=3,threads=1,free=289776408,total=447270912
[junit4] 2> NOTE: All tests run in this JVM: [TestLeaderElectionWithEmptyReplica, TestRestManager, TestManagedResource, CleanupOldIndexTest, CloneFieldUpdateProcessorFactoryTest, TestCustomSort, TestShardHandlerFactory, TestFieldResource, CollectionsAPIDistributedZkTest, TestWriterPerf, BasicAuthIntegrationTest, TestLMDirichletSimilarityFactory, MigrateRouteKeyTest, HdfsRecoverLeaseTest, TestCoreDiscovery, TestAnalyzedSuggestions, TestUtils, TestFieldCacheReopen, TestSchemaVersionResource, SparseHLLTest, CursorMarkTest, TestOmitPositions, TestStandardQParsers, ReturnFieldsTest, DistribCursorPagingTest, DistributedVersionInfoTest, TestNRTOpen, ScriptEngineTest, CoreSorterTest, TestJoin, LeaderInitiatedRecoveryOnCommitTest, TestDistributedMissingSort, SuggesterTSTTest, TestCollectionAPI, TestXmlQParserPlugin, TestSimpleTrackingShardHandler, TestConfigSetProperties, TestInfoStreamLogging, UUIDUpdateProcessorFallbackTest, RegexBoostProcessorTest, TestLegacyNumericRangeQueryBuilder, TestFieldCacheSort, DateRangeFieldTest, FullSolrCloudDistribCmdsTest, TestIndexingPerformance, PreAnalyzedUpdateProcessorTest, ConfigSetsAPITest, TestDistributedGrouping, TestSubQueryTransformerCrossCore, TestConfigSetsAPIExclusivity, SpellCheckComponentTest, FieldAnalysisRequestHandlerTest, TestFuzzyAnalyzedSuggestions, SpatialHeatmapFacetsTest, AnalyticsMergeStrategyTest, ConvertedLegacyTest, TestManagedSchema, TestRecovery, SolrCLIZkUtilsTest, ReplaceNodeTest, TestCryptoKeys, TestValueSourceCache, ExplicitHLLTest, QueryResultKeyTest, RAMDirectoryFactoryTest, BJQParserTest, ZkStateReaderTest, TestCrossCoreJoin, TestSolr4Spatial2, TestFilteredDocIdSet, TestFieldTypeResource, JsonLoaderTest, TestQuerySenderListener, HdfsDirectoryTest, TestRawTransformer, TestReplicaProperties, NotRequiredUniqueKeyTest, TestReplicationHandlerBackup, InfoHandlerTest, TestConfig, TestCloudRecovery, CSVRequestHandlerTest, TestReload, TriLevelCompositeIdRoutingTest, MinimalSchemaTest, TestSolrCoreProperties, TestTolerantUpdateProcessorRandomCloud, BadComponentTest, TestJsonFacets, TestCloudDeleteByQuery, TestScoreJoinQPScore, DistanceFunctionTest, ExternalFileFieldSortTest, ReplicaListTransformerTest, DistributedFacetPivotSmallTest, HdfsChaosMonkeyNothingIsSafeTest, TestCorePropertiesReload, TestNonDefinedSimilarityFactory, EchoParamsTest, BasicFunctionalityTest, SegmentsInfoRequestHandlerTest, CircularListTest, HttpPartitionTest, TestDynamicFieldResource, TestSolrCloudSnapshots, TestSolrDeletionPolicy2, EnumFieldTest, TestRandomRequestDistribution, CreateCollectionCleanupTest, DirectUpdateHandlerOptimizeTest, TestDocSet, HighlighterMaxOffsetTest, SharedFSAutoReplicaFailoverUtilsTest, TestShortCircuitedRequests, TestZkChroot, SpellPossibilityIteratorTest, URLClassifyProcessorTest, TestSolrQueryParserDefaultOperatorResource, TestMacros, CollectionReloadTest, DebugComponentTest, CollectionsAPISolrJTest, TermVectorComponentDistributedTest, RulesTest, TestHashQParserPlugin, TestSystemIdResolver, TestUseDocValuesAsStored, RestartWhileUpdatingTest, ResourceLoaderTest, TestStressRecovery, OverseerRolesTest, BooleanFieldTest, TestFoldingMultitermQuery, TestComponentsName, FieldMutatingUpdateProcessorTest, WordBreakSolrSpellCheckerTest, TestSolrCLIRunExample, AddBlockUpdateTest, IgnoreCommitOptimizeUpdateProcessorFactoryTest, SpellCheckCollatorTest, TestLeaderInitiatedRecoveryThread, CdcrBootstrapTest, UtilsToolTest, SolrInfoMBeanTest, TestTrackingShardHandlerFactory, AsyncCallRequestStatusResponseTest, TestRandomFaceting, TestSolrDynamicMBean, CoreAdminHandlerTest, DeleteNodeTest, TestTrie, TestReRankQParserPlugin, SolrXmlInZkTest, CdcrVersionReplicationTest, TestCodecSupport, BasicZkTest, TestReplicationHandler]
[junit4] Completed [338/653 (1!)] on J1 in 100.28s, 15 tests, 1 failure, 1 skipped <<< FAILURES!
[...truncated 63380 lines...]