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 2017/01/13 08:41:49 UTC
[JENKINS] Lucene-Solr-master-Solaris (64bit/jdk1.8.0) - Build #
1076 - Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/1076/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseSerialGC
2 tests failed.
FAILED: org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication
Error Message:
[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-017/./collection1/data/index.20170113165512555, /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-017/./collection1/data, /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-017/./collection1/data/snapshot_metadata, /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-017/./collection1/data/index.20170113165512430] expected:<3> but was:<4>
Stack Trace:
java.lang.AssertionError: [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-017/./collection1/data/index.20170113165512555, /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-017/./collection1/data, /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-017/./collection1/data/snapshot_metadata, /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-017/./collection1/data/index.20170113165512430] expected:<3> but was:<4>
at __randomizedtesting.SeedInfo.seed([4BF88155B9B629BC:BC8B6F0D7F5E865A]: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:918)
at org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication(TestReplicationHandler.java:1350)
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)
FAILED: org.apache.solr.handler.component.TestDistributedStatsComponentCardinality.test
Error Message:
int_i: goodEst=13949, poorEst=13970, real=13974, p=q=id:[24+TO+13997]&rows=0&stats=true&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_int_i}int_i&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_int_i_prehashed_l+hllPreHashed%3Dtrue}int_i_prehashed_l&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_int_i}int_i&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_int_i_prehashed_l+hllPreHashed%3Dtrue}int_i_prehashed_l&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_long_l}long_l&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_long_l_prehashed_l+hllPreHashed%3Dtrue}long_l_prehashed_l&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_long_l}long_l&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_long_l_prehashed_l+hllPreHashed%3Dtrue}long_l_prehashed_l&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_string_s}string_s&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_string_s_prehashed_l+hllPreHashed%3Dtrue}string_s_prehashed_l&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_string_s}string_s&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_string_s_prehashed_l+hllPreHashed%3Dtrue}string_s_prehashed_l
Stack Trace:
java.lang.AssertionError: int_i: goodEst=13949, poorEst=13970, real=13974, p=q=id:[24+TO+13997]&rows=0&stats=true&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_int_i}int_i&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_int_i_prehashed_l+hllPreHashed%3Dtrue}int_i_prehashed_l&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_int_i}int_i&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_int_i_prehashed_l+hllPreHashed%3Dtrue}int_i_prehashed_l&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_long_l}long_l&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_long_l_prehashed_l+hllPreHashed%3Dtrue}long_l_prehashed_l&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_long_l}long_l&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_long_l_prehashed_l+hllPreHashed%3Dtrue}long_l_prehashed_l&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_string_s}string_s&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_string_s_prehashed_l+hllPreHashed%3Dtrue}string_s_prehashed_l&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_string_s}string_s&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_string_s_prehashed_l+hllPreHashed%3Dtrue}string_s_prehashed_l
at __randomizedtesting.SeedInfo.seed([4BF88155B9B629BC:C3ACBE8F174A4444]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.handler.component.TestDistributedStatsComponentCardinality.test(TestDistributedStatsComponentCardinality.java:217)
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 org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:985)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:960)
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 10806 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/init-core-data-001
[junit4] 2> 147129 INFO (SUITE-TestReplicationHandler-seed#[4BF88155B9B629BC]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None)
[junit4] 2> 147135 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.SolrTestCaseJ4 ###Starting doTestStressReplication
[junit4] 2> 147136 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-001/collection1
[junit4] 2> 147144 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 147145 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@387331ba{/solr,null,AVAILABLE}
[junit4] 2> 147148 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2529c529{HTTP/1.1,[http/1.1]}{127.0.0.1:50178}
[junit4] 2> 147148 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.Server Started @150703ms
[junit4] 2> 147148 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=50178}
[junit4] 2> 147149 ERROR (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 147149 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0
[junit4] 2> 147149 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 147149 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 147149 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-13T07:24:34.607Z
[junit4] 2> 147150 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-001/solr.xml
[junit4] 2> 147167 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-001/.
[junit4] 2> 147168 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 147195 WARN (coreLoadExecutor-186-thread-1) [ x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 147196 INFO (coreLoadExecutor-186-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 147218 INFO (coreLoadExecutor-186-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 147233 INFO (coreLoadExecutor-186-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 147236 INFO (coreLoadExecutor-186-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-001/./collection1
[junit4] 2> 147237 INFO (coreLoadExecutor-186-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-001/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-001/./collection1/data/]
[junit4] 2> 147240 INFO (coreLoadExecutor-186-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=2137739492, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 147271 INFO (coreLoadExecutor-186-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 147271 INFO (coreLoadExecutor-186-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 147272 INFO (coreLoadExecutor-186-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=47, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8492621479415416]
[junit4] 2> 147272 INFO (coreLoadExecutor-186-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@453ee316[collection1] main]
[junit4] 2> 147273 INFO (coreLoadExecutor-186-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-001/collection1/conf
[junit4] 2> 147274 INFO (coreLoadExecutor-186-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 147274 INFO (coreLoadExecutor-186-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 147274 INFO (searcherExecutor-187-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@453ee316[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 147289 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/collection1
[junit4] 2> 147292 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 147295 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@21191e03{/solr,null,AVAILABLE}
[junit4] 2> 147296 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@451d83db{HTTP/1.1,[http/1.1]}{127.0.0.1:48778}
[junit4] 2> 147296 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.Server Started @150851ms
[junit4] 2> 147296 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/collection1/data, hostContext=/solr, hostPort=48778}
[junit4] 2> 147297 ERROR (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 147297 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0
[junit4] 2> 147297 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 147297 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 147297 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-13T07:24:34.755Z
[junit4] 2> 147298 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/solr.xml
[junit4] 2> 147311 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/.
[junit4] 2> 147311 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 147374 WARN (coreLoadExecutor-196-thread-1) [ x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 147376 INFO (coreLoadExecutor-196-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 147398 INFO (coreLoadExecutor-196-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 147400 INFO (coreLoadExecutor-196-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 147401 INFO (coreLoadExecutor-196-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/./collection1
[junit4] 2> 147401 INFO (coreLoadExecutor-196-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/./collection1/data/]
[junit4] 2> 147405 INFO (coreLoadExecutor-196-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=2137739492, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 147429 INFO (coreLoadExecutor-196-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 147429 INFO (coreLoadExecutor-196-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 147429 INFO (coreLoadExecutor-196-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=47, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8492621479415416]
[junit4] 2> 147430 INFO (coreLoadExecutor-196-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@717ddd76[collection1] main]
[junit4] 2> 147430 INFO (coreLoadExecutor-196-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/collection1/conf
[junit4] 2> 147447 INFO (coreLoadExecutor-196-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms
[junit4] 2> 147455 INFO (searcherExecutor-197-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@717ddd76[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 147460 INFO (qtp2026695925-1895) [ 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=1
[junit4] 2> 147462 INFO (indexFetcher-201-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 147462 INFO (indexFetcher-201-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 147462 INFO (indexFetcher-201-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 147462 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@451d83db{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 147462 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1649141286
[junit4] 2> 147464 INFO (coreCloseExecutor-202-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@64bf81ab
[junit4] 2> 147476 INFO (coreCloseExecutor-202-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 147477 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 147477 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@21191e03{/solr,null,UNAVAILABLE}
[junit4] 2> 147484 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 147485 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@194ecf6a{/solr,null,AVAILABLE}
[junit4] 2> 147485 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@b147c90{HTTP/1.1,[http/1.1]}{127.0.0.1:42753}
[junit4] 2> 147485 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.Server Started @151040ms
[junit4] 2> 147485 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/collection1/data, hostContext=/solr, hostPort=42753}
[junit4] 2> 147485 ERROR (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 147491 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0
[junit4] 2> 147491 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 147491 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 147491 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-13T07:24:34.949Z
[junit4] 2> 147491 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/solr.xml
[junit4] 2> 147501 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/.
[junit4] 2> 147501 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 147567 WARN (coreLoadExecutor-209-thread-1) [ x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 147569 INFO (coreLoadExecutor-209-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 147587 INFO (coreLoadExecutor-209-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 147590 INFO (coreLoadExecutor-209-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 147591 INFO (coreLoadExecutor-209-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/./collection1
[junit4] 2> 147602 INFO (coreLoadExecutor-209-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/./collection1/data/]
[junit4] 2> 147604 INFO (coreLoadExecutor-209-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=36, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5004542877467401]
[junit4] 2> 147619 INFO (coreLoadExecutor-209-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 147619 INFO (coreLoadExecutor-209-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 147620 INFO (coreLoadExecutor-209-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=59.203125, floorSegmentMB=2.0390625, forceMergeDeletesPctAllowed=20.208512680390392, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 147621 INFO (coreLoadExecutor-209-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1dc73c98[collection1] main]
[junit4] 2> 147621 INFO (coreLoadExecutor-209-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/collection1/conf
[junit4] 2> 147621 INFO (coreLoadExecutor-209-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 147622 INFO (searcherExecutor-210-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1dc73c98[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 148050 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@2529c529{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 148050 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=143341975
[junit4] 2> 148052 INFO (coreCloseExecutor-214-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@ed06c4d
[junit4] 2> 148055 INFO (coreCloseExecutor-214-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 148056 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 148056 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@387331ba{/solr,null,UNAVAILABLE}
[junit4] 2> 148060 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 148061 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@ade3389{/solr,null,AVAILABLE}
[junit4] 2> 148062 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5fce0c94{HTTP/1.1,[http/1.1]}{127.0.0.1:58606}
[junit4] 2> 148078 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.Server Started @151633ms
[junit4] 2> 148078 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=58606}
[junit4] 2> 148079 ERROR (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 148079 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0
[junit4] 2> 148079 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 148079 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 148080 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-13T07:24:35.538Z
[junit4] 2> 148080 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-001/solr.xml
[junit4] 2> 148092 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-001/.
[junit4] 2> 148092 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 148106 WARN (coreLoadExecutor-221-thread-1) [ x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 148107 INFO (coreLoadExecutor-221-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 148128 INFO (coreLoadExecutor-221-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 148131 INFO (coreLoadExecutor-221-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 148133 INFO (coreLoadExecutor-221-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-001/./collection1
[junit4] 2> 148133 INFO (coreLoadExecutor-221-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-001/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-001/./collection1/data/]
[junit4] 2> 148135 INFO (coreLoadExecutor-221-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=36, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5004542877467401]
[junit4] 2> 148151 INFO (coreLoadExecutor-221-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 148151 INFO (coreLoadExecutor-221-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 148153 INFO (coreLoadExecutor-221-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=59.203125, floorSegmentMB=2.0390625, forceMergeDeletesPctAllowed=20.208512680390392, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 148156 INFO (coreLoadExecutor-221-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4588b089[collection1] main]
[junit4] 2> 148156 INFO (coreLoadExecutor-221-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-001/collection1/conf
[junit4] 2> 148157 INFO (coreLoadExecutor-221-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml
[junit4] 2> 148157 INFO (coreLoadExecutor-221-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 148157 INFO (searcherExecutor-222-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4588b089[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 148238 INFO (qtp425459192-1955) [ x:collection1] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 148240 INFO (qtp425459192-1955) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:*} 0 19
[junit4] 2> 148244 INFO (qtp1238983389-1933) [ x:collection1] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 148245 INFO (qtp1238983389-1933) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:*} 0 1
[junit4] 2> 148248 INFO (qtp1238983389-1937) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 148248 INFO (qtp1238983389-1937) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@53e13c2a
[junit4] 2> 148253 INFO (qtp1238983389-1937) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5919575a[collection1] main]
[junit4] 2> 148254 INFO (qtp1238983389-1937) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 148254 INFO (searcherExecutor-210-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5919575a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 148254 INFO (qtp1238983389-1937) [ 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 5
[junit4] 2> 148259 INFO (qtp425459192-1959) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0]} 0 3
[junit4] 2> 148261 INFO (qtp425459192-1960) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1]} 0 0
[junit4] 2> 148263 INFO (qtp425459192-1960) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2]} 0 0
[junit4] 2> 148265 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[3]} 0 0
[junit4] 2> 148266 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[4]} 0 0
[junit4] 2> 148268 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[5]} 0 0
[junit4] 2> 148269 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[6]} 0 0
[junit4] 2> 148270 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[7]} 0 0
[junit4] 2> 148271 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[8]} 0 0
[junit4] 2> 148273 INFO (qtp425459192-1958) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[9]} 0 0
[junit4] 2> 148277 INFO (qtp425459192-1956) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[10]} 0 0
[junit4] 2> 148279 INFO (qtp425459192-1955) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[11]} 0 0
[junit4] 2> 148280 INFO (qtp425459192-1955) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[12]} 0 0
[junit4] 2> 148281 INFO (qtp425459192-1955) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[13]} 0 0
[junit4] 2> 148285 INFO (qtp425459192-1960) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[14]} 0 0
[junit4] 2> 148286 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[15]} 0 0
[junit4] 2> 148287 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[16]} 0 0
[junit4] 2> 148288 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[17]} 0 0
[junit4] 2> 148290 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[18]} 0 0
[junit4] 2> 148291 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[19]} 0 0
[junit4] 2> 148293 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[20]} 0 0
[junit4] 2> 148294 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[21]} 0 0
[junit4] 2> 148295 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[22]} 0 0
[junit4] 2> 148296 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[23]} 0 0
[junit4] 2> 148297 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[24]} 0 0
[junit4] 2> 148298 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[25]} 0 0
[junit4] 2> 148299 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[26]} 0 0
[junit4] 2> 148301 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[27]} 0 0
[junit4] 2> 148302 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[28]} 0 0
[junit4] 2> 148303 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[29]} 0 0
[junit4] 2> 148304 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[30]} 0 0
[junit4] 2> 148305 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[31]} 0 0
[junit4] 2> 148307 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[32]} 0 0
[junit4] 2> 148308 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[33]} 0 0
[junit4] 2> 148309 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[34]} 0 0
[junit4] 2> 148310 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[35]} 0 0
[junit4] 2> 148311 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[36]} 0 0
[junit4] 2> 148312 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[37]} 0 0
[junit4] 2> 148313 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[38]} 0 0
[junit4] 2> 148315 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[39]} 0 0
[junit4] 2> 148316 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[40]} 0 0
[junit4] 2> 148317 INFO (qtp425459192-1958) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[41]} 0 0
[junit4] 2> 148318 INFO (qtp425459192-1958) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[42]} 0 0
[junit4] 2> 148320 INFO (qtp425459192-1958) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[43]} 0 0
[junit4] 2> 148321 INFO (qtp425459192-1958) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[44]} 0 0
[junit4] 2> 148322 INFO (qtp425459192-1958) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[45]} 0 0
[junit4] 2> 148323 INFO (qtp425459192-1960) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[46]} 0 0
[junit4] 2> 148324 INFO (qtp425459192-1960) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[47]} 0 0
[junit4] 2> 148325 INFO (qtp425459192-1960) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[48]} 0 0
[junit4] 2> 148328 INFO (qtp425459192-1960) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[49]} 0 0
[junit4] 2> 148329 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[50]} 0 0
[junit4] 2> 148330 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[51]} 0 0
[junit4] 2> 148331 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[52]} 0 0
[junit4] 2> 148332 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[53]} 0 0
[junit4] 2> 148333 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[54]} 0 0
[junit4] 2> 148334 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[55]} 0 0
[junit4] 2> 148335 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[56]} 0 0
[junit4] 2> 148337 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[57]} 0 0
[junit4] 2> 148338 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[58]} 0 0
[junit4] 2> 148339 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[59]} 0 0
[junit4] 2> 148340 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[60]} 0 0
[junit4] 2> 148341 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[61]} 0 0
[junit4] 2> 148342 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[62]} 0 0
[junit4] 2> 148343 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[63]} 0 0
[junit4] 2> 148344 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[64]} 0 0
[junit4] 2> 148346 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[65]} 0 0
[junit4] 2> 148347 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[66]} 0 0
[junit4] 2> 148348 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[67]} 0 0
[junit4] 2> 148349 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[68]} 0 0
[junit4] 2> 148350 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[69]} 0 0
[junit4] 2> 148351 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[70]} 0 0
[junit4] 2> 148352 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[71]} 0 0
[junit4] 2> 148353 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[72]} 0 0
[junit4] 2> 148355 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[73]} 0 0
[junit4] 2> 148356 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[74]} 0 0
[junit4] 2> 148357 INFO (qtp425459192-1955) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[75]} 0 0
[junit4] 2> 148358 INFO (qtp425459192-1955) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[76]} 0 0
[junit4] 2> 148360 INFO (qtp425459192-1955) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[77]} 0 0
[junit4] 2> 148361 INFO (qtp425459192-1956) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 148361 INFO (qtp425459192-1956) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@4b6daaaf
[junit4] 2> 148381 INFO (qtp425459192-1956) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@41a9debc[collection1] main]
[junit4] 2> 148381 INFO (qtp425459192-1956) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 148381 INFO (searcherExecutor-222-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@41a9debc[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C78)))}
[junit4] 2> 148382 INFO (qtp425459192-1956) [ 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 20
[junit4] 2> 148389 INFO (qtp425459192-1959) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=*:*&sort=id+desc&wt=javabin&version=2} hits=78 status=0 QTime=2
[junit4] 2> 148395 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 78 docs
[junit4] 2> 148403 INFO (qtp1238983389-1942) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=collection1&action=status&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 148407 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 148411 INFO (qtp425459192-1961) [ 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> 148411 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 2
[junit4] 2> 148411 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1484292275819
[junit4] 2> 148411 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 2
[junit4] 2> 148411 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 148418 INFO (qtp425459192-1961) [ 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=6
[junit4] 2> 148419 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 10
[junit4] 2> 148420 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=true) to MetricsDirectory(NRTCachingDirectory(MMapDirectory@/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/collection1/data/index.20170113165435877 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@581a6b02; maxCacheMB=48.0 maxMergeSizeMB=4.0))
[junit4] 2> 148430 INFO (qtp425459192-1961) [ 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=3
[junit4] 2> 148437 INFO (qtp425459192-1961) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene50_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148439 INFO (qtp425459192-1961) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene50_0.tim&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148442 INFO (qtp425459192-1961) [ 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> 148444 INFO (qtp425459192-1961) [ 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> 148447 INFO (qtp425459192-1958) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene50_0.tip&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148450 INFO (qtp425459192-1962) [ 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> 148462 INFO (qtp425459192-1955) [ 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> 148465 INFO (qtp425459192-1955) [ 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> 148466 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher File segments_2 did not match. expected checksum is 3642563681 and actual is checksum 1431637796. expected length is 165 and actual length is 100
[junit4] 2> 148467 INFO (qtp425459192-1956) [ 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> 148468 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=true,bytesDownloaded=3085) : 0 secs (null bytes/sec) to MetricsDirectory(NRTCachingDirectory(MMapDirectory@/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/collection1/data/index.20170113165435877 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@581a6b02; maxCacheMB=48.0 maxMergeSizeMB=4.0))
[junit4] 2> 148469 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher New index installed. Updating index properties... index=index.20170113165435877
[junit4] 2> 148473 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher removing old index directory MetricsDirectory(NRTCachingDirectory(MMapDirectory@/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/collection1/data/index lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6ea07481; maxCacheMB=48.0 maxMergeSizeMB=4.0))
[junit4] 2> 148476 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=36, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5004542877467401]
[junit4] 2> 148479 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 148481 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@44fbd570[collection1] main]
[junit4] 2> 148482 INFO (searcherExecutor-210-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@44fbd570[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C78)))}
[junit4] 2> 148482 INFO (qtp1238983389-1938) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:58606/solr/collection1/replication&command=fetchindex} status=0 QTime=76
[junit4] 2> 148490 INFO (qtp1238983389-1936) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=*:*&sort=id+desc&wt=javabin&version=2} hits=78 status=0 QTime=1
[junit4] 2> 148495 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 78 docs
[junit4] 2> 148500 INFO (qtp425459192-1959) [ 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=2
[junit4] 2> 148502 INFO (qtp425459192-1960) [ 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=0
[junit4] 2> 148507 INFO (qtp425459192-1961) [ 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=0
[junit4] 2> 148508 INFO (qtp1238983389-1933) [ 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=5
[junit4] 2> 148509 INFO (qtp425459192-1958) [ 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> 148510 INFO (qtp1238983389-1937) [ 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> [replication.properties, index.properties, snapshot_metadata, index.20170113165435877]
[junit4] 2> 148517 INFO (qtp1238983389-1939) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[78]} 0 3
[junit4] 2> 148518 INFO (qtp1238983389-1942) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[79]} 0 0
[junit4] 2> 148519 INFO (qtp1238983389-1943) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[80]} 0 0
[junit4] 2> 148520 INFO (qtp1238983389-1940) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 148521 INFO (qtp1238983389-1940) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@52a5426
[junit4] 2> 148537 INFO (qtp1238983389-1940) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2eb101c9[collection1] main]
[junit4] 2> 148537 INFO (qtp1238983389-1940) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 148537 INFO (searcherExecutor-210-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2eb101c9[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C78) Uninverting(_1(7.0.0):C3)))}
[junit4] 2> 148538 INFO (qtp1238983389-1940) [ 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 17
[junit4] 2> 148540 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[81]} 0 1
[junit4] 2> 148541 INFO (qtp425459192-1955) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[82]} 0 0
[junit4] 2> 148543 INFO (qtp425459192-1956) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[83]} 0 0
[junit4] 2> 148544 INFO (qtp425459192-1959) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[84]} 0 0
[junit4] 2> 148545 INFO (qtp425459192-1960) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[85]} 0 0
[junit4] 2> 148546 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[86]} 0 0
[junit4] 2> 148547 INFO (qtp425459192-1958) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[87]} 0 0
[junit4] 2> 148548 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[88]} 0 0
[junit4] 2> 148549 INFO (qtp425459192-1955) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[89]} 0 0
[junit4] 2> 148551 INFO (qtp425459192-1956) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[90]} 0 0
[junit4] 2> 148552 INFO (qtp425459192-1959) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[91]} 0 0
[junit4] 2> 148552 INFO (qtp425459192-1960) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[92]} 0 0
[junit4] 2> 148554 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[93]} 0 0
[junit4] 2> 148555 INFO (qtp425459192-1958) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[94]} 0 0
[junit4] 2> 148556 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[95]} 0 0
[junit4] 2> 148557 INFO (qtp425459192-1955) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[96]} 0 0
[junit4] 2> 148559 INFO (qtp425459192-1956) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[97]} 0 0
[junit4] 2> 148560 INFO (qtp425459192-1959) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[98]} 0 0
[junit4] 2> 148561 INFO (qtp425459192-1960) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[99]} 0 0
[junit4] 2> 148562 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[100]} 0 0
[junit4] 2> 148563 INFO (qtp425459192-1958) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[101]} 0 0
[junit4] 2> 148564 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[102]} 0 0
[junit4] 2> 148565 INFO (qtp425459192-1955) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[103]} 0 0
[junit4] 2> 148566 INFO (qtp425459192-1956) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[104]} 0 0
[junit4] 2> 148567 INFO (qtp425459192-1959) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[105]} 0 0
[junit4] 2> 148569 INFO (qtp425459192-1960) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[106]} 0 0
[junit4] 2> 148570 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[107]} 0 0
[junit4] 2> 148571 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[108]} 0 0
[junit4] 2> 148572 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[109]} 0 0
[junit4] 2> 148573 INFO (qtp425459192-1955) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[110]} 0 0
[junit4] 2> 148574 INFO (qtp425459192-1956) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[111]} 0 0
[junit4] 2> 148575 INFO (qtp425459192-1959) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[112]} 0 0
[junit4] 2> 148576 INFO (qtp425459192-1960) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[113]} 0 0
[junit4] 2> 148577 INFO (qtp425459192-1958) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[114]} 0 0
[junit4] 2> 148579 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[115]} 0 0
[junit4] 2> 148580 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[116]} 0 0
[junit4] 2> 148581 INFO (qtp425459192-1955) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[117]} 0 0
[junit4] 2> 148582 INFO (qtp425459192-1956) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[118]} 0 0
[junit4] 2> 148583 INFO (qtp425459192-1959) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[119]} 0 0
[junit4] 2> 148584 INFO (qtp425459192-1959) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[120]} 0 0
[junit4] 2> 148585 INFO (qtp425459192-1958) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[121]} 0 0
[junit4] 2> 148586 INFO (qtp425459192-1961) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[122]} 0 0
[junit4] 2> 148587 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 148588 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@4b6daaaf
[junit4] 2> 148604 INFO (qtp425459192-1962) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5cd2100e[collection1] main]
[junit4] 2> 148604 INFO (qtp425459192-1962) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 148604 INFO (searcherExecutor-222-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5cd2100e[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C78) Uninverting(_1(7.0.0):C42)))}
[junit4] 2> 148604 INFO (qtp425459192-1962) [ 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 17
[junit4] 2> 148607 INFO (qtp425459192-1955) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=*:*&sort=id+desc&wt=javabin&version=2} hits=120 status=0 QTime=1
[junit4] 2> 148609 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[4BF88155B9B629BC]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 120 docs
[junit4] 2> 148614 INFO (qtp1238983389-1938) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=collection1&action=status&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 148618 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 148623 INFO (qtp425459192-1956) [ 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> 148625 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 3
[junit4] 2> 148625 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1484292276046
[junit4] 2> 148625 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 3
[junit4] 2> 148625 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 148649 INFO (qtp425459192-1956) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&wt=javabin&version=2&command=filelist} status=0 QTime=21
[junit4] 2> 148650 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 19
[junit4] 2> 148652 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=true) to MetricsDirectory(NRTCachingDirectory(MMapDirectory@/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_4BF88155B9B629BC-001/solr-instance-002/collection1/data/index.20170113165436108 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@586988d1; maxCacheMB=48.0 maxMergeSizeMB=4.0))
[junit4] 2> 148653 INFO (qtp425459192-1959) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148658 INFO (qtp425459192-1958) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0_Lucene50_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148660 INFO (qtp425459192-1961) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0_Lucene50_0.tim&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148664 INFO (qtp425459192-1962) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148667 INFO (qtp425459192-1955) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148670 INFO (qtp425459192-1960) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0_Lucene50_0.tip&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148673 INFO (qtp425459192-1960) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148677 INFO (qtp425459192-1956) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148683 INFO (qtp425459192-1959) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148685 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher File _1_Lucene50_0.doc did not match. expected checksum is 3089921068 and actual is checksum 631856481. expected length is 110 and actual length is 110
[junit4] 2> 148686 INFO (qtp425459192-1958) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1_Lucene50_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148688 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher File _1_Lucene50_0.tim did not match. expected checksum is 3129348390 and actual is checksum 970666645. expected length is 680 and actual length is 266
[junit4] 2> 148689 INFO (qtp425459192-1961) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1_Lucene50_0.tim&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148691 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher File _1.si did not match. expected checksum is 2311371242 and actual is checksum 1085254929. expected length is 433 and actual length is 433
[junit4] 2> 148707 INFO (qtp425459192-1961) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148709 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher File _1.nvd did not match. expected checksum is 1740204597 and actual is checksum 2037406342. expected length is 59 and actual length is 59
[junit4] 2> 148712 INFO (qtp425459192-1961) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148713 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher File _1.fdx did not match. expected checksum is 2948501238 and actual is checksum 1601444810. expected length is 84 and actual length is 83
[junit4] 2> 148715 INFO (qtp425459192-1961) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148717 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher File _1.fnm did not match. expected checksum is 4287743904 and actual is checksum 1730986198. expected length is 239 and actual length is 239
[junit4] 2> 148719 INFO (qtp425459192-1961) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 148721 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher File _1.nvm did not match. expected checksum is 2884014922 and actual is checksum 1455458760. expected length is 133 and actual length is 133
[junit4] 2> 148723 INFO (qtp425459192-1956) [ x:collection
[...truncated too long message...]
int_i_prehashed_l&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_long_l}long_l&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_long_l_prehashed_l+hllPreHashed%3Dtrue}long_l_prehashed_l&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_long_l}long_l&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_long_l_prehashed_l+hllPreHashed%3Dtrue}long_l_prehashed_l&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_string_s}string_s&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_string_s_prehashed_l+hllPreHashed%3Dtrue}string_s_prehashed_l&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_string_s}string_s&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_string_s_prehashed_l+hllPreHashed%3Dtrue}string_s_prehashed_l} hits=13974 status=0 QTime=37
[junit4] 2> 1448868 INFO (TEST-TestDistributedStatsComponentCardinality.test-seed#[4BF88155B9B629BC]) [ ] o.a.s.SolrTestCaseJ4 ###Ending test
[junit4] 2> 1448869 INFO (TEST-TestDistributedStatsComponentCardinality.test-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1ade9a38{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1448869 INFO (TEST-TestDistributedStatsComponentCardinality.test-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1842269698
[junit4] 2> 1448870 INFO (coreCloseExecutor-3831-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@7f604cbe
[junit4] 2> 1448933 INFO (coreCloseExecutor-3831-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 1448933 INFO (TEST-TestDistributedStatsComponentCardinality.test-seed#[4BF88155B9B629BC]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 1448934 INFO (TEST-TestDistributedStatsComponentCardinality.test-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@747cee8e{/u_g,null,UNAVAILABLE}
[junit4] 2> 1448940 INFO (TEST-TestDistributedStatsComponentCardinality.test-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@3e8808f6{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1448940 INFO (TEST-TestDistributedStatsComponentCardinality.test-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1152358815
[junit4] 2> 1448942 INFO (coreCloseExecutor-3833-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@6148175a
[junit4] 2> 1448998 INFO (coreCloseExecutor-3833-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 1449000 INFO (TEST-TestDistributedStatsComponentCardinality.test-seed#[4BF88155B9B629BC]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 1449001 INFO (TEST-TestDistributedStatsComponentCardinality.test-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@116ed28f{/u_g,null,UNAVAILABLE}
[junit4] 2> 1449004 INFO (TEST-TestDistributedStatsComponentCardinality.test-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@458338a2{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1449004 INFO (TEST-TestDistributedStatsComponentCardinality.test-seed#[4BF88155B9B629BC]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1981007599
[junit4] 2> 1449006 INFO (coreCloseExecutor-3835-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@7294a307
[junit4] 2> 1449029 INFO (coreCloseExecutor-3835-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 1449030 INFO (TEST-TestDistributedStatsComponentCardinality.test-seed#[4BF88155B9B629BC]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 1449030 INFO (TEST-TestDistributedStatsComponentCardinality.test-seed#[4BF88155B9B629BC]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5d5a4c58{/u_g,null,UNAVAILABLE}
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestDistributedStatsComponentCardinality -Dtests.method=test -Dtests.seed=4BF88155B9B629BC -Dtests.slow=true -Dtests.locale=sl-SI -Dtests.timezone=Australia/Darwin -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 26.9s J1 | TestDistributedStatsComponentCardinality.test <<<
[junit4] > Throwable #1: java.lang.AssertionError: int_i: goodEst=13949, poorEst=13970, real=13974, p=q=id:[24+TO+13997]&rows=0&stats=true&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_int_i}int_i&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_int_i_prehashed_l+hllPreHashed%3Dtrue}int_i_prehashed_l&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_int_i}int_i&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_int_i_prehashed_l+hllPreHashed%3Dtrue}int_i_prehashed_l&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_long_l}long_l&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_long_l_prehashed_l+hllPreHashed%3Dtrue}long_l_prehashed_l&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_long_l}long_l&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_long_l_prehashed_l+hllPreHashed%3Dtrue}long_l_prehashed_l&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_string_s}string_s&stats.field={!cardinality%3D0.0057088390826023905+key%3Dlow_string_s_prehashed_l+hllPreHashed%3Dtrue}string_s_prehashed_l&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_string_s}string_s&stats.field={!cardinality%3D0.5057088390826023+key%3Dhigh_string_s_prehashed_l+hllPreHashed%3Dtrue}string_s_prehashed_l
[junit4] > at __randomizedtesting.SeedInfo.seed([4BF88155B9B629BC:C3ACBE8F174A4444]:0)
[junit4] > at org.apache.solr.handler.component.TestDistributedStatsComponentCardinality.test(TestDistributedStatsComponentCardinality.java:217)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:985)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:960)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 1449037 INFO (SUITE-TestDistributedStatsComponentCardinality-seed#[4BF88155B9B629BC]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.handler.component.TestDistributedStatsComponentCardinality_4BF88155B9B629BC-001
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarity(queryNorm=true): {}, locale=sl-SI, timezone=Australia/Darwin
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_112 (64-bit)/cpus=3,threads=1,free=64240664,total=507338752
[junit4] 2> NOTE: All tests run in this JVM: [TestUnifiedSolrHighlighter, PreAnalyzedFieldTest, TestInitQParser, CoreAdminRequestStatusTest, TestPushWriter, HdfsUnloadDistributedZkTest, TestCodecSupport, TestTestInjection, TestExportWriter, TestExactStatsCache, TestLocalFSCloudBackupRestore, ExternalFileFieldSortTest, TestBinaryResponseWriter, TestRebalanceLeaders, EchoParamsTest, CacheHeaderTest, SolrJmxReporterTest, HdfsLockFactoryTest, CloudMLTQParserTest, FileBasedSpellCheckerTest, TestReload, HdfsCollectionsAPIDistributedZkTest, TestSolrCoreParser, CollectionTooManyReplicasTest, TestRangeQuery, EnumFieldTest, TestConfigReload, DistributedFacetPivotSmallAdvancedTest, AliasIntegrationTest, ZkStateReaderTest, HdfsRecoverLeaseTest, AnalyticsMergeStrategyTest, BasicDistributedZk2Test, TestValueSourceCache, TestSolr4Spatial, OverriddenZkACLAndCredentialsProvidersTest, TestSchemaResource, MinimalSchemaTest, SuggestComponentContextFilterQueryTest, TestSolrCloudWithSecureImpersonation, TestScoreJoinQPScore, TestUninvertingReader, DistributedQueryComponentOptimizationTest, BufferStoreTest, FullSolrCloudDistribCmdsTest, TestUtils, TestDefaultSearchFieldResource, TestSmileRequest, RegexBoostProcessorTest, TestOrdValues, TestIndexingPerformance, TestManagedResource, ZkSolrClientTest, FullHLLTest, DirectUpdateHandlerOptimizeTest, TestManagedSchemaAPI, SolrCmdDistributorTest, CollectionsAPIDistributedZkTest, TestSubQueryTransformerCrossCore, UpdateRequestProcessorFactoryTest, ScriptEngineTest, TestDownShardTolerantSearch, StressHdfsTest, SortByFunctionTest, SimpleCollectionCreateDeleteTest, ChaosMonkeySafeLeaderTest, ShardRoutingCustomTest, TestSolrIndexConfig, FieldMutatingUpdateProcessorTest, TestNonDefinedSimilarityFactory, TestCoreDiscovery, TestTolerantUpdateProcessorRandomCloud, SolrGangliaReporterTest, IndexSchemaTest, QueryResultKeyTest, TestAuthenticationFramework, TestAnalyzedSuggestions, TestSSLRandomization, TestNRTOpen, TestDocSet, TestConfig, TestRealTimeGet, LeaderElectionIntegrationTest, CdcrBootstrapTest, TestTrie, LeaderElectionContextKeyTest, TestEmbeddedSolrServerConstructors, SuggesterWFSTTest, TestQueryWrapperFilter, TestStressRecovery, TestCloudPseudoReturnFields, HLLUtilTest, TestMacroExpander, ClassificationUpdateProcessorIntegrationTest, OpenCloseCoreStressTest, UUIDFieldTest, TestMiniSolrCloudCluster, TestShardHandlerFactory, CdcrVersionReplicationTest, TemplateUpdateProcessorTest, TestChildDocTransformer, LukeRequestHandlerTest, TestPHPSerializedResponseWriter, TestAtomicUpdateErrorCases, TestSolrConfigHandlerConcurrent, TestDistributedStatsComponentCardinality]
[junit4] Completed [222/678 (2!)] on J1 in 26.91s, 1 test, 1 failure <<< FAILURES!
[...truncated 63915 lines...]
[JENKINS] Lucene-Solr-master-Solaris (64bit/jdk1.8.0) - Build #
1077 - Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/1077/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.PeerSyncReplicationTest.test
Error Message:
timeout waiting to see all nodes active
Stack Trace:
java.lang.AssertionError: timeout waiting to see all nodes active
at __randomizedtesting.SeedInfo.seed([4D52461D5849BB5:8C811BBB7B78F64D]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.PeerSyncReplicationTest.waitTillNodesActive(PeerSyncReplicationTest.java:326)
at org.apache.solr.cloud.PeerSyncReplicationTest.bringUpDeadNodeAndEnsureNoReplication(PeerSyncReplicationTest.java:277)
at org.apache.solr.cloud.PeerSyncReplicationTest.forceNodeFailureAndDoPeerSync(PeerSyncReplicationTest.java:259)
at org.apache.solr.cloud.PeerSyncReplicationTest.test(PeerSyncReplicationTest.java:138)
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 org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:985)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:960)
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 12201 lines...]
[junit4] Suite: org.apache.solr.cloud.PeerSyncReplicationTest
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/init-core-data-001
[junit4] 2> 2045429 INFO (SUITE-PeerSyncReplicationTest-seed#[4D52461D5849BB5]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 2045430 INFO (SUITE-PeerSyncReplicationTest-seed#[4D52461D5849BB5]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /uj/
[junit4] 2> 2045431 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2045432 INFO (Thread-4289) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2045432 INFO (Thread-4289) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2045532 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.ZkTestServer start zk server on port:33981
[junit4] 2> 2045547 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 2045550 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 2045553 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2045556 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 2045558 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 2045560 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 2045562 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 2045565 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 2045567 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2045569 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 2045572 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 2045711 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/control-001/cores/collection1
[junit4] 2> 2045712 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2045713 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@54f9ae88{/uj,null,AVAILABLE}
[junit4] 2> 2045714 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4bc5187d{HTTP/1.1,[http/1.1]}{127.0.0.1:62019}
[junit4] 2> 2045714 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.Server Started @2049282ms
[junit4] 2> 2045714 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/tempDir-001/control/data, hostContext=/uj, hostPort=62019, coreRootDirectory=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/../../../../../../../../../../export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/control-001/cores}
[junit4] 2> 2045714 ERROR (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2045714 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 2045714 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2045714 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2045714 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-13T19:00:42.556Z
[junit4] 2> 2045718 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 2045718 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/control-001/solr.xml
[junit4] 2> 2045724 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33981/solr
[junit4] 2> 2045760 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:62019_uj ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:62019_uj
[junit4] 2> 2045762 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:62019_uj ] o.a.s.c.Overseer Overseer (id=97277315794534404-127.0.0.1:62019_uj-n_0000000000) starting
[junit4] 2> 2045773 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:62019_uj ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62019_uj
[junit4] 2> 2045777 INFO (OverseerStateUpdate-97277315794534404-127.0.0.1:62019_uj-n_0000000000) [n:127.0.0.1:62019_uj ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2045839 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:62019_uj ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/../../../../../../../../../../export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/control-001/cores
[junit4] 2> 2045839 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:62019_uj ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 2045843 INFO (OverseerStateUpdate-97277315794534404-127.0.0.1:62019_uj-n_0000000000) [n:127.0.0.1:62019_uj ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 2046858 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 2046871 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 2046942 WARN (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection 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> 2046944 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2046960 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 2046960 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/control-001/cores/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/../../../../../../../../../../export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/control-001/cores/collection1/data/]
[junit4] 2> 2046960 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2089e905
[junit4] 2> 2046962 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=1.302734375, floorSegmentMB=0.2734375, forceMergeDeletesPctAllowed=19.58138317092313, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6143905165044186
[junit4] 2> 2046970 WARN (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 2046979 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2046980 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=1000 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2046980 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2046980 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2046981 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection 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.28058095103363545]
[junit4] 2> 2046981 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@880c98[collection1] main]
[junit4] 2> 2046991 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2046992 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2046992 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2046993 INFO (searcherExecutor-8683-thread-1-processing-n:127.0.0.1:62019_uj x:collection1 c:control_collection) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@880c98[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2046993 INFO (coreLoadExecutor-8682-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj c:control_collection x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556437054348328960
[junit4] 2> 2047003 INFO (coreZkRegister-8675-thread-1-processing-n:127.0.0.1:62019_uj x:collection1 c:control_collection) [n:127.0.0.1:62019_uj c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2047003 INFO (coreZkRegister-8675-thread-1-processing-n:127.0.0.1:62019_uj x:collection1 c:control_collection) [n:127.0.0.1:62019_uj c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2047003 INFO (coreZkRegister-8675-thread-1-processing-n:127.0.0.1:62019_uj x:collection1 c:control_collection) [n:127.0.0.1:62019_uj c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:62019/uj/collection1/
[junit4] 2> 2047003 INFO (coreZkRegister-8675-thread-1-processing-n:127.0.0.1:62019_uj x:collection1 c:control_collection) [n:127.0.0.1:62019_uj c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2047003 INFO (coreZkRegister-8675-thread-1-processing-n:127.0.0.1:62019_uj x:collection1 c:control_collection) [n:127.0.0.1:62019_uj c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:62019/uj/collection1/ has no replicas
[junit4] 2> 2047010 INFO (coreZkRegister-8675-thread-1-processing-n:127.0.0.1:62019_uj x:collection1 c:control_collection) [n:127.0.0.1:62019_uj c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:62019/uj/collection1/ shard1
[junit4] 2> 2047162 INFO (coreZkRegister-8675-thread-1-processing-n:127.0.0.1:62019_uj x:collection1 c:control_collection) [n:127.0.0.1:62019_uj c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2047359 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2047361 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:33981/solr ready
[junit4] 2> 2047361 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 2047486 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-1-001/cores/collection1
[junit4] 2> 2047487 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-1-001
[junit4] 2> 2047487 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2047489 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5e708e59{/uj,null,AVAILABLE}
[junit4] 2> 2047489 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2e8d0024{HTTP/1.1,[http/1.1]}{127.0.0.1:48477}
[junit4] 2> 2047489 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.Server Started @2051059ms
[junit4] 2> 2047490 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/uj, hostPort=48477, coreRootDirectory=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/../../../../../../../../../../export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-1-001/cores}
[junit4] 2> 2047490 ERROR (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2047490 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 2047490 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2047490 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2047490 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-13T19:00:44.332Z
[junit4] 2> 2047494 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 2047494 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-1-001/solr.xml
[junit4] 2> 2047500 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33981/solr
[junit4] 2> 2047515 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:48477_uj ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2047524 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:48477_uj ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48477_uj
[junit4] 2> 2047527 INFO (zkCallback-3586-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2047529 INFO (zkCallback-3590-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2047530 INFO (zkCallback-3595-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2047595 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:48477_uj ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/../../../../../../../../../../export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-1-001/cores
[junit4] 2> 2047595 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:48477_uj ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 2047598 INFO (OverseerStateUpdate-97277315794534404-127.0.0.1:62019_uj-n_0000000000) [n:127.0.0.1:62019_uj ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 2048628 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 2048640 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 2048712 WARN (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 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> 2048714 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2048730 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2048730 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-1-001/cores/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/../../../../../../../../../../export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-1-001/cores/collection1/data/]
[junit4] 2> 2048730 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2089e905
[junit4] 2> 2048732 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=1.302734375, floorSegmentMB=0.2734375, forceMergeDeletesPctAllowed=19.58138317092313, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6143905165044186
[junit4] 2> 2048750 WARN (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 2048765 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2048765 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=1000 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2048766 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2048766 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2048766 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 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.28058095103363545]
[junit4] 2> 2048767 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@310d10a2[collection1] main]
[junit4] 2> 2048769 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2048770 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2048770 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2048772 INFO (searcherExecutor-8694-thread-1-processing-n:127.0.0.1:48477_uj x:collection1 c:collection1) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@310d10a2[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2048772 INFO (coreLoadExecutor-8693-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj c:collection1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556437056213745664
[junit4] 2> 2048784 INFO (coreZkRegister-8688-thread-1-processing-n:127.0.0.1:48477_uj x:collection1 c:collection1) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2048784 INFO (coreZkRegister-8688-thread-1-processing-n:127.0.0.1:48477_uj x:collection1 c:collection1) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2048784 INFO (coreZkRegister-8688-thread-1-processing-n:127.0.0.1:48477_uj x:collection1 c:collection1) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:48477/uj/collection1/
[junit4] 2> 2048784 INFO (coreZkRegister-8688-thread-1-processing-n:127.0.0.1:48477_uj x:collection1 c:collection1) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2048784 INFO (coreZkRegister-8688-thread-1-processing-n:127.0.0.1:48477_uj x:collection1 c:collection1) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:48477/uj/collection1/ has no replicas
[junit4] 2> 2048791 INFO (coreZkRegister-8688-thread-1-processing-n:127.0.0.1:48477_uj x:collection1 c:collection1) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:48477/uj/collection1/ shard1
[junit4] 2> 2048943 INFO (coreZkRegister-8688-thread-1-processing-n:127.0.0.1:48477_uj x:collection1 c:collection1) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2049243 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-2-001/cores/collection1
[junit4] 2> 2049244 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-2-001
[junit4] 2> 2049244 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2049246 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7bc5f474{/uj,null,AVAILABLE}
[junit4] 2> 2049246 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1587268{HTTP/1.1,[http/1.1]}{127.0.0.1:53138}
[junit4] 2> 2049246 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.Server Started @2052816ms
[junit4] 2> 2049246 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/tempDir-001/jetty2, solrconfig=solrconfig.xml, hostContext=/uj, hostPort=53138, coreRootDirectory=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-2-001/cores}
[junit4] 2> 2049247 ERROR (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2049252 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 2049252 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2049252 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2049252 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-13T19:00:46.094Z
[junit4] 2> 2049256 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 2049256 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-2-001/solr.xml
[junit4] 2> 2049263 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33981/solr
[junit4] 2> 2049276 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:53138_uj ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2049283 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:53138_uj ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53138_uj
[junit4] 2> 2049286 INFO (zkCallback-3586-thread-1-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2049286 INFO (zkCallback-3595-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2049286 INFO (zkCallback-3590-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2049288 INFO (zkCallback-3601-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2049462 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:53138_uj ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-2-001/cores
[junit4] 2> 2049462 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:53138_uj ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 2049464 INFO (OverseerStateUpdate-97277315794534404-127.0.0.1:62019_uj-n_0000000000) [n:127.0.0.1:62019_uj ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 2050477 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 2050489 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 2050567 WARN (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 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> 2050568 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2050585 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2050585 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-2-001/cores/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-2-001/cores/collection1/data/]
[junit4] 2> 2050585 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2089e905
[junit4] 2> 2050587 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=1.302734375, floorSegmentMB=0.2734375, forceMergeDeletesPctAllowed=19.58138317092313, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6143905165044186
[junit4] 2> 2050596 WARN (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 2050609 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2050609 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=1000 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2050609 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2050609 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2050610 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 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.28058095103363545]
[junit4] 2> 2050611 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3ef52042[collection1] main]
[junit4] 2> 2050612 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2050613 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2050613 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2050614 INFO (searcherExecutor-8705-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 c:collection1) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3ef52042[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2050614 INFO (coreLoadExecutor-8704-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj c:collection1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556437058145222656
[junit4] 2> 2050620 INFO (coreZkRegister-8699-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 c:collection1) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.ZkController Core needs to recover:collection1
[junit4] 2> 2050620 INFO (updateExecutor-3598-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 2050621 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 2050621 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 2050621 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
[junit4] 2> 2050621 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 2050621 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, leader is [http://127.0.0.1:48477/uj/collection1/] and I am [http://127.0.0.1:53138/uj/collection1/]
[junit4] 2> 2050624 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:48477/uj]; [WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:53138_uj&coreNodeName=core_node2&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 2050627 INFO (qtp484076366-20077) [n:127.0.0.1:48477_uj ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 2050628 INFO (qtp484076366-20077) [n:127.0.0.1:48477_uj ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
[junit4] 2> 2050628 INFO (qtp484076366-20077) [n:127.0.0.1:48477_uj ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:53138_uj, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"core":"collection1","base_url":"http://127.0.0.1:53138/uj","node_name":"127.0.0.1:53138_uj","state":"down"}
[junit4] 2> 2051105 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-3-001/cores/collection1
[junit4] 2> 2051106 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in directory /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-3-001
[junit4] 2> 2051106 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2051108 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@626b254d{/uj,null,AVAILABLE}
[junit4] 2> 2051108 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6ae679c4{HTTP/1.1,[http/1.1]}{127.0.0.1:61236}
[junit4] 2> 2051108 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.e.j.s.Server Started @2054679ms
[junit4] 2> 2051108 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/tempDir-001/jetty3, solrconfig=solrconfig.xml, hostContext=/uj, hostPort=61236, coreRootDirectory=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-3-001/cores}
[junit4] 2> 2051109 ERROR (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2051109 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 2051109 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2051109 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2051109 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-01-13T19:00:47.951Z
[junit4] 2> 2051112 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 2051112 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-3-001/solr.xml
[junit4] 2> 2051119 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33981/solr
[junit4] 2> 2051153 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:61236_uj ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 2051161 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:61236_uj ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:61236_uj
[junit4] 2> 2051164 INFO (zkCallback-3590-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2051164 INFO (zkCallback-3586-thread-3-processing-n:127.0.0.1:62019_uj) [n:127.0.0.1:62019_uj ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2051165 INFO (zkCallback-3595-thread-1-processing-n:127.0.0.1:48477_uj) [n:127.0.0.1:48477_uj ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2051165 INFO (zkCallback-3601-thread-1-processing-n:127.0.0.1:53138_uj) [n:127.0.0.1:53138_uj ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2051165 INFO (zkCallback-3608-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2051236 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:61236_uj ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-3-001/cores
[junit4] 2> 2051237 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [n:127.0.0.1:61236_uj ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 2051239 INFO (OverseerStateUpdate-97277315794534404-127.0.0.1:62019_uj-n_0000000000) [n:127.0.0.1:62019_uj ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 2051629 INFO (qtp484076366-20077) [n:127.0.0.1:48477_uj ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:53138_uj, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"core":"collection1","base_url":"http://127.0.0.1:53138/uj","node_name":"127.0.0.1:53138_uj","state":"recovering"}
[junit4] 2> 2051629 INFO (qtp484076366-20077) [n:127.0.0.1:48477_uj ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 2051629 INFO (qtp484076366-20077) [n:127.0.0.1:48477_uj ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:53138_uj&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node2&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1002
[junit4] 2> 2052253 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 2052265 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 2052344 WARN (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 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> 2052345 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 2052361 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2052361 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-3-001/cores/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001/shard-3-001/cores/collection1/data/]
[junit4] 2> 2052361 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2089e905
[junit4] 2> 2052363 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=1.302734375, floorSegmentMB=0.2734375, forceMergeDeletesPctAllowed=19.58138317092313, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6143905165044186
[junit4] 2> 2052373 WARN (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 2052385 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2052386 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=1000 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2052394 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2052394 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2052395 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 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.28058095103363545]
[junit4] 2> 2052396 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5db944a3[collection1] main]
[junit4] 2> 2052397 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2052398 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2052398 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2052399 INFO (searcherExecutor-8716-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 c:collection1) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5db944a3[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2052400 INFO (coreLoadExecutor-8715-thread-1-processing-n:127.0.0.1:61236_uj) [n:127.0.0.1:61236_uj c:collection1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1556437060017979392
[junit4] 2> 2052405 INFO (coreZkRegister-8710-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 c:collection1) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.ZkController Core needs to recover:collection1
[junit4] 2> 2052405 INFO (updateExecutor-3605-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 2052407 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 2052407 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 2052407 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
[junit4] 2> 2052407 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 2052407 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, leader is [http://127.0.0.1:48477/uj/collection1/] and I am [http://127.0.0.1:61236/uj/collection1/]
[junit4] 2> 2052410 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:48477/uj]; [WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:61236_uj&coreNodeName=core_node3&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 2052413 INFO (qtp484076366-20081) [n:127.0.0.1:48477_uj ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 2052413 INFO (qtp484076366-20081) [n:127.0.0.1:48477_uj ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
[junit4] 2> 2052413 INFO (qtp484076366-20081) [n:127.0.0.1:48477_uj ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:61236_uj, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"collection1","base_url":"http://127.0.0.1:61236/uj","node_name":"127.0.0.1:61236_uj","state":"down"}
[junit4] 2> 2052791 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 2052791 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Wait for recoveries to finish - wait 30 for each attempt
[junit4] 2> 2052791 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):30
[junit4] 2> 2053419 INFO (qtp484076366-20081) [n:127.0.0.1:48477_uj ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:61236_uj, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"collection1","base_url":"http://127.0.0.1:61236/uj","node_name":"127.0.0.1:61236_uj","state":"recovering"}
[junit4] 2> 2053419 INFO (qtp484076366-20081) [n:127.0.0.1:48477_uj ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 2053419 INFO (qtp484076366-20081) [n:127.0.0.1:48477_uj ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:61236_uj&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node3&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1007
[junit4] 2> 2058629 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy Attempting to PeerSync from [http://127.0.0.1:48477/uj/collection1/] - recoveringAfterStartup=[true]
[junit4] 2> 2058630 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.PeerSync PeerSync: core=collection1 url=http://127.0.0.1:53138/uj START replicas=[http://127.0.0.1:48477/uj/collection1/] nUpdates=1000
[junit4] 2> 2058632 INFO (qtp484076366-20078) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 2058632 INFO (qtp484076366-20078) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.S.Request [collection1] webapp=/uj path=/get params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2058632 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 2058632 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync
[junit4] 2> 2058632 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2058633 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2058633 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2058633 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy PeerSync stage of recovery was successful.
[junit4] 2> 2058633 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy Replaying updates buffered during PeerSync.
[junit4] 2> 2058633 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy No replay needed.
[junit4] 2> 2058633 INFO (recoveryExecutor-3599-thread-1-processing-n:127.0.0.1:53138_uj x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RecoveryStrategy Registering as Active after recovery.
[junit4] 2> 2060420 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Attempting to PeerSync from [http://127.0.0.1:48477/uj/collection1/] - recoveringAfterStartup=[true]
[junit4] 2> 2060420 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.PeerSync PeerSync: core=collection1 url=http://127.0.0.1:61236/uj START replicas=[http://127.0.0.1:48477/uj/collection1/] nUpdates=1000
[junit4] 2> 2060422 INFO (qtp484076366-20079) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 2060423 INFO (qtp484076366-20079) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.S.Request [collection1] webapp=/uj path=/get params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2060424 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 2060424 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync
[junit4] 2> 2060424 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2060424 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2060425 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2060425 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy PeerSync stage of recovery was successful.
[junit4] 2> 2060425 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Replaying updates buffered during PeerSync.
[junit4] 2> 2060425 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy No replay needed.
[junit4] 2> 2060425 INFO (recoveryExecutor-3606-thread-1-processing-n:127.0.0.1:61236_uj x:collection1 s:shard1 c:collection1 r:core_node3) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Registering as Active after recovery.
[junit4] 2> 2060804 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.AbstractDistribZkTestBase Recoveries finished - collection: collection1
[junit4] 2> 2060806 INFO (qtp343873685-20041) [n:127.0.0.1:62019_uj c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2060806 INFO (qtp343873685-20041) [n:127.0.0.1:62019_uj c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2060807 INFO (qtp343873685-20041) [n:127.0.0.1:62019_uj c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2060808 INFO (qtp343873685-20041) [n:127.0.0.1:62019_uj c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 1
[junit4] 2> 2060812 INFO (qtp484076366-20077) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2060812 INFO (qtp484076366-20077) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2060814 INFO (qtp484076366-20077) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2060814 INFO (qtp484076366-20077) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:48477/uj/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 1
[junit4] 2> 2060815 INFO (qtp238635777-20106) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2060815 INFO (qtp660029986-20141) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2060815 INFO (qtp660029986-20141) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2060815 INFO (qtp238635777-20106) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2060816 INFO (qtp660029986-20141) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2060816 INFO (qtp238635777-20106) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2060816 INFO (qtp238635777-20106) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:48477/uj/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 1
[junit4] 2> 2060816 INFO (qtp660029986-20141) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:48477/uj/collection1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 1
[junit4] 2> 2060817 INFO (qtp484076366-20082) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 7
[junit4] 2> 2060818 INFO (qtp484076366-20078) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.S.Request [collection1] webapp=/uj path=/select params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 2060820 INFO (qtp238635777-20108) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.S.Request [collection1] webapp=/uj path=/select params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 2060822 INFO (qtp660029986-20143) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.c.S.Request [collection1] webapp=/uj path=/select params={q=*:*&distrib=false&tests=checkShardConsistency&rows=0&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 2062825 INFO (qtp343873685-20042) [n:127.0.0.1:62019_uj c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1556437070947287040)} 0 2
[junit4] 2> 2062831 INFO (qtp238635777-20109) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&_version_=-1556437070951481344&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{deleteByQuery=*:* (-1556437070951481344)} 0 1
[junit4] 2> 2062831 INFO (qtp660029986-20144) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&_version_=-1556437070951481344&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{deleteByQuery=*:* (-1556437070951481344)} 0 2
[junit4] 2> 2062832 INFO (qtp484076366-20080) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1556437070951481344)} 0 5
[junit4] 2> 2062837 INFO (qtp660029986-20145) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{add=[0 (1556437070958821376)]} 0 1
[junit4] 2> 2062837 INFO (qtp238635777-20110) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{add=[0 (1556437070958821376)]} 0 1
[junit4] 2> 2062837 INFO (qtp484076366-20079) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={wt=javabin&version=2}{add=[0 (1556437070958821376)]} 0 3
[junit4] 2> 2062840 INFO (qtp238635777-20111) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{add=[1 (1556437070963015680)]} 0 0
[junit4] 2> 2062840 INFO (qtp660029986-20146) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{add=[1 (1556437070963015680)]} 0 0
[junit4] 2> 2062840 INFO (qtp484076366-20081) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={wt=javabin&version=2}{add=[1 (1556437070963015680)]} 0 1
[junit4] 2> 2062842 INFO (qtp238635777-20104) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{add=[2 (1556437070966161408)]} 0 0
[junit4] 2> 2062842 INFO (qtp660029986-20139) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{add=[2 (1556437070966161408)]} 0 0
[junit4] 2> 2062842 INFO (qtp484076366-20077) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={wt=javabin&version=2}{add=[2 (1556437070966161408)]} 0 1
[junit4] 2> 2062845 INFO (qtp660029986-20141) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{add=[3 (1556437070968258560)]} 0 1
[junit4] 2> 2062845 INFO (qtp238635777-20106) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{add=[3 (1556437070968258560)]} 0 0
[junit4] 2> 2062845 INFO (qtp484076366-20082) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={wt=javabin&version=2}{add=[3 (1556437070968258560)]} 0 2
[junit4] 2> 2062847 INFO (qtp238635777-20107) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{add=[4 (1556437070971404288)]} 0 0
[junit4] 2> 2062847 INFO (qtp660029986-20142) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{add=[4 (1556437070971404288)]} 0 0
[junit4] 2> 2062848 INFO (qtp484076366-20075) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={wt=javabin&version=2}{add=[4 (1556437070971404288)]} 0 2
[junit4] 2> 2062849 INFO (qtp238635777-20107) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{add=[5 (1556437070974550016)]} 0 0
[junit4] 2> 2062849 INFO (qtp660029986-20143) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{add=[5 (1556437070974550016)]} 0 0
[junit4] 2> 2062850 INFO (qtp484076366-20078) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={wt=javabin&version=2}{add=[5 (1556437070974550016)]} 0 1
[junit4] 2> 2062852 INFO (qtp660029986-20143) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{add=[6 (1556437070976647168)]} 0 0
[junit4] 2> 2062852 INFO (qtp238635777-20107) [n:127.0.0.1:53138_uj c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{add=[6 (1556437070976647168)]} 0 0
[junit4] 2> 2062852 INFO (qtp484076366-20080) [n:127.0.0.1:48477_uj c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={wt=javabin&version=2}{add=[6 (1556437070976647168)]} 0 1
[junit4] 2> 2062853 INFO (qtp660029986-20143) [n:127.0.0.1:61236_uj c:collection1 s:shard1 r:core_node3 x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/uj path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:48477/uj/collection1/&wt=javabin&version=2}{add=[7 (15564370
[...truncated too long message...]
461D5849BB5]) [ ] o.a.s.c.ChaosMonkey monkey: stop shard! 61236
[junit4] 2> 2252877 INFO (TEST-PeerSyncReplicationTest.test-seed#[4D52461D5849BB5]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33981 33981
[junit4] 2> 2262904 INFO (Thread-4289) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33981 33981
[junit4] 2> 2262906 WARN (Thread-4289) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/aliases.json
[junit4] 2> 6 /solr/clusterprops.json
[junit4] 2> 5 /solr/security.json
[junit4] 2> 5 /solr/configs/conf1
[junit4] 2> 4 /solr/collections/collection1/state.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/clusterstate.json
[junit4] 2> 2 /solr/overseer_elect/election/97277315794534408-127.0.0.1:48477_uj-n_0000000001
[junit4] 2> 2 /solr/collections/collection1/leader_elect/shard1/election/97277315794534408-core_node1-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 207 /solr/overseer/collection-queue-work
[junit4] 2> 36 /solr/overseer/queue
[junit4] 2> 6 /solr/collections
[junit4] 2> 5 /solr/live_nodes
[junit4] 2> 4 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=PeerSyncReplicationTest -Dtests.method=test -Dtests.seed=4D52461D5849BB5 -Dtests.slow=true -Dtests.locale=hr -Dtests.timezone=America/Halifax -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 217s J1 | PeerSyncReplicationTest.test <<<
[junit4] > Throwable #1: java.lang.AssertionError: timeout waiting to see all nodes active
[junit4] > at __randomizedtesting.SeedInfo.seed([4D52461D5849BB5:8C811BBB7B78F64D]:0)
[junit4] > at org.apache.solr.cloud.PeerSyncReplicationTest.waitTillNodesActive(PeerSyncReplicationTest.java:326)
[junit4] > at org.apache.solr.cloud.PeerSyncReplicationTest.bringUpDeadNodeAndEnsureNoReplication(PeerSyncReplicationTest.java:277)
[junit4] > at org.apache.solr.cloud.PeerSyncReplicationTest.forceNodeFailureAndDoPeerSync(PeerSyncReplicationTest.java:259)
[junit4] > at org.apache.solr.cloud.PeerSyncReplicationTest.test(PeerSyncReplicationTest.java:138)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:985)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:960)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2262910 INFO (SUITE-PeerSyncReplicationTest-seed#[4D52461D5849BB5]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.PeerSyncReplicationTest_4D52461D5849BB5-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {other_tl1=PostingsFormat(name=MockRandom), range_facet_l_dv=PostingsFormat(name=Memory), rnd_s=PostingsFormat(name=Asserting), multiDefault=PostingsFormat(name=Asserting), intDefault=PostingsFormat(name=MockRandom), a_i1=PostingsFormat(name=MockRandom), range_facet_l=PostingsFormat(name=MockRandom), _version_=PostingsFormat(name=MockRandom), a_t=PostingsFormat(name=MockRandom), id=PostingsFormat(name=Memory), range_facet_i_dv=PostingsFormat(name=MockRandom), text=BlockTreeOrds(blocksize=128), timestamp=PostingsFormat(name=MockRandom)}, docValues:{range_facet_l_dv=DocValuesFormat(name=Memory), range_facet_i_dv=DocValuesFormat(name=Lucene70), timestamp=DocValuesFormat(name=Lucene70)}, maxPointsInLeafNode=1702, maxMBSortInHeap=6.92896443689157, sim=RandomSimilarity(queryNorm=false): {}, locale=hr, timezone=America/Halifax
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_112 (64-bit)/cpus=3,threads=1,free=229212952,total=530579456
[junit4] 2> NOTE: All tests run in this JVM: [TestDeleteCollectionOnDownNodes, TestPushWriter, EnumFieldTest, VersionInfoTest, OverseerStatusTest, CollectionsAPISolrJTest, BasicZkTest, StatsReloadRaceTest, TriLevelCompositeIdRoutingTest, TermVectorComponentDistributedTest, CdcrVersionReplicationTest, SolrJmxReporterTest, TestLeaderElectionZkExpiry, TestSha256AuthenticationProvider, LeaderElectionContextKeyTest, BJQParserTest, TestSolrCoreParser, SpellingQueryConverterTest, TestRecovery, BasicAuthIntegrationTest, TestConfigSetsAPI, TestComponentsName, TestSolrCloudSnapshots, DistanceFunctionTest, TestSolrCloudWithDelegationTokens, ReturnFieldsTest, SolrIndexSplitterTest, DistributedIntervalFacetingTest, TestRTimerTree, WrapperMergePolicyFactoryTest, DistributedVersionInfoTest, RequestHandlersTest, RankQueryTest, TestStressLiveNodes, ConvertedLegacyTest, BooleanFieldTest, SuggesterTSTTest, UUIDFieldTest, TestUnifiedSolrHighlighter, TestFieldTypeResource, TestLuceneMatchVersion, TestDFRSimilarityFactory, AnalysisErrorHandlingTest, CreateCollectionCleanupTest, ConnectionReuseTest, TemplateUpdateProcessorTest, TestShortCircuitedRequests, TestSQLHandlerNonCloud, BasicDistributedZk2Test, TestRebalanceLeaders, MetricUtilsTest, BadComponentTest, SpellCheckCollatorTest, CleanupOldIndexTest, DirectUpdateHandlerOptimizeTest, PreAnalyzedFieldManagedSchemaCloudTest, TestClusterProperties, TestConfig, SolrCoreMetricManagerTest, TestTolerantUpdateProcessorRandomCloud, TestBinaryResponseWriter, TestReload, TestChildDocTransformer, TestSolrQueryParserDefaultOperatorResource, TestRestoreCore, ClusterStateTest, ChaosMonkeySafeLeaderTest, ShowFileRequestHandlerTest, OverseerModifyCollectionTest, TestDynamicFieldResource, TestDefaultSearchFieldResource, RulesTest, DateMathParserTest, TestWriterPerf, SolrCloudExampleTest, CollectionTooManyReplicasTest, TestSuggestSpellingConverter, TestCloudInspectUtil, OpenCloseCoreStressTest, HttpSolrCallGetCoreTest, TestPKIAuthenticationPlugin, DeleteShardTest, DeleteNodeTest, ShufflingReplicaListTransformerTest, TestFieldResource, TestExactStatsCache, SaslZkACLProviderTest, BitVectorTest, RollingRestartTest, TestOrdValues, ReplicationFactorTest, TestImpersonationWithHadoopAuth, CurrencyFieldOpenExchangeTest, FieldMutatingUpdateProcessorTest, TestSolrQueryParser, CollectionsAPIDistributedZkTest, TestRestManager, SolrCmdDistributorTest, ZkSolrClientTest, SecurityConfHandlerTest, JSONWriterTest, BlockJoinFacetRandomTest, TestInfoStreamLogging, SolrMetricReporterTest, DataDrivenBlockJoinTest, TestGraphTermsQParserPlugin, HLLUtilTest, TolerantUpdateProcessorTest, TestUtils, TestCollapseQParserPlugin, DistributedFacetPivotLargeTest, BufferStoreTest, ResourceLoaderTest, URLClassifyProcessorTest, TestDistributedStatsComponentCardinality, FieldAnalysisRequestHandlerTest, CdcrBootstrapTest, TestDistributedGrouping, AliasIntegrationTest, OverriddenZkACLAndCredentialsProvidersTest, TestQueryUtils, HdfsRecoverLeaseTest, NotRequiredUniqueKeyTest, TestIndexSearcher, TestSchemaVersionResource, TestQueryTypes, TestMaxScoreQueryParser, DistribJoinFromCollectionTest, TestSolrDeletionPolicy2, TestSolr4Spatial, AutoCommitTest, JavabinLoaderTest, TestMiniSolrCloudClusterSSL, TestTrie, QueryResultKeyTest, TestBadConfig, LoggingHandlerTest, DistributedFacetPivotSmallAdvancedTest, UpdateParamsTest, NoCacheHeaderTest, AsyncCallRequestStatusResponseTest, SuggestComponentContextFilterQueryTest, CSVRequestHandlerTest, IgnoreCommitOptimizeUpdateProcessorFactoryTest, TestNumericTerms32, TestSolrCoreProperties, MultiThreadedOCPTest, BasicFunctionalityTest, TestTrieFacet, UpdateRequestProcessorFactoryTest, TestSystemIdResolver, RemoteQueryErrorTest, TestCoreDiscovery, TestStandardQParsers, TestDownShardTolerantSearch, TestValueSourceCache, ConjunctionSolrSpellCheckerTest, TestExportWriter, TestFoldingMultitermQuery, TestPivotHelperCode, AnalyticsMergeStrategyTest, TestRequestForwarding, ShardRoutingCustomTest, TestSearcherReuse, SyncSliceTest, OverseerTest, LeaderElectionIntegrationTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler, ClusterStateUpdateTest, TestRandomFaceting, TestZkChroot, TestRandomDVFaceting, ZkCLITest, PeerSyncTest, TestFiltering, AnalysisAfterCoreReloadTest, SignatureUpdateProcessorFactoryTest, SuggesterFSTTest, CoreAdminHandlerTest, SolrRequestParserTest, DocValuesTest, LukeRequestHandlerTest, FileBasedSpellCheckerTest, DocumentBuilderTest, TestIndexingPerformance, FastVectorHighlighterTest, IndexSchemaTest, TestCollationField, QueryParsingTest, UniqFieldsUpdateProcessorFactoryTest, TestPartialUpdateDeduplication, SearchHandlerTest, TestMergePolicyConfig, MultiTermTest, TestDocSet, TestSearchPerf, MinimalSchemaTest, TestElisionMultitermQuery, OutputWriterTest, TestFuzzyAnalyzedSuggestions, TestPostingsSolrHighlighter, TestPhraseSuggestions, TestCodecSupport, TestLMDirichletSimilarityFactory, TestLMJelinekMercerSimilarityFactory, TestFastWriter, ScriptEngineTest, PreAnalyzedFieldTest, TestSolrJ, SliceStateTest, DistributedMLTComponentTest, SolrTestCaseJ4Test, TestCrossCoreJoin, TestCursorMarkWithoutUniqueKey, TestDistributedMissingSort, TestHighlightDedupGrouping, TestSimpleTrackingShardHandler, TestEmbeddedSolrServerConstructors, TestJettySolrRunner, ActionThrottleTest, AssignTest, BaseCdcrDistributedZkTest, CdcrReplicationHandlerTest, CdcrRequestHandlerTest, CloudExitableDirectoryReaderTest, CollectionReloadTest, ConcurrentDeleteAndCreateCollectionTest, ConfigSetsAPITest, ConnectionManagerTest, DeleteInactiveReplicaTest, DeleteLastCustomShardedReplicaTest, DeleteReplicaTest, DistributedQueueTest, ForceLeaderTest, LeaderFailureAfterFreshStartTest, PeerSyncReplicationTest]
[junit4] Completed [493/678 (1!)] on J1 in 217.50s, 1 test, 1 failure <<< FAILURES!
[...truncated 63095 lines...]