Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Windows/141/
Java: 32bit/jdk-9-ea+181 -server -XX:+UseSerialGC --illegal-access=deny
2 tests failed.
FAILED:
org.apache.solr.cloud.CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster
Error Message:
Document mismatch on target after sync expected:<2000> but was:<1100>
Stack Trace:
java.lang.AssertionError: Document mismatch on target after sync
expected:<2000> but was:<1100>
at
__randomizedtesting.SeedInfo.seed([7A9E45EFC9AD45FD:AEDB0EB62EFBF606]: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.cloud.CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster(CdcrBootstrapTest.java:309)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
FAILED: org.apache.solr.cloud.ForceLeaderTest.testReplicasInLIRNoLeader
Error Message:
Doc with id=1 not found in
http://127.0.0.1:60021/pm_ed/forceleader_test_collection due to: Path not
found: /id; rsp={doc=null}
Stack Trace:
java.lang.AssertionError: Doc with id=1 not found in
http://127.0.0.1:60021/pm_ed/forceleader_test_collection due to: Path not
found: /id; rsp={doc=null}
at
__randomizedtesting.SeedInfo.seed([7A9E45EFC9AD45FD:9C09712FF02FBC9C]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at
org.apache.solr.cloud.HttpPartitionTest.assertDocExists(HttpPartitionTest.java:603)
at
org.apache.solr.cloud.HttpPartitionTest.assertDocsExistInAllReplicas(HttpPartitionTest.java:556)
at
org.apache.solr.cloud.ForceLeaderTest.testReplicasInLIRNoLeader(ForceLeaderTest.java:142)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
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:993)
at
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:968)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 10882 lines...]
[junit4] Suite: org.apache.solr.cloud.ForceLeaderTest
[junit4] 2> 85221 INFO
(SUITE-ForceLeaderTest-seed#[7A9E45EFC9AD45FD]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir:
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\init-core-data-001
[junit4] 2> 85223 WARN
(SUITE-ForceLeaderTest-seed#[7A9E45EFC9AD45FD]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 85224 INFO
(SUITE-ForceLeaderTest-seed#[7A9E45EFC9AD45FD]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 85226 INFO
(SUITE-ForceLeaderTest-seed#[7A9E45EFC9AD45FD]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via:
@org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl="https://issues.apache.org/jira/browse/SOLR-5776";)
[junit4] 2> 85226 INFO
(SUITE-ForceLeaderTest-seed#[7A9E45EFC9AD45FD]-worker) [ ]
o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /pm_ed/
[junit4] 2> 85234 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 85239 INFO (Thread-205) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 85239 INFO (Thread-205) [ ] o.a.s.c.ZkTestServer Starting
server
[junit4] 2> 85248 ERROR (Thread-205) [ ] o.a.z.s.ZooKeeperServer
ZKShutdownHandler is not registered, so ZooKeeper server won't take any action
on ERROR or SHUTDOWN server state changes
[junit4] 2> 85336 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.ZkTestServer start zk server on port:59754
[junit4] 2> 85362 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig-tlog.xml
to /configs/conf1/solrconfig.xml
[junit4] 2> 85365 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\core\src\test-files\solr\collection1\conf\schema.xml
to /configs/conf1/schema.xml
[junit4] 2> 85368 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml
to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 85371 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\core\src\test-files\solr\collection1\conf\stopwords.txt
to /configs/conf1/stopwords.txt
[junit4] 2> 85374 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\core\src\test-files\solr\collection1\conf\protwords.txt
to /configs/conf1/protwords.txt
[junit4] 2> 85376 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\core\src\test-files\solr\collection1\conf\currency.xml
to /configs/conf1/currency.xml
[junit4] 2> 85379 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\core\src\test-files\solr\collection1\conf\enumsConfig.xml
to /configs/conf1/enumsConfig.xml
[junit4] 2> 85382 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\core\src\test-files\solr\collection1\conf\open-exchange-rates.json
to /configs/conf1/open-exchange-rates.json
[junit4] 2> 85387 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\core\src\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt
to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 85389 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\core\src\test-files\solr\collection1\conf\old_synonyms.txt
to /configs/conf1/old_synonyms.txt
[junit4] 2> 85391 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractZkTestCase put
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\core\src\test-files\solr\collection1\conf\synonyms.txt
to /configs/conf1/synonyms.txt
[junit4] 2> 85394 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractFullDistribZkTestBase Will use TLOG replicas unless
explicitly asked otherwise
[junit4] 2> 85847 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 85848 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@1f1ca15{/pm_ed,null,AVAILABLE}
[junit4] 2> 85850 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.AbstractConnector Started
ServerConnector@145f55c{HTTP/1.1,[http/1.1]}{127.0.0.1:59764}
[junit4] 2> 85850 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.Server Started @94965ms
[junit4] 2> 85850 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/pm_ed,
solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\tempDir-001/control/data,
hostPort=59763,
coreRootDirectory=C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\control-001\cores}
[junit4] 2> 85851 ERROR
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may
be missing or incomplete.
[junit4] 2> 85851 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr?
version 7.1.0
[junit4] 2> 85851 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on
port null
[junit4] 2> 85851 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default
config dir: null
[junit4] 2> 85851 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-08-27T01:24:34.906987400Z
[junit4] 2> 85856 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 85856 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.SolrXmlConfig Loading container configuration from
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\control-001\solr.xml
[junit4] 2> 85863 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.SolrXmlConfig MBean server found:
com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4, but no JMX reporters were
configured - adding default JMX reporter.
[junit4] 2> 85870 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59754/solr
[junit4] 2> 85874 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x15e214a597b0003, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 86004 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 86005 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.OverseerElectionContext I am going to be the leader
127.0.0.1:59763_pm_ed
[junit4] 2> 86006 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.Overseer Overseer
(id=98552845061259268-127.0.0.1:59763_pm_ed-n_0000000000) starting
[junit4] 2> 86014 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:59763_pm_ed
[junit4] 2> 86016 INFO
(OverseerStateUpdate-98552845061259268-127.0.0.1:59763_pm_ed-n_0000000000) [
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 86144 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry
'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 86152 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry
'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 86152 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry
'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 86154 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\control-001\cores
[junit4] 2> 86176 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 86177 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:59754/solr
ready
[junit4] 2> 86178 INFO (SocketProxy-Acceptor-59763) [ ]
o.a.s.c.SocketProxy accepted
Socket[addr=/127.0.0.1,port=59779,localport=59763], receiveBufferSize:65536
[junit4] 2> 86180 INFO (SocketProxy-Acceptor-59763) [ ]
o.a.s.c.SocketProxy proxy connection
Socket[addr=/127.0.0.1,port=59764,localport=59780], receiveBufferSize=65536
[junit4] 2> 86182 INFO (qtp32789330-1021) [ ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params
replicationFactor=1&collection.configName=conf1&name=control_collection&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=127.0.0.1:59763_pm_ed&wt=javabin&version=2
and sendToOCPQueue=true
[junit4] 2> 86185 INFO (OverseerThreadFactory-362-thread-1) [ ]
o.a.s.c.CreateCollectionCmd Create collection control_collection
[junit4] 2> 86299 INFO (SocketProxy-Acceptor-59763) [ ]
o.a.s.c.SocketProxy accepted
Socket[addr=/127.0.0.1,port=59781,localport=59763], receiveBufferSize:65536
[junit4] 2> 86300 INFO (SocketProxy-Acceptor-59763) [ ]
o.a.s.c.SocketProxy proxy connection
Socket[addr=/127.0.0.1,port=59764,localport=59782], receiveBufferSize=65536
[junit4] 2> 86304 INFO (qtp32789330-1023) [ ]
o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&collection.configName=conf1&newCollection=true&name=control_collection_shard1_replica_n1&action=CREATE&numShards=1&collection=control_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 86305 INFO (qtp32789330-1023) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4
transient cores
[junit4] 2> 86421 INFO (zkCallback-169-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged
path:/collections/control_collection/state.json] for collection
[control_collection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 87355 INFO (qtp32789330-1023) [ ] o.a.s.c.SolrConfig Using
Lucene MatchVersion: 7.1.0
[junit4] 2> 87376 INFO (qtp32789330-1023) [ ] o.a.s.s.IndexSchema
[control_collection_shard1_replica_n1] Schema name=test
[junit4] 2> 87482 INFO (qtp32789330-1023) [ ] o.a.s.s.IndexSchema
Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 87504 INFO (qtp32789330-1023) [ ] o.a.s.c.CoreContainer
Creating SolrCore 'control_collection_shard1_replica_n1' using configuration
from collection control_collection, trusted=true
[junit4] 2> 87505 INFO (qtp32789330-1023) [ ]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr.core.control_collection.shard1.replica_n1' (registry
'solr.core.control_collection.shard1.replica_n1') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 87505 INFO (qtp32789330-1023) [ ] o.a.s.c.SolrCore
solr.RecoveryStrategy.Builder
[junit4] 2> 87505 INFO (qtp32789330-1023) [ ] o.a.s.c.SolrCore
[[control_collection_shard1_replica_n1] ] Opening new SolrCore at
[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\control-001\cores\control_collection_shard1_replica_n1],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\control-001\cores\control_collection_shard1_replica_n1\data\]
[junit4] 2> 87507 INFO (qtp32789330-1023) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy:
minMergeSize=0, mergeFactor=10, maxMergeSize=393223826,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.1]
[junit4] 2> 87509 WARN (qtp32789330-1023) [ ] 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> 87631 INFO (qtp32789330-1023) [ ] o.a.s.u.UpdateHandler
Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 87631 INFO (qtp32789330-1023) [ ] o.a.s.u.UpdateLog
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 87634 INFO (qtp32789330-1023) [ ] o.a.s.u.CommitTracker
Hard AutoCommit: disabled
[junit4] 2> 87634 INFO (qtp32789330-1023) [ ] o.a.s.u.CommitTracker
Soft AutoCommit: disabled
[junit4] 2> 87636 INFO (qtp32789330-1023) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=12, maxMergeAtOnceExplicit=24, maxMergedSegmentMB=70.5830078125,
floorSegmentMB=1.62109375, forceMergeDeletesPctAllowed=7.6971784096891005,
segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 87637 INFO (qtp32789330-1023) [ ]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@1606cf6[control_collection_shard1_replica_n1] main]
[junit4] 2> 87639 INFO (qtp32789330-1023) [ ]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 87639 INFO (qtp32789330-1023) [ ]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 87640 INFO (qtp32789330-1023) [ ]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 87642 INFO (searcherExecutor-365-thread-1) [ ]
o.a.s.c.SolrCore [control_collection_shard1_replica_n1] Registered new searcher
Searcher@1606cf6[control_collection_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 87643 INFO (qtp32789330-1023) [ ] o.a.s.u.UpdateLog Could
not find max version in index or recent updates, using new clock
1576845523495682048
[junit4] 2> 87652 INFO (qtp32789330-1023) [ ]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 87652 INFO (qtp32789330-1023) [ ]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 87652 INFO (qtp32789330-1023) [ ] o.a.s.c.SyncStrategy
Sync replicas to
http://127.0.0.1:59763/pm_ed/control_collection_shard1_replica_n1/
[junit4] 2> 87652 INFO (qtp32789330-1023) [ ] o.a.s.c.SyncStrategy
Sync Success - now sync replicas to me
[junit4] 2> 87652 INFO (qtp32789330-1023) [ ] o.a.s.c.SyncStrategy
http://127.0.0.1:59763/pm_ed/control_collection_shard1_replica_n1/ has no
replicas
[junit4] 2> 87652 INFO (qtp32789330-1023) [ ]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 87657 INFO (qtp32789330-1023) [ ]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:59763/pm_ed/control_collection_shard1_replica_n1/ shard1
[junit4] 2> 87764 INFO (zkCallback-169-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged
path:/collections/control_collection/state.json] for collection
[control_collection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 87809 INFO (qtp32789330-1023) [ ] o.a.s.c.ZkController I
am the leader, no recovery necessary
[junit4] 2> 87812 INFO (qtp32789330-1023) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={qt=/admin/cores&collection.configName=conf1&newCollection=true&name=control_collection_shard1_replica_n1&action=CREATE&numShards=1&collection=control_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT}
status=0 QTime=1509
[junit4] 2> 87818 INFO (qtp32789330-1021) [ ]
o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most
30 seconds. Check all shard replicas
[junit4] 2> 87937 INFO (zkCallback-169-thread-1) [ ]
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent
state:SyncConnected type:NodeDataChanged
path:/collections/control_collection/state.json] for collection
[control_collection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 88189 INFO
(OverseerCollectionConfigSetProcessor-98552845061259268-127.0.0.1:59763_pm_ed-n_0000000000)
[ ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 88819 INFO (qtp32789330-1021) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/collections
params={replicationFactor=1&collection.configName=conf1&name=control_collection&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=127.0.0.1:59763_pm_ed&wt=javabin&version=2}
status=0 QTime=2636
[junit4] 2> 88820 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x15e214a597b0005, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 88828 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 88829 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:59754/solr
ready
[junit4] 2> 88831 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection
loss:false
[junit4] 2> 88833 INFO (SocketProxy-Acceptor-59763) [ ]
o.a.s.c.SocketProxy accepted
Socket[addr=/127.0.0.1,port=59786,localport=59763], receiveBufferSize:65536
[junit4] 2> 88833 INFO (SocketProxy-Acceptor-59763) [ ]
o.a.s.c.SocketProxy proxy connection
Socket[addr=/127.0.0.1,port=59764,localport=59787], receiveBufferSize=65536
[junit4] 2> 88836 INFO (qtp32789330-1024) [ ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params
replicationFactor=1&collection.configName=conf1&name=collection1&nrtReplicas=1&action=CREATE&numShards=2&createNodeSet=&stateFormat=1&wt=javabin&version=2
and sendToOCPQueue=true
[junit4] 2> 88839 INFO (OverseerThreadFactory-362-thread-2) [ ]
o.a.s.c.CreateCollectionCmd Create collection collection1
[junit4] 2> 88841 WARN (OverseerThreadFactory-362-thread-2) [ ]
o.a.s.c.CreateCollectionCmd It is unusual to create a collection (collection1)
without cores.
[junit4] 2> 89046 INFO (qtp32789330-1024) [ ]
o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most
30 seconds. Check all shard replicas
[junit4] 2> 89046 INFO (qtp32789330-1024) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/collections
params={replicationFactor=1&collection.configName=conf1&name=collection1&nrtReplicas=1&action=CREATE&numShards=2&createNodeSet=&stateFormat=1&wt=javabin&version=2}
status=0 QTime=209
[junit4] 2> 89489 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-1-001
of type TLOG
[junit4] 2> 89490 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 89491 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@18fccfe{/pm_ed,null,AVAILABLE}
[junit4] 2> 89491 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.AbstractConnector Started
ServerConnector@1a14e59{HTTP/1.1,[http/1.1]}{127.0.0.1:59789}
[junit4] 2> 89492 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.Server Started @98606ms
[junit4] 2> 89492 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/pm_ed,
solrconfig=solrconfig.xml,
solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\tempDir-001/jetty1,
hostPort=59788,
coreRootDirectory=C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-1-001\cores,
replicaType=TLOG}
[junit4] 2> 89493 ERROR
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may
be missing or incomplete.
[junit4] 2> 89493 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr?
version 7.1.0
[junit4] 2> 89493 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on
port null
[junit4] 2> 89493 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default
config dir: null
[junit4] 2> 89493 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-08-27T01:24:38.548655600Z
[junit4] 2> 89504 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 89504 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.SolrXmlConfig Loading container configuration from
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-1-001\solr.xml
[junit4] 2> 89509 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.SolrXmlConfig MBean server found:
com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4, but no JMX reporters were
configured - adding default JMX reporter.
[junit4] 2> 89511 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59754/solr
[junit4] 2> 89525 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 89528 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 89530 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:59788_pm_ed
[junit4] 2> 89533 INFO (zkCallback-181-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 89534 INFO (zkCallback-169-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 89534 INFO (zkCallback-176-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 89932 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry
'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 89945 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry
'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 89946 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry
'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 89948 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-1-001\cores
[junit4] 2> 89975 INFO (qtp32789330-1019) [ ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params
node=127.0.0.1:59788_pm_ed&action=ADDREPLICA&collection=collection1&shard=shard2&type=TLOG&wt=javabin&version=2
and sendToOCPQueue=true
[junit4] 2> 89979 INFO (OverseerThreadFactory-362-thread-3) [ ]
o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:59788_pm_ed for creating new
replica
[junit4] 2> 89979 INFO
(OverseerCollectionConfigSetProcessor-98552845061259268-127.0.0.1:59763_pm_ed-n_0000000000)
[ ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 89982 INFO (SocketProxy-Acceptor-59788) [ ]
o.a.s.c.SocketProxy accepted
Socket[addr=/127.0.0.1,port=59801,localport=59788], receiveBufferSize:65536
[junit4] 2> 89983 INFO (SocketProxy-Acceptor-59788) [ ]
o.a.s.c.SocketProxy proxy connection
Socket[addr=/127.0.0.1,port=59789,localport=59802], receiveBufferSize=65536
[junit4] 2> 89985 INFO (qtp27517264-1068) [ ]
o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&collection.configName=conf1&name=collection1_shard2_replica_t41&action=CREATE&collection=collection1&shard=shard2&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 89986 INFO (qtp27517264-1068) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4
transient cores
[junit4] 2> 91020 INFO (qtp27517264-1068) [ ] o.a.s.c.SolrConfig Using
Lucene MatchVersion: 7.1.0
[junit4] 2> 91063 INFO (qtp27517264-1068) [ ] o.a.s.s.IndexSchema
[collection1_shard2_replica_t41] Schema name=test
[junit4] 2> 91169 INFO (qtp27517264-1068) [ ] o.a.s.s.IndexSchema
Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 91191 INFO (qtp27517264-1068) [ ] o.a.s.c.CoreContainer
Creating SolrCore 'collection1_shard2_replica_t41' using configuration from
collection collection1, trusted=true
[junit4] 2> 91192 INFO (qtp27517264-1068) [ ]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr.core.collection1.shard2.replica_t41' (registry
'solr.core.collection1.shard2.replica_t41') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 91192 INFO (qtp27517264-1068) [ ] o.a.s.c.SolrCore
solr.RecoveryStrategy.Builder
[junit4] 2> 91192 INFO (qtp27517264-1068) [ ] o.a.s.c.SolrCore
[[collection1_shard2_replica_t41] ] Opening new SolrCore at
[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-1-001\cores\collection1_shard2_replica_t41],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-1-001\cores\collection1_shard2_replica_t41\data\]
[junit4] 2> 91195 INFO (qtp27517264-1068) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy:
minMergeSize=0, mergeFactor=10, maxMergeSize=393223826,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.1]
[junit4] 2> 91196 WARN (qtp27517264-1068) [ ] 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> 91274 INFO (qtp27517264-1068) [ ] o.a.s.u.UpdateHandler
Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 91274 INFO (qtp27517264-1068) [ ] o.a.s.u.UpdateLog
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 91276 INFO (qtp27517264-1068) [ ] o.a.s.u.CommitTracker
Hard AutoCommit: disabled
[junit4] 2> 91276 INFO (qtp27517264-1068) [ ] o.a.s.u.CommitTracker
Soft AutoCommit: disabled
[junit4] 2> 91277 INFO (qtp27517264-1068) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=12, maxMergeAtOnceExplicit=24, maxMergedSegmentMB=70.5830078125,
floorSegmentMB=1.62109375, forceMergeDeletesPctAllowed=7.6971784096891005,
segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 91277 INFO (qtp27517264-1068) [ ]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@18aa457[collection1_shard2_replica_t41] main]
[junit4] 2> 91279 INFO (qtp27517264-1068) [ ]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 91279 INFO (qtp27517264-1068) [ ]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 91280 INFO (qtp27517264-1068) [ ]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 91280 INFO (qtp27517264-1068) [ ] o.a.s.u.UpdateLog Could
not find max version in index or recent updates, using new clock
1576845527309352960
[junit4] 2> 91282 INFO (searcherExecutor-376-thread-1) [ ]
o.a.s.c.SolrCore [collection1_shard2_replica_t41] Registered new searcher
Searcher@18aa457[collection1_shard2_replica_t41]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 91287 INFO (qtp27517264-1068) [ ]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 91287 INFO (qtp27517264-1068) [ ]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 91287 INFO (qtp27517264-1068) [ ] o.a.s.c.SyncStrategy
Sync replicas to http://127.0.0.1:59788/pm_ed/collection1_shard2_replica_t41/
[junit4] 2> 91287 INFO (qtp27517264-1068) [ ] o.a.s.c.SyncStrategy
Sync Success - now sync replicas to me
[junit4] 2> 91287 INFO (qtp27517264-1068) [ ] o.a.s.c.SyncStrategy
http://127.0.0.1:59788/pm_ed/collection1_shard2_replica_t41/ has no replicas
[junit4] 2> 91287 INFO (qtp27517264-1068) [ ]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 91288 INFO (qtp27517264-1068) [ ] o.a.s.c.ZkController
collection1_shard2_replica_t41 stopping background replication from leader
[junit4] 2> 91291 INFO (qtp27517264-1068) [ ]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:59788/pm_ed/collection1_shard2_replica_t41/ shard2
[junit4] 2> 91447 INFO (qtp27517264-1068) [ ] o.a.s.c.ZkController I
am the leader, no recovery necessary
[junit4] 2> 91454 INFO (qtp27517264-1068) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={qt=/admin/cores&collection.configName=conf1&name=collection1_shard2_replica_t41&action=CREATE&collection=collection1&shard=shard2&wt=javabin&version=2&replicaType=TLOG}
status=0 QTime=1468
[junit4] 2> 91459 INFO (qtp32789330-1019) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/collections
params={node=127.0.0.1:59788_pm_ed&action=ADDREPLICA&collection=collection1&shard=shard2&type=TLOG&wt=javabin&version=2}
status=0 QTime=1483
[junit4] 2> 91868 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-2-001
of type TLOG
[junit4] 2> 91869 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 91869 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@1ccc70e{/pm_ed,null,AVAILABLE}
[junit4] 2> 91870 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.AbstractConnector Started
ServerConnector@feff27{HTTP/1.1,[http/1.1]}{127.0.0.1:59804}
[junit4] 2> 91871 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.Server Started @100985ms
[junit4] 2> 91871 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/pm_ed,
solrconfig=solrconfig.xml,
solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\tempDir-001/jetty2,
hostPort=59803,
coreRootDirectory=C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-2-001\cores,
replicaType=TLOG}
[junit4] 2> 91871 ERROR
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may
be missing or incomplete.
[junit4] 2> 91872 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr?
version 7.1.0
[junit4] 2> 91872 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on
port null
[junit4] 2> 91872 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default
config dir: null
[junit4] 2> 91872 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-08-27T01:24:40.927092200Z
[junit4] 2> 91876 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 91876 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.SolrXmlConfig Loading container configuration from
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-2-001\solr.xml
[junit4] 2> 91880 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.SolrXmlConfig MBean server found:
com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4, but no JMX reporters were
configured - adding default JMX reporter.
[junit4] 2> 91883 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59754/solr
[junit4] 2> 91895 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 91897 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 91900 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:59803_pm_ed
[junit4] 2> 91901 INFO (zkCallback-187-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 91902 INFO (zkCallback-181-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 91902 INFO (zkCallback-176-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 91902 INFO (zkCallback-169-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 91982 INFO
(OverseerCollectionConfigSetProcessor-98552845061259268-127.0.0.1:59763_pm_ed-n_0000000000)
[ ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000004 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 92189 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry
'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 92199 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry
'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 92199 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry
'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 92200 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-2-001\cores
[junit4] 2> 92235 INFO (qtp32789330-1022) [ ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params
node=127.0.0.1:59803_pm_ed&action=ADDREPLICA&collection=collection1&shard=shard1&type=TLOG&wt=javabin&version=2
and sendToOCPQueue=true
[junit4] 2> 92238 INFO (OverseerThreadFactory-362-thread-4) [ ]
o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:59803_pm_ed for creating new
replica
[junit4] 2> 92241 INFO (SocketProxy-Acceptor-59803) [ ]
o.a.s.c.SocketProxy accepted
Socket[addr=/127.0.0.1,port=59816,localport=59803], receiveBufferSize:65536
[junit4] 2> 92241 INFO (SocketProxy-Acceptor-59803) [ ]
o.a.s.c.SocketProxy proxy connection
Socket[addr=/127.0.0.1,port=59804,localport=59817], receiveBufferSize=65536
[junit4] 2> 92244 INFO (qtp6782424-1102) [ ]
o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&collection.configName=conf1&name=collection1_shard1_replica_t43&action=CREATE&collection=collection1&shard=shard1&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 92245 INFO (qtp6782424-1102) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4
transient cores
[junit4] 2> 93292 INFO (qtp6782424-1102) [ ] o.a.s.c.SolrConfig Using
Lucene MatchVersion: 7.1.0
[junit4] 2> 93323 INFO (qtp6782424-1102) [ ] o.a.s.s.IndexSchema
[collection1_shard1_replica_t43] Schema name=test
[junit4] 2> 93446 INFO (qtp6782424-1102) [ ] o.a.s.s.IndexSchema
Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 93469 INFO (qtp6782424-1102) [ ] o.a.s.c.CoreContainer
Creating SolrCore 'collection1_shard1_replica_t43' using configuration from
collection collection1, trusted=true
[junit4] 2> 93470 INFO (qtp6782424-1102) [ ] o.a.s.m.r.SolrJmxReporter
JMX monitoring for 'solr.core.collection1.shard1.replica_t43' (registry
'solr.core.collection1.shard1.replica_t43') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 93470 INFO (qtp6782424-1102) [ ] o.a.s.c.SolrCore
solr.RecoveryStrategy.Builder
[junit4] 2> 93470 INFO (qtp6782424-1102) [ ] o.a.s.c.SolrCore
[[collection1_shard1_replica_t43] ] Opening new SolrCore at
[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-2-001\cores\collection1_shard1_replica_t43],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-2-001\cores\collection1_shard1_replica_t43\data\]
[junit4] 2> 93472 INFO (qtp6782424-1102) [ ] o.a.s.u.RandomMergePolicy
RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy:
[AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=393223826,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.1]
[junit4] 2> 93474 WARN (qtp6782424-1102) [ ] 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> 93554 INFO (qtp6782424-1102) [ ] o.a.s.u.UpdateHandler
Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 93554 INFO (qtp6782424-1102) [ ] o.a.s.u.UpdateLog
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 93556 INFO (qtp6782424-1102) [ ] o.a.s.u.CommitTracker
Hard AutoCommit: disabled
[junit4] 2> 93556 INFO (qtp6782424-1102) [ ] o.a.s.u.CommitTracker
Soft AutoCommit: disabled
[junit4] 2> 93565 INFO (qtp6782424-1102) [ ] o.a.s.u.RandomMergePolicy
RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy:
[TieredMergePolicy: maxMergeAtOnce=12, maxMergeAtOnceExplicit=24,
maxMergedSegmentMB=70.5830078125, floorSegmentMB=1.62109375,
forceMergeDeletesPctAllowed=7.6971784096891005, segmentsPerTier=17.0,
maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 93566 INFO (qtp6782424-1102) [ ] o.a.s.s.SolrIndexSearcher
Opening [Searcher@13e35e7[collection1_shard1_replica_t43] main]
[junit4] 2> 93567 INFO (qtp6782424-1102) [ ]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 93567 INFO (qtp6782424-1102) [ ]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 93569 INFO (qtp6782424-1102) [ ]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 93571 INFO (searcherExecutor-387-thread-1) [ ]
o.a.s.c.SolrCore [collection1_shard1_replica_t43] Registered new searcher
Searcher@13e35e7[collection1_shard1_replica_t43]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 93571 INFO (qtp6782424-1102) [ ] o.a.s.u.UpdateLog Could
not find max version in index or recent updates, using new clock
1576845529711640576
[junit4] 2> 93578 INFO (qtp6782424-1102) [ ]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 93578 INFO (qtp6782424-1102) [ ]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 93578 INFO (qtp6782424-1102) [ ] o.a.s.c.SyncStrategy Sync
replicas to http://127.0.0.1:59803/pm_ed/collection1_shard1_replica_t43/
[junit4] 2> 93578 INFO (qtp6782424-1102) [ ] o.a.s.c.SyncStrategy Sync
Success - now sync replicas to me
[junit4] 2> 93578 INFO (qtp6782424-1102) [ ] o.a.s.c.SyncStrategy
http://127.0.0.1:59803/pm_ed/collection1_shard1_replica_t43/ has no replicas
[junit4] 2> 93578 INFO (qtp6782424-1102) [ ]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 93579 INFO (qtp6782424-1102) [ ] o.a.s.c.ZkController
collection1_shard1_replica_t43 stopping background replication from leader
[junit4] 2> 93583 INFO (qtp6782424-1102) [ ]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:59803/pm_ed/collection1_shard1_replica_t43/ shard1
[junit4] 2> 93736 INFO (qtp6782424-1102) [ ] o.a.s.c.ZkController I am
the leader, no recovery necessary
[junit4] 2> 93740 INFO (qtp6782424-1102) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={qt=/admin/cores&collection.configName=conf1&name=collection1_shard1_replica_t43&action=CREATE&collection=collection1&shard=shard1&wt=javabin&version=2&replicaType=TLOG}
status=0 QTime=1495
[junit4] 2> 93746 INFO (qtp32789330-1022) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/collections
params={node=127.0.0.1:59803_pm_ed&action=ADDREPLICA&collection=collection1&shard=shard1&type=TLOG&wt=javabin&version=2}
status=0 QTime=1511
[junit4] 2> 94153 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in directory
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-3-001
of type TLOG
[junit4] 2> 94153 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 94154 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@11d6d2a{/pm_ed,null,AVAILABLE}
[junit4] 2> 94155 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.AbstractConnector Started
ServerConnector@11ab66f{HTTP/1.1,[http/1.1]}{127.0.0.1:59821}
[junit4] 2> 94155 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.e.j.s.Server Started @103269ms
[junit4] 2> 94155 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/pm_ed,
solrconfig=solrconfig.xml,
solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\tempDir-001/jetty3,
hostPort=59820,
coreRootDirectory=C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-3-001\cores,
replicaType=TLOG}
[junit4] 2> 94155 ERROR
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may
be missing or incomplete.
[junit4] 2> 94156 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr?
version 7.1.0
[junit4] 2> 94156 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on
port null
[junit4] 2> 94156 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default
config dir: null
[junit4] 2> 94156 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-08-27T01:24:43.211460500Z
[junit4] 2> 94165 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in
ZooKeeper)
[junit4] 2> 94166 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.SolrXmlConfig Loading container configuration from
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-3-001\solr.xml
[junit4] 2> 94170 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.SolrXmlConfig MBean server found:
com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4, but no JMX reporters were
configured - adding default JMX reporter.
[junit4] 2> 94173 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59754/solr
[junit4] 2> 94188 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 94190 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 94193 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:59820_pm_ed
[junit4] 2> 94194 INFO (zkCallback-187-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 94195 INFO (zkCallback-176-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 94195 INFO (zkCallback-181-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 94195 INFO (zkCallback-169-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 94195 INFO (zkCallback-193-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 94241 INFO
(OverseerCollectionConfigSetProcessor-98552845061259268-127.0.0.1:59763_pm_ed-n_0000000000)
[ ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000006 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 94330 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry
'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 94347 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry
'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 94347 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry
'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 94350 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-3-001\cores
[junit4] 2> 94394 INFO (qtp32789330-1023) [ ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params
node=127.0.0.1:59820_pm_ed&action=ADDREPLICA&collection=collection1&shard=shard2&type=TLOG&wt=javabin&version=2
and sendToOCPQueue=true
[junit4] 2> 94397 INFO (OverseerThreadFactory-362-thread-5) [ ]
o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:59820_pm_ed for creating new
replica
[junit4] 2> 94400 INFO (SocketProxy-Acceptor-59820) [ ]
o.a.s.c.SocketProxy accepted
Socket[addr=/127.0.0.1,port=59833,localport=59820], receiveBufferSize:65536
[junit4] 2> 94401 INFO (SocketProxy-Acceptor-59820) [ ]
o.a.s.c.SocketProxy proxy connection
Socket[addr=/127.0.0.1,port=59821,localport=59834], receiveBufferSize=65536
[junit4] 2> 94403 INFO (qtp14103242-1134) [ ]
o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&collection.configName=conf1&name=collection1_shard2_replica_t45&action=CREATE&collection=collection1&shard=shard2&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 94404 INFO (qtp14103242-1134) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4
transient cores
[junit4] 2> 95435 INFO (qtp14103242-1134) [ ] o.a.s.c.SolrConfig Using
Lucene MatchVersion: 7.1.0
[junit4] 2> 95478 INFO (qtp14103242-1134) [ ] o.a.s.s.IndexSchema
[collection1_shard2_replica_t45] Schema name=test
[junit4] 2> 95588 INFO (qtp14103242-1134) [ ] o.a.s.s.IndexSchema
Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 95609 INFO (qtp14103242-1134) [ ] o.a.s.c.CoreContainer
Creating SolrCore 'collection1_shard2_replica_t45' using configuration from
collection collection1, trusted=true
[junit4] 2> 95610 INFO (qtp14103242-1134) [ ]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr.core.collection1.shard2.replica_t45' (registry
'solr.core.collection1.shard2.replica_t45') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 95610 INFO (qtp14103242-1134) [ ] o.a.s.c.SolrCore
solr.RecoveryStrategy.Builder
[junit4] 2> 95610 INFO (qtp14103242-1134) [ ] o.a.s.c.SolrCore
[[collection1_shard2_replica_t45] ] Opening new SolrCore at
[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-3-001\cores\collection1_shard2_replica_t45],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-3-001\cores\collection1_shard2_replica_t45\data\]
[junit4] 2> 95613 INFO (qtp14103242-1134) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy:
minMergeSize=0, mergeFactor=10, maxMergeSize=393223826,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.1]
[junit4] 2> 95615 WARN (qtp14103242-1134) [ ] 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> 95699 INFO (qtp14103242-1134) [ ] o.a.s.u.UpdateHandler
Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 95699 INFO (qtp14103242-1134) [ ] o.a.s.u.UpdateLog
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 95701 INFO (qtp14103242-1134) [ ] o.a.s.u.CommitTracker
Hard AutoCommit: disabled
[junit4] 2> 95701 INFO (qtp14103242-1134) [ ] o.a.s.u.CommitTracker
Soft AutoCommit: disabled
[junit4] 2> 95702 INFO (qtp14103242-1134) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=12, maxMergeAtOnceExplicit=24, maxMergedSegmentMB=70.5830078125,
floorSegmentMB=1.62109375, forceMergeDeletesPctAllowed=7.6971784096891005,
segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 95702 INFO (qtp14103242-1134) [ ]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@84f2e5[collection1_shard2_replica_t45] main]
[junit4] 2> 95703 INFO (qtp14103242-1134) [ ]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf1
[junit4] 2> 95704 INFO (qtp14103242-1134) [ ]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 95704 INFO (qtp14103242-1134) [ ]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 95706 INFO (searcherExecutor-398-thread-1) [ ]
o.a.s.c.SolrCore [collection1_shard2_replica_t45] Registered new searcher
Searcher@84f2e5[collection1_shard2_replica_t45]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 95706 INFO (qtp14103242-1134) [ ] o.a.s.u.UpdateLog Could
not find max version in index or recent updates, using new clock
1576845531950350336
[junit4] 2> 95711 INFO (qtp14103242-1134) [ ] o.a.s.c.ZkController
Core needs to recover:collection1_shard2_replica_t45
[junit4] 2> 95711 INFO (updateExecutor-190-thread-1) [ ]
o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 95711 INFO (qtp14103242-1134) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={qt=/admin/cores&collection.configName=conf1&name=collection1_shard2_replica_t45&action=CREATE&collection=collection1&shard=shard2&wt=javabin&version=2&replicaType=TLOG}
status=0 QTime=1308
[junit4] 2> 95712 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 95712 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 95712 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.c.ZkController collection1_shard2_replica_t45 stopping background
replication from leader
[junit4] 2> 95712 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.c.RecoveryStrategy Begin buffering updates.
core=[collection1_shard2_replica_t45]
[junit4] 2> 95712 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE,
tlog=null}
[junit4] 2> 95712 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.c.RecoveryStrategy Publishing state of core
[collection1_shard2_replica_t45] as recovering, leader is
[http://127.0.0.1:59788/pm_ed/collection1_shard2_replica_t41/] and I am
[http://127.0.0.1:59820/pm_ed/collection1_shard2_replica_t45/]
[junit4] 2> 95714 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.c.RecoveryStrategy Sending prep recovery command to
[http://127.0.0.1:59788/pm_ed]; [WaitForState:
action=PREPRECOVERY&core=collection1_shard2_replica_t41&nodeName=127.0.0.1:59820_pm_ed&coreNodeName=core_node46&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 95714 INFO (qtp32789330-1023) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/collections
params={node=127.0.0.1:59820_pm_ed&action=ADDREPLICA&collection=collection1&shard=shard2&type=TLOG&wt=javabin&version=2}
status=0 QTime=1320
[junit4] 2> 95715 INFO (SocketProxy-Acceptor-59788) [ ]
o.a.s.c.SocketProxy accepted
Socket[addr=/127.0.0.1,port=59836,localport=59788], receiveBufferSize:65536
[junit4] 2> 95716 INFO (SocketProxy-Acceptor-59788) [ ]
o.a.s.c.SocketProxy proxy connection
Socket[addr=/127.0.0.1,port=59789,localport=59837], receiveBufferSize=65536
[junit4] 2> 95719 INFO (qtp27517264-1074) [ ] o.a.s.h.a.PrepRecoveryOp
Going to wait for coreNodeName: core_node46, state: recovering, checkLive:
true, onlyIfLeader: true, onlyIfLeaderActive: true, maxTime: 183 s
[junit4] 2> 95719 INFO (qtp27517264-1074) [ ] o.a.s.h.a.PrepRecoveryOp
In WaitForState(recovering): collection=collection1, shard=shard2,
thisCore=collection1_shard2_replica_t41, leaderDoesNotNeedRecovery=false,
isLeader? true, live=true, checkLive=true, currentState=down,
localState=active, nodeName=127.0.0.1:59820_pm_ed, coreNodeName=core_node46,
onlyIfActiveCheckResult=false, nodeProps:
core_node46:{"core":"collection1_shard2_replica_t45","base_url":"http://127.0.0.1:59820/pm_ed","node_name":"127.0.0.1:59820_pm_ed","state":"down","type":"TLOG"}
[junit4] 2> 95719 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.SolrTestCaseJ4 ###Starting testLastPublishedStateIsActive
[junit4] 2> 95719 INFO
(TEST-ForceLeaderTest.testLastPublishedStateIsActive-seed#[7A9E45EFC9AD45FD]) [
] o.a.s.c.AbstractFullDistribZkTestBase Creating collection with
stateFormat=1: forceleader_last_published
[junit4] 2> 95721 INFO (SocketProxy-Acceptor-59788) [ ]
o.a.s.c.SocketProxy accepted
Socket[addr=/127.0.0.1,port=59838,localport=59788], receiveBufferSize:65536
[junit4] 2> 95721 INFO (SocketProxy-Acceptor-59788) [ ]
o.a.s.c.SocketProxy proxy connection
Socket[addr=/127.0.0.1,port=59789,localport=59839], receiveBufferSize=65536
[junit4] 2> 95724 INFO (qtp27517264-1072) [ ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params
pullReplicas=0&maxShardsPerNode=1&collection.configName=conf1&nrtReplicas=0&name=forceleader_last_published&action=CREATE&numShards=1&tlogReplicas=3&stateFormat=1&wt=javabin&version=2
and sendToOCPQueue=true
[junit4] 2> 95725 INFO (OverseerThreadFactory-362-thread-5) [ ]
o.a.s.c.CreateCollectionCmd Create collection forceleader_last_published
[junit4] 2> 95726 INFO
(OverseerCollectionConfigSetProcessor-98552845061259268-127.0.0.1:59763_pm_ed-n_0000000000)
[ ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000008 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 95939 INFO (qtp14103242-1135) [ ]
o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&collection.configName=conf1&newCollection=true&name=forceleader_last_published_shard1_replica_t1&action=CREATE&numShards=1&collection=forceleader_last_published&shard=shard1&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 95946 INFO (qtp32789330-1021) [ ]
o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&collection.configName=conf1&newCollection=true&name=forceleader_last_published_shard1_replica_t2&action=CREATE&numShards=1&collection=forceleader_last_published&shard=shard1&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 95949 INFO (qtp27517264-1070) [ ]
o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&collection.configName=conf1&newCollection=true&name=forceleader_last_published_shard1_replica_t3&action=CREATE&numShards=1&collection=forceleader_last_published&shard=shard1&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 96719 INFO (qtp27517264-1074) [ ] o.a.s.h.a.PrepRecoveryOp
In WaitForState(recovering): collection=collection1, shard=shard2,
thisCore=collection1_shard2_replica_t41, leaderDoesNotNeedRecovery=false,
isLeader? true, live=true, checkLive=true, currentState=recovering,
localState=active, nodeName=127.0.0.1:59820_pm_ed, coreNodeName=core_node46,
onlyIfActiveCheckResult=false, nodeProps:
core_node46:{"core":"collection1_shard2_replica_t45","base_url":"http://127.0.0.1:59820/pm_ed","node_name":"127.0.0.1:59820_pm_ed","state":"recovering","type":"TLOG"}
[junit4] 2> 96719 INFO (qtp27517264-1074) [ ] o.a.s.h.a.PrepRecoveryOp
Waited coreNodeName: core_node46, state: recovering, checkLive: true,
onlyIfLeader: true for: 1 seconds.
[junit4] 2> 96719 INFO (qtp27517264-1074) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={nodeName=127.0.0.1:59820_pm_ed&onlyIfLeaderActive=true&core=collection1_shard2_replica_t41&coreNodeName=core_node46&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2}
status=0 QTime=1000
[junit4] 2> 96976 INFO (qtp14103242-1135) [ ] o.a.s.c.SolrConfig Using
Lucene MatchVersion: 7.1.0
[junit4] 2> 96979 INFO (qtp32789330-1021) [ ] o.a.s.c.SolrConfig Using
Lucene MatchVersion: 7.1.0
[junit4] 2> 97003 INFO (qtp27517264-1070) [ ] o.a.s.c.SolrConfig Using
Lucene MatchVersion: 7.1.0
[junit4] 2> 97008 INFO (qtp14103242-1135) [ ] o.a.s.s.IndexSchema
[forceleader_last_published_shard1_replica_t1] Schema name=test
[junit4] 2> 97014 INFO (qtp32789330-1021) [ ] o.a.s.s.IndexSchema
[forceleader_last_published_shard1_replica_t2] Schema name=test
[junit4] 2> 97034 INFO (qtp27517264-1070) [ ] o.a.s.s.IndexSchema
[forceleader_last_published_shard1_replica_t3] Schema name=test
[junit4] 2> 97186 INFO (qtp32789330-1021) [ ] o.a.s.s.IndexSchema
Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 97192 INFO (qtp27517264-1070) [ ] o.a.s.s.IndexSchema
Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 97197 INFO (qtp14103242-1135) [ ] o.a.s.s.IndexSchema
Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 97216 INFO (qtp32789330-1021) [ ] o.a.s.c.CoreContainer
Creating SolrCore 'forceleader_last_published_shard1_replica_t2' using
configuration from collection forceleader_last_published, trusted=true
[junit4] 2> 97217 INFO (qtp32789330-1021) [ ]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr.core.forceleader_last_published.shard1.replica_t2' (registry
'solr.core.forceleader_last_published.shard1.replica_t2') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 97217 INFO (qtp32789330-1021) [ ] o.a.s.c.SolrCore
solr.RecoveryStrategy.Builder
[junit4] 2> 97217 INFO (qtp32789330-1021) [ ] o.a.s.c.SolrCore
[[forceleader_last_published_shard1_replica_t2] ] Opening new SolrCore at
[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\control-001\cores\forceleader_last_published_shard1_replica_t2],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\control-001\cores\forceleader_last_published_shard1_replica_t2\data\]
[junit4] 2> 97221 INFO (qtp27517264-1070) [ ] o.a.s.c.CoreContainer
Creating SolrCore 'forceleader_last_published_shard1_replica_t3' using
configuration from collection forceleader_last_published, trusted=true
[junit4] 2> 97222 INFO (qtp27517264-1070) [ ]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr.core.forceleader_last_published.shard1.replica_t3' (registry
'solr.core.forceleader_last_published.shard1.replica_t3') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 97222 INFO (qtp27517264-1070) [ ] o.a.s.c.SolrCore
solr.RecoveryStrategy.Builder
[junit4] 2> 97222 INFO (qtp27517264-1070) [ ] o.a.s.c.SolrCore
[[forceleader_last_published_shard1_replica_t3] ] Opening new SolrCore at
[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-1-001\cores\forceleader_last_published_shard1_replica_t3],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-1-001\cores\forceleader_last_published_shard1_replica_t3\data\]
[junit4] 2> 97223 INFO (qtp32789330-1021) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy:
minMergeSize=0, mergeFactor=10, maxMergeSize=393223826,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.1]
[junit4] 2> 97223 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.c.RecoveryStrategy Starting Replication Recovery.
[junit4] 2> 97223 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.c.RecoveryStrategy Attempting to replicate from
[http://127.0.0.1:59788/pm_ed/collection1_shard2_replica_t41/].
[junit4] 2> 97224 INFO (qtp14103242-1135) [ ] o.a.s.c.CoreContainer
Creating SolrCore 'forceleader_last_published_shard1_replica_t1' using
configuration from collection forceleader_last_published, trusted=true
[junit4] 2> 97224 INFO (qtp14103242-1135) [ ]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr.core.forceleader_last_published.shard1.replica_t1' (registry
'solr.core.forceleader_last_published.shard1.replica_t1') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@105fdf4
[junit4] 2> 97224 INFO (qtp14103242-1135) [ ] o.a.s.c.SolrCore
solr.RecoveryStrategy.Builder
[junit4] 2> 97224 INFO (qtp14103242-1135) [ ] o.a.s.c.SolrCore
[[forceleader_last_published_shard1_replica_t1] ] Opening new SolrCore at
[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-3-001\cores\forceleader_last_published_shard1_replica_t1],
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.ForceLeaderTest_7A9E45EFC9AD45FD-001\shard-3-001\cores\forceleader_last_published_shard1_replica_t1\data\]
[junit4] 2> 97224 INFO (SocketProxy-Acceptor-59788) [ ]
o.a.s.c.SocketProxy accepted
Socket[addr=/127.0.0.1,port=59840,localport=59788], receiveBufferSize:65536
[junit4] 2> 97224 INFO (SocketProxy-Acceptor-59788) [ ]
o.a.s.c.SocketProxy proxy connection
Socket[addr=/127.0.0.1,port=59789,localport=59841], receiveBufferSize=65536
[junit4] 2> 97227 INFO (qtp27517264-1070) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy:
minMergeSize=0, mergeFactor=10, maxMergeSize=393223826,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.1]
[junit4] 2> 97228 INFO (qtp27517264-1071) [ ]
o.a.s.u.DirectUpdateHandler2 start
commit{_version_=1576845533546283008,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 97229 INFO (qtp27517264-1071) [ ]
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 97230 INFO (qtp27517264-1071) [ ]
o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 97230 INFO (qtp27517264-1071) [ ]
o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica_t41]
webapp=/pm_ed path=/update
params={waitSearcher=true&openSearcher=false&commit=true&softCommit=false&commit_end_point=true&wt=javabin&version=2}{commit=}
0 2
[junit4] 2> 97230 INFO (qtp14103242-1135) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy:
minMergeSize=0, mergeFactor=10, maxMergeSize=393223826,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.1]
[junit4] 2> 97232 WARN (qtp32789330-1021) [ ] 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> 97235 INFO (SocketProxy-Acceptor-59788) [ ]
o.a.s.c.SocketProxy accepted
Socket[addr=/127.0.0.1,port=59842,localport=59788], receiveBufferSize:65536
[junit4] 2> 97235 INFO (SocketProxy-Acceptor-59788) [ ]
o.a.s.c.SocketProxy proxy connection
Socket[addr=/127.0.0.1,port=59789,localport=59843], receiveBufferSize=65536
[junit4] 2> 97241 WARN (qtp14103242-1135) [ ] 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> 97244 WARN (qtp27517264-1070) [ ] 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> 97249 INFO (qtp27517264-1068) [ ] o.a.s.c.S.Request
[collection1_shard2_replica_t41] webapp=/pm_ed path=/replication
params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0
QTime=0
[junit4] 2> 97250 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 97250 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 97250 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 97250 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 97250 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.c.RecoveryStrategy Replication Recovery was successful.
[junit4] 2> 97250 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.c.RecoveryStrategy Registering as Active after recovery.
[junit4] 2> 97250 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.c.ZkController collection1_shard2_replica_t45 starting background
replication from leader
[junit4] 2> 97250 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.c.ReplicateFromLeader Will start replication from leader with poll
interval: 00:00:03
[junit4] 2> 97255 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 97275 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.c.RecoveryStrategy Updating version bucket highest from index after
successful recovery.
[junit4] 2> 97275 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using
new clock 1576845533595566080
[junit4] 2> 97275 INFO (recoveryExecutor-191-thread-1) [ ]
o.a.s.c.RecoveryStrategy Finished recovery process, successful=[true]
[junit4] 2> 97410 INFO (qtp32789330-1021) [ ] o.a.s.u.UpdateHandler
Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 97410 INFO (qtp32789330-1021) [ ] o.a.s.u.UpdateLog
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 97413 INFO (qtp32789330-1021) [ ] o.a.s.u.CommitTracker
Hard AutoCommit: disabled
[junit4] 2> 97413 INFO (qtp32789330-1021) [ ] o.a.s.u.CommitTracker
Soft AutoCommit: disabled
[junit4] 2> 97419 INFO (qtp27517264-1070) [ ] o.a.s.u.UpdateHandler
Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 97419 INFO (qtp27517264-1070) [ ] o.a.s.u.UpdateLog
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100
maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 97438 INFO (qtp27517264-1070) [ ] o.a.s.u.CommitTracker
Hard AutoCommit: disabled
[junit4] 2> 97438 INFO (qtp27517264-1070) [ ] o.a.s.u.CommitTracker
Soft AutoCommit: disabled
[junit4] 2> 97438 INFO (qtp32789330-1021) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=12, maxMergeAtOnceExplicit=24, maxMergedSegmentMB=70.5830078125,
floorSegmentMB=1.62109375, forceMergeDeletesPctAllowed=7.6971784096891005,
segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 97438 INFO (qtp32789330-1021) [ ]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@e4d345[forceleader_last_published_shard1_replica_t2] main]
[junit4] 2> 97441 INFO (qtp27517264-1070) [ ]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy:
maxMergeAtOnce=12, maxMergeAtOnceExplicit=24, maxMergedSegmentMB=70.5830078125,
floorSegmentMB=1.62109375, forceMergeDeletesPctAllowed=7.6971784096891005,
segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 97441 INFO (qtp32789330-1021) [ ]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBa
[...truncated too long message...]
6-thread-1) [ ] o.a.s.h.CdcrRequestHandler Bootstrap operation failed
[junit4] 2> java.util.concurrent.ExecutionException:
java.lang.AssertionError
[junit4] 2> at
java.base/java.util.concurrent.FutureTask.report(FutureTask.java:122)
[junit4] 2> at
java.base/java.util.concurrent.FutureTask.get(FutureTask.java:191)
[junit4] 2> at
org.apache.solr.handler.CdcrRequestHandler.lambda$handleBootstrapAction$0(CdcrRequestHandler.java:646)
[junit4] 2> at
com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
[junit4] 2> at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514)
[junit4] 2> at
java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
[junit4] 2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
[junit4] 2> at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> Caused by: java.lang.AssertionError
[junit4] 2> at
org.apache.solr.handler.CdcrRequestHandler$BootstrapCallable.call(CdcrRequestHandler.java:789)
[junit4] 2> at
org.apache.solr.handler.CdcrRequestHandler$BootstrapCallable.call(CdcrRequestHandler.java:716)
[junit4] 2> at
com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197)
[junit4] 2> ... 5 more
[junit4] 1> Adding 10 docs with commit=true, numDocs=1900
[junit4] 1> Adding 10 docs with commit=true, numDocs=2000
[junit4] 1> Cdcr queue response:
{responseHeader={status=0,QTime=2},queues={127.0.0.1:65398/solr={cdcr-target={queueSize=2020,lastTimestamp=}}},tlogTotalSize=96439,tlogTotalCount=20,updateLogSynchronizer=stopped}
[junit4] 2> 1104594 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x15e2157ec100007, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 1104640 WARN (cdcr-bootstrap-status-1273-thread-1) [ ]
o.a.s.h.CdcrReplicatorManager Cancelling waiting for bootstrap on target:
cdcr-target shard: shard1 to complete
[junit4] 2> 1104643 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x15e2157e9eb0008, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 1104704 WARN (zkCallback-1261-thread-4) [ ]
o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK:
[KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1104707 ERROR
(TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[7A9E45EFC9AD45FD])
[ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so
ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 1104708 WARN (Thread-1452) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/aliases.json
[junit4] 2> 2 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/collections/cdcr-source/state.json
[junit4] 2> 2 /solr/clusterstate.json
[junit4] 2> 2 /solr/collections/cdcr-source/cdcr/state/process
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/live_nodes
[junit4] 2> 2 /solr/collections
[junit4] 2>
[junit4] 2> 1106238 WARN (zkCallback-1249-thread-4) [ ]
o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK:
[KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1106240 ERROR
(TEST-CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster-seed#[7A9E45EFC9AD45FD])
[ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so
ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 1106245 WARN (Thread-1442) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2> 2 /solr/configs/cdcr-target/managed-schema
[junit4] 2> 2
/solr/collections/cdcr-target/leaders/shard1/leader
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/collections/cdcr-target/state.json
[junit4] 2> 3 /solr/collections/cdcr-target/cdcr/state/process
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2> 2 /solr/collections/cdcr-target/cdcr/state/buffer
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/collections
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CdcrBootstrapTest
-Dtests.method=testBootstrapWithContinousIndexingOnSourceCluster
-Dtests.seed=7A9E45EFC9AD45FD -Dtests.slow=true -Dtests.locale=ca
-Dtests.timezone=Asia/Chungking -Dtests.asserts=true
-Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 132s J0 |
CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster <<<
[junit4] > Throwable #1: java.lang.AssertionError: Document mismatch on
target after sync expected:<2000> but was:<1100>
[junit4] > at
__randomizedtesting.SeedInfo.seed([7A9E45EFC9AD45FD:AEDB0EB62EFBF606]:0)
[junit4] > at
org.apache.solr.cloud.CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster(CdcrBootstrapTest.java:309)
[junit4] > at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at
java.base/java.lang.reflect.Method.invoke(Method.java:564)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> NOTE: leaving temporary files on disk at:
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_7A9E45EFC9AD45FD-001
[junit4] 2> Aug 27, 2017 1:41:35 AM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked
thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70):
{xyz=FSTOrd50, id=PostingsFormat(name=Memory)}, docValues:{},
maxPointsInLeafNode=1246, maxMBSortInHeap=5.573548941457191,
sim=RandomSimilarity(queryNorm=false): {}, locale=ca, timezone=Asia/Chungking
[junit4] 2> NOTE: Windows 10 10.0 x86/Oracle Corporation 9
(32-bit)/cpus=3,threads=1,free=176340880,total=451358720
[junit4] 2> NOTE: All tests run in this JVM:
[AssignBackwardCompatibilityTest, OutputWriterTest, SolrSlf4jReporterTest,
VMParamsZkACLAndCredentialsProvidersTest, TestDynamicFieldCollectionResource,
MissingSegmentRecoveryTest, DistribJoinFromCollectionTest,
DefaultValueUpdateProcessorTest, TestStressVersions,
CollectionTooManyReplicasTest, CSVRequestHandlerTest, ForceLeaderTest,
BasicAuthIntegrationTest, SolrCLIZkUtilsTest, TestCursorMarkWithoutUniqueKey,
DistributedFacetPivotLargeTest, TestDocBasedVersionConstraints,
ReplicaListTransformerTest, TestSolrCoreParser, TestIBSimilarityFactory,
TestNumericRangeQuery32, TestJettySolrRunner, SolrMetricReporterTest,
SuggesterTest, TestSweetSpotSimilarityFactory, TestFoldingMultitermQuery,
TestRandomDVFaceting, TestLocalFSCloudBackupRestore,
TestComplexPhraseLeadingWildcard, SortByFunctionTest, UUIDFieldTest,
TestGroupingSearch, DateMathParserTest, TestAddFieldRealTimeGet,
HighlighterConfigTest, BinaryUpdateRequestHandlerTest, AlternateDirectoryTest,
TestMissingGroups, TestLegacyFieldCache, TestConfigSetImmutable,
TestRecoveryHdfs, TestManagedSchemaAPI, BasicDistributedZkTest,
TestUnifiedSolrHighlighter, TestSubQueryTransformerDistrib,
CurrencyFieldTypeTest, TestReplicaProperties, AnalysisAfterCoreReloadTest,
ShardSplitTest, SharedFSAutoReplicaFailoverUtilsTest, TestNumericTokenStream,
TestIndexingPerformance, TestUseDocValuesAsStored2, SmileWriterTest,
HdfsRecoverLeaseTest, TestJsonFacets, TestDownShardTolerantSearch,
TestPseudoReturnFields, TestBlendedInfixSuggestions, TestCollectionAPIs,
TestCustomStream, TestSolrConfigHandlerConcurrent, TestCSVResponseWriter,
TestRawResponseWriter, SolrCoreTest, HdfsCollectionsAPIDistributedZkTest,
SimplePostToolTest, AnalyticsQueryTest, DistributedFacetPivotWhiteBoxTest,
TestTolerantUpdateProcessorCloud, DistributedExpandComponentTest,
CdcrBootstrapTest]
[junit4] Completed [214/731 (2!)] on J0 in 157.19s, 3 tests, 1 failure <<<
FAILURES!
[...truncated 38273 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
