You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2017/08/30 05:22:54 UTC
[JENKINS-EA] Lucene-Solr-6.6-Windows (64bit/jdk-9-ea+181) - Build #
44 - Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.6-Windows/44/
Java: 64bit/jdk-9-ea+181 -XX:-UseCompressedOops -XX:+UseG1GC --illegal-access=deny
1 tests failed.
FAILED: org.apache.solr.cloud.OverseerRolesTest.testOverseerRole
Error Message:
Timed out waiting for overseer state change
Stack Trace:
java.lang.AssertionError: Timed out waiting for overseer state change
at __randomizedtesting.SeedInfo.seed([CAF3A4D85571E668:2B38594C6EC2D0B9]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.OverseerRolesTest.waitForNewOverseer(OverseerRolesTest.java:62)
at org.apache.solr.cloud.OverseerRolesTest.testOverseerRole(OverseerRolesTest.java:140)
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)
Build Log:
[...truncated 11955 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerRolesTest
[junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.OverseerRolesTest_CAF3A4D85571E668-001\init-core-data-001
[junit4] 2> 876815 WARN (SUITE-OverseerRolesTest-seed#[CAF3A4D85571E668]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 876815 INFO (SUITE-OverseerRolesTest-seed#[CAF3A4D85571E668]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields
[junit4] 2> 876818 INFO (SUITE-OverseerRolesTest-seed#[CAF3A4D85571E668]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 876819 INFO (SUITE-OverseerRolesTest-seed#[CAF3A4D85571E668]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.OverseerRolesTest_CAF3A4D85571E668-001\tempDir-001
[junit4] 2> 876819 INFO (SUITE-OverseerRolesTest-seed#[CAF3A4D85571E668]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 876819 INFO (Thread-2010) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 876819 INFO (Thread-2010) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 876826 ERROR (Thread-2010) [ ] 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> 876919 INFO (SUITE-OverseerRolesTest-seed#[CAF3A4D85571E668]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:64114
[junit4] 2> 876927 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 0x15e31733f070000, 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> 876927 INFO (jetty-launcher-1369-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 876927 INFO (jetty-launcher-1369-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@520839a8{/solr,null,AVAILABLE}
[junit4] 2> 876927 INFO (jetty-launcher-1369-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1fd99fd2{HTTP/1.1,[http/1.1]}{127.0.0.1:64118}
[junit4] 2> 876927 INFO (jetty-launcher-1369-thread-1) [ ] o.e.j.s.Server Started @879265ms
[junit4] 2> 876927 INFO (jetty-launcher-1369-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=64118}
[junit4] 2> 876937 ERROR (jetty-launcher-1369-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 876938 INFO (jetty-launcher-1369-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.1
[junit4] 2> 876938 INFO (jetty-launcher-1369-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 876938 INFO (jetty-launcher-1369-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 876938 INFO (jetty-launcher-1369-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-30T04:43:10.073135400Z
[junit4] 2> 876938 INFO (jetty-launcher-1369-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 876939 INFO (jetty-launcher-1369-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 876940 INFO (jetty-launcher-1369-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 876941 INFO (jetty-launcher-1369-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@379f9317{/solr,null,AVAILABLE}
[junit4] 2> 876942 INFO (jetty-launcher-1369-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@fc9c4e9{HTTP/1.1,[http/1.1]}{127.0.0.1:64123}
[junit4] 2> 876942 INFO (jetty-launcher-1369-thread-3) [ ] o.e.j.s.Server Started @879274ms
[junit4] 2> 876942 INFO (jetty-launcher-1369-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=64123}
[junit4] 2> 876942 INFO (jetty-launcher-1369-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6bd0cb81{/solr,null,AVAILABLE}
[junit4] 2> 876942 ERROR (jetty-launcher-1369-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 876942 INFO (jetty-launcher-1369-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.1
[junit4] 2> 876942 INFO (jetty-launcher-1369-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 876943 INFO (jetty-launcher-1369-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 876943 INFO (jetty-launcher-1369-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-30T04:43:10.078924100Z
[junit4] 2> 876943 INFO (jetty-launcher-1369-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5ef9fc1d{HTTP/1.1,[http/1.1]}{127.0.0.1:64126}
[junit4] 2> 876943 INFO (jetty-launcher-1369-thread-2) [ ] o.e.j.s.Server Started @879275ms
[junit4] 2> 876943 INFO (jetty-launcher-1369-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=64126}
[junit4] 2> 876943 ERROR (jetty-launcher-1369-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 876943 INFO (jetty-launcher-1369-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.1
[junit4] 2> 876943 INFO (jetty-launcher-1369-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 876943 INFO (jetty-launcher-1369-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 876944 INFO (jetty-launcher-1369-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-30T04:43:10.079856Z
[junit4] 2> 876942 INFO (jetty-launcher-1369-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@66efc2c7{/solr,null,AVAILABLE}
[junit4] 2> 876946 INFO (jetty-launcher-1369-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@679d01e4{HTTP/1.1,[http/1.1]}{127.0.0.1:64133}
[junit4] 2> 876951 INFO (jetty-launcher-1369-thread-4) [ ] o.e.j.s.Server Started @879284ms
[junit4] 2> 876952 INFO (jetty-launcher-1369-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=64133}
[junit4] 2> 876952 ERROR (jetty-launcher-1369-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 876952 INFO (jetty-launcher-1369-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.1
[junit4] 2> 876952 INFO (jetty-launcher-1369-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 876952 INFO (jetty-launcher-1369-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 876952 INFO (jetty-launcher-1369-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-30T04:43:10.087998200Z
[junit4] 2> 876965 INFO (jetty-launcher-1369-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 876989 INFO (jetty-launcher-1369-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 876992 INFO (jetty-launcher-1369-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 877017 INFO (jetty-launcher-1369-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 877019 INFO (jetty-launcher-1369-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:64114/solr
[junit4] 2> 877028 INFO (jetty-launcher-1369-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 877029 INFO (jetty-launcher-1369-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:64114/solr
[junit4] 2> 877031 INFO (jetty-launcher-1369-thread-3) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 877032 INFO (jetty-launcher-1369-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:64114/solr
[junit4] 2> 877034 INFO (jetty-launcher-1369-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 877044 INFO (jetty-launcher-1369-thread-4) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 877045 INFO (jetty-launcher-1369-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:64114/solr
[junit4] 2> 877057 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 0x15e31733f070007, 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> 877142 INFO (jetty-launcher-1369-thread-2) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 877142 INFO (jetty-launcher-1369-thread-1) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 877142 INFO (jetty-launcher-1369-thread-3) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 877143 INFO (jetty-launcher-1369-thread-4) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 877144 INFO (jetty-launcher-1369-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:64126_solr
[junit4] 2> 877145 INFO (jetty-launcher-1369-thread-1) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64118_solr
[junit4] 2> 877146 INFO (jetty-launcher-1369-thread-3) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64123_solr
[junit4] 2> 877148 INFO (jetty-launcher-1369-thread-4) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64133_solr
[junit4] 2> 877148 INFO (jetty-launcher-1369-thread-2) [ ] o.a.s.c.Overseer Overseer (id=98570612897153033-127.0.0.1:64126_solr-n_0000000000) starting
[junit4] 2> 877216 INFO (jetty-launcher-1369-thread-3) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.OverseerRolesTest_CAF3A4D85571E668-001\tempDir-001\node3\.
[junit4] 2> 877237 INFO (zkCallback-1390-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 877237 INFO (zkCallback-1391-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 877246 INFO (jetty-launcher-1369-thread-1) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.OverseerRolesTest_CAF3A4D85571E668-001\tempDir-001\node1\.
[junit4] 2> 877247 INFO (zkCallback-1389-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 877250 INFO (zkCallback-1388-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 877251 INFO (zkCallback-1388-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 877251 INFO (zkCallback-1391-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 877288 INFO (jetty-launcher-1369-thread-4) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.OverseerRolesTest_CAF3A4D85571E668-001\tempDir-001\node2\.
[junit4] 2> 877306 INFO (jetty-launcher-1369-thread-2) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64126_solr
[junit4] 2> 877321 INFO (zkCallback-1388-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 877323 INFO (zkCallback-1391-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 877326 INFO (zkCallback-1390-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 877328 INFO (zkCallback-1389-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 877389 INFO (jetty-launcher-1369-thread-2) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.OverseerRolesTest_CAF3A4D85571E668-001\tempDir-001\node4\.
[junit4] 2> 877402 INFO (SUITE-OverseerRolesTest-seed#[CAF3A4D85571E668]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 877404 INFO (SUITE-OverseerRolesTest-seed#[CAF3A4D85571E668]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:64114/solr ready
[junit4] 2> 877439 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testOverseerRole
[junit4] 2> 877441 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.c.OverseerRolesTest Overseer: 127.0.0.1:64126_solr
[junit4] 2> 877441 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.c.OverseerRolesTest Election queue:
[junit4] 2> 877445 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.c.OverseerRolesTest ### Setting overseer designate 127.0.0.1:64118_solr
[junit4] 2> 877471 INFO (qtp549510336-8387) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addrole with params node=127.0.0.1:64118_solr&role=overseer&action=ADDROLE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 877498 INFO (OverseerThreadFactory-4785-thread-1) [ ] o.a.s.c.OverseerRoleCmd Overseer role added to 127.0.0.1:64118_solr
[junit4] 2> 877506 INFO (qtp549510336-8387) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={node=127.0.0.1:64118_solr&role=overseer&action=ADDROLE&wt=javabin&version=2} status=0 QTime=35
[junit4] 2> 877508 INFO (Thread-2059) [ ] o.a.s.c.OverseerNodePrioritizer prioritizing overseer nodes at 98570612897153033-127.0.0.1:64126_solr-n_0000000000 overseer designates are [127.0.0.1:64118_solr]
[junit4] 2> 877509 INFO (Thread-2059) [ ] o.a.s.c.OverseerNodePrioritizer sorted nodes [98570612897153033-127.0.0.1:64126_solr-n_0000000000, 98570612897153035-127.0.0.1:64118_solr-n_0000000001, 98570612897153034-127.0.0.1:64123_solr-n_0000000002, 98570612897153036-127.0.0.1:64133_solr-n_0000000003]
[junit4] 2> 877512 INFO (OverseerStateUpdate-98570612897153033-127.0.0.1:64126_solr-n_0000000000) [ ] o.a.s.c.Overseer Quit command received {
[junit4] 2> "operation":"quit",
[junit4] 2> "id":"98570612897153033-127.0.0.1:64126_solr-n_0000000000"} 127.0.0.1:64126_solr
[junit4] 2> 877514 INFO (OverseerStateUpdate-98570612897153033-127.0.0.1:64126_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:64126_solr
[junit4] 2> 877515 WARN (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting, but I'm still the leader
[junit4] 2> 877516 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer Overseer (id=98570612897153033-127.0.0.1:64126_solr-n_0000000000) closing
[junit4] 2> 877518 INFO (zkCallback-1388-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:64118_solr
[junit4] 2> 877522 INFO (zkCallback-1388-thread-2) [ ] o.a.s.c.Overseer Overseer (id=98570612897153035-127.0.0.1:64118_solr-n_0000000001) starting
[junit4] 2> 877609 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.c.OverseerRolesTest ### Adding another overseer designate 127.0.0.1:64133_solr
[junit4] 2> 877611 INFO (qtp549510336-8384) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addrole with params node=127.0.0.1:64133_solr&role=overseer&action=ADDROLE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 877618 INFO (OverseerThreadFactory-4789-thread-1) [ ] o.a.s.c.OverseerRoleCmd Overseer role added to 127.0.0.1:64133_solr
[junit4] 2> 877623 INFO (qtp549510336-8384) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={node=127.0.0.1:64133_solr&role=overseer&action=ADDROLE&wt=javabin&version=2} status=0 QTime=12
[junit4] 2> 877625 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.c.OverseerRolesTest Overseer: 127.0.0.1:64118_solr
[junit4] 2> 877625 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.c.OverseerRolesTest Election queue:
[junit4] 2> 877625 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.c.ChaosMonkey monkey: stop shard! 64118
[junit4] 2> 877626 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=3946439
[junit4] 2> 877626 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 877626 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
[junit4] 2> 877626 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 877628 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 877630 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.c.Overseer Overseer (id=98570612897153035-127.0.0.1:64118_solr-n_0000000001) closing
[junit4] 2> 877632 INFO (OverseerStateUpdate-98570612897153035-127.0.0.1:64118_solr-n_0000000001) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:64118_solr
[junit4] 2> 877640 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 0x15e31733f07000b, 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> 877643 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1fd99fd2{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 877645 INFO (zkCallback-1391-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 877645 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@520839a8{/solr,null,UNAVAILABLE}
[junit4] 2> 877645 INFO (zkCallback-1390-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:64123_solr
[junit4] 2> 877648 INFO (zkCallback-1389-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 877648 INFO (zkCallback-1390-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 877648 INFO (zkCallback-1399-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 877658 INFO (zkCallback-1390-thread-2) [ ] o.a.s.c.Overseer Overseer (id=98570612897153034-127.0.0.1:64123_solr-n_0000000002) starting
[junit4] 2> 877670 INFO (OverseerCollectionConfigSetProcessor-98570612897153034-127.0.0.1:64123_solr-n_0000000002) [ ] o.a.s.c.OverseerNodePrioritizer prioritizing overseer nodes at 98570612897153034-127.0.0.1:64123_solr-n_0000000002 overseer designates are [127.0.0.1:64118_solr, 127.0.0.1:64133_solr]
[junit4] 2> 877671 INFO (OverseerCollectionConfigSetProcessor-98570612897153034-127.0.0.1:64123_solr-n_0000000002) [ ] o.a.s.c.OverseerNodePrioritizer sorted nodes [98570612897153034-127.0.0.1:64123_solr-n_0000000002, 98570612897153036-127.0.0.1:64133_solr-n_0000000003, 98570612897153033-127.0.0.1:64126_solr-n_0000000004]
[junit4] 2> 877687 INFO (OverseerStateUpdate-98570612897153034-127.0.0.1:64123_solr-n_0000000002) [ ] o.a.s.c.Overseer Quit command received {
[junit4] 2> "operation":"quit",
[junit4] 2> "id":"98570612897153034-127.0.0.1:64123_solr-n_0000000002"} 127.0.0.1:64123_solr
[junit4] 2> 877688 INFO (OverseerStateUpdate-98570612897153034-127.0.0.1:64123_solr-n_0000000002) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:64123_solr
[junit4] 2> 877703 WARN (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting, but I'm still the leader
[junit4] 2> 877704 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer Overseer (id=98570612897153034-127.0.0.1:64123_solr-n_0000000002) closing
[junit4] 2> 877707 INFO (zkCallback-1391-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:64133_solr
[junit4] 2> 877709 INFO (zkCallback-1391-thread-2) [ ] o.a.s.c.Overseer Overseer (id=98570612897153036-127.0.0.1:64133_solr-n_0000000003) starting
[junit4] 2> 877759 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.c.OverseerRolesTest ### Adding last overseer designate 127.0.0.1:64123_solr
[junit4] 2> 877760 INFO (qtp549510336-8383) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addrole with params node=127.0.0.1:64123_solr&role=overseer&action=ADDROLE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 877766 INFO (OverseerThreadFactory-4794-thread-1) [ ] o.a.s.c.OverseerRoleCmd Overseer role added to 127.0.0.1:64123_solr
[junit4] 2> 877770 INFO (qtp549510336-8383) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={node=127.0.0.1:64123_solr&role=overseer&action=ADDROLE&wt=javabin&version=2} status=0 QTime=9
[junit4] 2> 877771 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.c.OverseerRolesTest Overseer: 127.0.0.1:64133_solr
[junit4] 2> 877772 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.c.OverseerRolesTest Election queue:
[junit4] 2> 877773 INFO (qtp549510336-8382) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :removerole with params node=127.0.0.1:64133_solr&role=overseer&action=REMOVEROLE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 877778 INFO (OverseerCollectionConfigSetProcessor-98570612897153036-127.0.0.1:64133_solr-n_0000000003) [ ] 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> 877780 INFO (OverseerThreadFactory-4794-thread-2) [ ] o.a.s.c.OverseerRoleCmd Overseer role removed from 127.0.0.1:64133_solr
[junit4] 2> 877782 INFO (qtp549510336-8382) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={node=127.0.0.1:64133_solr&role=overseer&action=REMOVEROLE&wt=javabin&version=2} status=0 QTime=9
[junit4] 2> 877785 INFO (Thread-2063) [ ] o.a.s.c.OverseerNodePrioritizer prioritizing overseer nodes at 98570612897153036-127.0.0.1:64133_solr-n_0000000003 overseer designates are [127.0.0.1:64118_solr, 127.0.0.1:64123_solr]
[junit4] 2> 877785 INFO (Thread-2063) [ ] o.a.s.c.OverseerNodePrioritizer sorted nodes [98570612897153036-127.0.0.1:64133_solr-n_0000000003, 98570612897153033-127.0.0.1:64126_solr-n_0000000004, 98570612897153034-127.0.0.1:64123_solr-n_0000000005]
[junit4] 2> 877785 INFO (Thread-2063) [ ] o.a.s.c.OverseerNodePrioritizer asking node 98570612897153034-127.0.0.1:64123_solr-n_0000000005 to come join election at head
[junit4] 2> 877790 INFO (qtp675425393-8372) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={op=rejoinAtHead&qt=/admin/cores&action=OVERSEEROP&electionNode=98570612897153034-127.0.0.1:64123_solr-n_0000000005&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 877791 INFO (Thread-2063) [ ] o.a.s.c.OverseerNodePrioritizer asking the old first in line 98570612897153033-127.0.0.1:64126_solr-n_0000000004 to rejoin election
[junit4] 2> 877794 INFO (qtp1019253729-8358) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={op=rejoin&qt=/admin/cores&action=OVERSEEROP&electionNode=98570612897153033-127.0.0.1:64126_solr-n_0000000004&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 877798 INFO (OverseerStateUpdate-98570612897153036-127.0.0.1:64133_solr-n_0000000003) [ ] o.a.s.c.Overseer Quit command received {
[junit4] 2> "operation":"quit",
[junit4] 2> "id":"98570612897153036-127.0.0.1:64133_solr-n_0000000003"} 127.0.0.1:64133_solr
[junit4] 2> 877799 INFO (OverseerStateUpdate-98570612897153036-127.0.0.1:64133_solr-n_0000000003) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:64133_solr
[junit4] 2> 877802 WARN (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting, but I'm still the leader
[junit4] 2> 877804 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer Overseer (id=98570612897153036-127.0.0.1:64133_solr-n_0000000003) closing
[junit4] 2> 877805 INFO (zkCallback-1389-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:64126_solr
[junit4] 2> 877809 INFO (zkCallback-1389-thread-2) [ ] o.a.s.c.Overseer Overseer (id=98570612897153033-127.0.0.1:64126_solr-n_0000000004) starting
[junit4] 2> 877820 INFO (OverseerCollectionConfigSetProcessor-98570612897153033-127.0.0.1:64126_solr-n_0000000004) [ ] o.a.s.c.OverseerNodePrioritizer prioritizing overseer nodes at 98570612897153033-127.0.0.1:64126_solr-n_0000000004 overseer designates are [127.0.0.1:64118_solr, 127.0.0.1:64123_solr]
[junit4] 2> 877821 INFO (OverseerCollectionConfigSetProcessor-98570612897153033-127.0.0.1:64126_solr-n_0000000004) [ ] o.a.s.c.OverseerNodePrioritizer sorted nodes [98570612897153033-127.0.0.1:64126_solr-n_0000000004, 98570612897153034-127.0.0.1:64123_solr-n_0000000005, 98570612897153036-127.0.0.1:64133_solr-n_0000000006]
[junit4] 2> 877825 INFO (OverseerStateUpdate-98570612897153033-127.0.0.1:64126_solr-n_0000000004) [ ] o.a.s.c.Overseer Quit command received {
[junit4] 2> "operation":"quit",
[junit4] 2> "id":"98570612897153033-127.0.0.1:64126_solr-n_0000000004"} 127.0.0.1:64126_solr
[junit4] 2> 877829 INFO (OverseerStateUpdate-98570612897153033-127.0.0.1:64126_solr-n_0000000004) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:64126_solr
[junit4] 2> 877835 WARN (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting, but I'm still the leader
[junit4] 2> 877838 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer Overseer (id=98570612897153033-127.0.0.1:64126_solr-n_0000000004) closing
[junit4] 2> 877840 INFO (zkCallback-1390-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:64123_solr
[junit4] 2> 877843 INFO (zkCallback-1390-thread-2) [ ] o.a.s.c.Overseer Overseer (id=98570612897153034-127.0.0.1:64123_solr-n_0000000005) starting
[junit4] 2> 877885 INFO (qtp549510336-8381) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addrole with params node=127.0.0.1:64133_solr&role=overseer&action=ADDROLE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 877892 INFO (OverseerThreadFactory-4798-thread-1) [ ] o.a.s.c.OverseerRoleCmd Overseer role added to 127.0.0.1:64133_solr
[junit4] 2> 877896 INFO (qtp549510336-8381) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={node=127.0.0.1:64133_solr&role=overseer&action=ADDROLE&wt=javabin&version=2} status=0 QTime=9
[junit4] 2> 877897 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.c.OverseerRolesTest ### Sending QUIT to overseer 127.0.0.1:64123_solr
[junit4] 2> 877901 INFO (OverseerStateUpdate-98570612897153034-127.0.0.1:64123_solr-n_0000000005) [ ] o.a.s.c.Overseer Quit command received {
[junit4] 2> "operation":"quit",
[junit4] 2> "id":"98570612897153034-127.0.0.1:64123_solr-n_0000000005"} 127.0.0.1:64123_solr
[junit4] 2> 877902 INFO (OverseerStateUpdate-98570612897153034-127.0.0.1:64123_solr-n_0000000005) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:64123_solr
[junit4] 2> 877907 WARN (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting, but I'm still the leader
[junit4] 2> 877909 INFO (Thread-2064) [ ] o.a.s.c.OverseerNodePrioritizer prioritizing overseer nodes at 98570612897153034-127.0.0.1:64123_solr-n_0000000005 overseer designates are [127.0.0.1:64118_solr, 127.0.0.1:64123_solr, 127.0.0.1:64133_solr]
[junit4] 2> 877909 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer Overseer (id=98570612897153034-127.0.0.1:64123_solr-n_0000000005) closing
[junit4] 2> 877910 INFO (Thread-2064) [ ] o.a.s.c.OverseerNodePrioritizer sorted nodes [98570612897153036-127.0.0.1:64133_solr-n_0000000006, 98570612897153033-127.0.0.1:64126_solr-n_0000000007]
[junit4] 2> 877910 INFO (Thread-2064) [ ] o.a.s.c.OverseerNodePrioritizer asking node 98570612897153036-127.0.0.1:64133_solr-n_0000000006 to come join election at head
[junit4] 2> 877912 INFO (zkCallback-1391-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:64133_solr
[junit4] 2> 877912 INFO (qtp549510336-8367) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={op=rejoinAtHead&qt=/admin/cores&action=OVERSEEROP&electionNode=98570612897153036-127.0.0.1:64133_solr-n_0000000006&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 877915 INFO (Thread-2064) [ ] o.a.s.c.OverseerNodePrioritizer asking the old first in line 98570612897153033-127.0.0.1:64126_solr-n_0000000007 to rejoin election
[junit4] 2> 877919 INFO (qtp1019253729-8394) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={op=rejoin&qt=/admin/cores&action=OVERSEEROP&electionNode=98570612897153033-127.0.0.1:64126_solr-n_0000000007&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 877921 INFO (zkCallback-1391-thread-2) [ ] o.a.s.c.Overseer Overseer (id=98570612897153036-127.0.0.1:64133_solr-n_0000000006) starting
[junit4] 2> 877938 INFO (OverseerStateUpdate-98570612897153036-127.0.0.1:64133_solr-n_0000000006) [ ] o.a.s.c.Overseer Quit command received {
[junit4] 2> "operation":"quit",
[junit4] 2> "id":"98570612897153036-127.0.0.1:64133_solr-n_0000000006"} 127.0.0.1:64133_solr
[junit4] 2> 877940 INFO (OverseerStateUpdate-98570612897153036-127.0.0.1:64133_solr-n_0000000006) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:64133_solr
[junit4] 2> 877944 WARN (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting, but I'm still the leader
[junit4] 2> 877945 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer Overseer (id=98570612897153036-127.0.0.1:64133_solr-n_0000000006) closing
[junit4] 2> 877947 INFO (zkCallback-1389-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:64126_solr
[junit4] 2> 877949 INFO (zkCallback-1389-thread-2) [ ] o.a.s.c.Overseer Overseer (id=98570612897153033-127.0.0.1:64126_solr-n_0000000007) starting
[junit4] 2> 877962 INFO (OverseerCollectionConfigSetProcessor-98570612897153033-127.0.0.1:64126_solr-n_0000000007) [ ] o.a.s.c.OverseerNodePrioritizer prioritizing overseer nodes at 98570612897153033-127.0.0.1:64126_solr-n_0000000007 overseer designates are [127.0.0.1:64118_solr, 127.0.0.1:64123_solr, 127.0.0.1:64133_solr]
[junit4] 2> 877962 INFO (OverseerCollectionConfigSetProcessor-98570612897153033-127.0.0.1:64126_solr-n_0000000007) [ ] o.a.s.c.OverseerNodePrioritizer sorted nodes [98570612897153033-127.0.0.1:64126_solr-n_0000000007, 98570612897153034-127.0.0.1:64123_solr-n_0000000008, 98570612897153036-127.0.0.1:64133_solr-n_0000000009]
[junit4] 2> 877965 INFO (OverseerStateUpdate-98570612897153033-127.0.0.1:64126_solr-n_0000000007) [ ] o.a.s.c.Overseer Quit command received {
[junit4] 2> "operation":"quit",
[junit4] 2> "id":"98570612897153033-127.0.0.1:64126_solr-n_0000000007"} 127.0.0.1:64126_solr
[junit4] 2> 877966 INFO (OverseerStateUpdate-98570612897153033-127.0.0.1:64126_solr-n_0000000007) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:64126_solr
[junit4] 2> 877970 WARN (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting, but I'm still the leader
[junit4] 2> 877972 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer Overseer (id=98570612897153033-127.0.0.1:64126_solr-n_0000000007) closing
[junit4] 2> 877974 INFO (zkCallback-1390-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:64123_solr
[junit4] 2> 877977 INFO (zkCallback-1390-thread-2) [ ] o.a.s.c.Overseer Overseer (id=98570612897153034-127.0.0.1:64123_solr-n_0000000008) starting
[junit4] 2> 879138 ERROR (Thread-2060) [ ] o.a.s.c.OverseerRoleCmd Error in prioritizing Overseer
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1212)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:357)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:354)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:354)
[junit4] 2> at org.apache.solr.cloud.OverseerNodePrioritizer.prioritizeOverseerNodes(OverseerNodePrioritizer.java:62)
[junit4] 2> at org.apache.solr.cloud.OverseerRoleCmd.lambda$call$0(OverseerRoleCmd.java:93)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 892937 INFO (TEST-OverseerRolesTest.testOverseerRole-seed#[CAF3A4D85571E668]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testOverseerRole
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerRolesTest -Dtests.method=testOverseerRole -Dtests.seed=CAF3A4D85571E668 -Dtests.slow=true -Dtests.locale=pt-ST -Dtests.timezone=Asia/Omsk -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 15.5s J1 | OverseerRolesTest.testOverseerRole <<<
[junit4] > Throwable #1: java.lang.AssertionError: Timed out waiting for overseer state change
[junit4] > at __randomizedtesting.SeedInfo.seed([CAF3A4D85571E668:2B38594C6EC2D0B9]:0)
[junit4] > at org.apache.solr.cloud.OverseerRolesTest.waitForNewOverseer(OverseerRolesTest.java:62)
[junit4] > at org.apache.solr.cloud.OverseerRolesTest.testOverseerRole(OverseerRolesTest.java:140)
[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> 892945 INFO (jetty-closer-1370-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@fc9c4e9{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 892947 INFO (jetty-closer-1370-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1136138534
[junit4] 2> 892949 INFO (jetty-closer-1370-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 892949 INFO (jetty-closer-1370-thread-4) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@5ef9fc1d{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 892949 INFO (jetty-closer-1370-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
[junit4] 2> 892952 INFO (jetty-closer-1370-thread-4) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1075210334
[junit4] 2> 892952 INFO (jetty-closer-1370-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 892953 INFO (jetty-closer-1370-thread-3) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@679d01e4{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 892955 INFO (jetty-closer-1370-thread-3) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=575917997
[junit4] 2> 892955 INFO (jetty-closer-1370-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 892955 INFO (jetty-closer-1370-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
[junit4] 2> 892955 INFO (jetty-closer-1370-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 892955 INFO (jetty-closer-1370-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 892955 INFO (jetty-closer-1370-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
[junit4] 2> 892955 INFO (jetty-closer-1370-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 892959 INFO (jetty-closer-1370-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 892960 INFO (jetty-closer-1370-thread-1) [ ] o.a.s.c.Overseer Overseer (id=98570612897153034-127.0.0.1:64123_solr-n_0000000008) closing
[junit4] 2> 892960 INFO (jetty-closer-1370-thread-4) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 892961 INFO (OverseerStateUpdate-98570612897153034-127.0.0.1:64123_solr-n_0000000008) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:64123_solr
[junit4] 2> 892965 INFO (jetty-closer-1370-thread-3) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 892967 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 0x15e31733f07000a, 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> 892970 WARN (zkCallback-1390-thread-2) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 892970 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 0x15e31733f070009, 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> 892972 WARN (zkCallback-1391-thread-2) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 892973 INFO (jetty-closer-1370-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@379f9317{/solr,null,UNAVAILABLE}
[junit4] 2> 894471 WARN (zkCallback-1389-thread-2) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 894471 INFO (jetty-closer-1370-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6bd0cb81{/solr,null,UNAVAILABLE}
[junit4] 2> 894473 INFO (jetty-closer-1370-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@66efc2c7{/solr,null,UNAVAILABLE}
[junit4] 2> 894475 ERROR (SUITE-OverseerRolesTest-seed#[CAF3A4D85571E668]-worker) [ ] 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> 894476 INFO (SUITE-OverseerRolesTest-seed#[CAF3A4D85571E668]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:64114 64114
[junit4] 2> 894476 INFO (Thread-2010) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:64114 64114
[junit4] 2> 894478 WARN (Thread-2010) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 5 /solr/aliases.json
[junit4] 2> 5 /solr/clusterprops.json
[junit4] 2> 4 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 5 /solr/clusterstate.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 9 /solr/overseer/queue-work
[junit4] 2> 5 /solr/live_nodes
[junit4] 2> 5 /solr/collections
[junit4] 2> 4 /solr/overseer/collection-queue-work
[junit4] 2> 2 /solr/overseer/queue
[junit4] 2>
[junit4] 2> 894478 INFO (SUITE-OverseerRolesTest-seed#[CAF3A4D85571E668]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.OverseerRolesTest_CAF3A4D85571E668-001
[junit4] 2> Aug 30, 2017 4:43:27 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(Lucene62): {}, docValues:{}, maxPointsInLeafNode=466, maxMBSortInHeap=5.878453781413317, sim=RandomSimilarity(queryNorm=true,coord=yes): {}, locale=pt-ST, timezone=Asia/Omsk
[junit4] 2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 9 (64-bit)/cpus=3,threads=1,free=228003616,total=509607936
[junit4] 2> NOTE: All tests run in this JVM: [NoCacheHeaderTest, JsonLoaderTest, HighlighterMaxOffsetTest, MultiThreadedOCPTest, BasicFunctionalityTest, TestZkAclsWithHadoopAuth, ClassificationUpdateProcessorIntegrationTest, TestUninvertingReader, SolrGraphiteReporterTest, TestDynamicLoading, TestSimpleTrackingShardHandler, TestRebalanceLeaders, LeaderElectionContextKeyTest, TestSystemCollAutoCreate, TestDFRSimilarityFactory, TermVectorComponentDistributedTest, CircularListTest, CSVRequestHandlerTest, UtilsToolTest, SuggesterTest, CoreAdminCreateDiscoverTest, TestIndexingPerformance, ZkSolrClientTest, TestXmlQParser, HdfsBasicDistributedZkTest, TestCloudNestedDocsSort, TestSearchPerf, CreateCollectionCleanupTest, TestDocSet, TestSolrFieldCacheMBean, StatsReloadRaceTest, TestFiltering, DistributedFacetPivotWhiteBoxTest, DistribJoinFromCollectionTest, LargeFieldTest, TestPointFields, TemplateUpdateProcessorTest, CollectionsAPISolrJTest, TestSolr4Spatial, TestReqParamsAPI, TestQuerySenderNoQuery, DistanceFunctionTest, MBeansHandlerTest, SolrMetricsIntegrationTest, TestSimpleQParserPlugin, DistributedVersionInfoTest, IgnoreCommitOptimizeUpdateProcessorFactoryTest, FileBasedSpellCheckerTest, TestFieldCollectionResource, TestSolrConfigHandler, TestChildDocTransformer, PreAnalyzedUpdateProcessorTest, TestReloadDeadlock, TestAddFieldRealTimeGet, TestUtils, TestMultiWordSynonyms, UpdateParamsTest, HdfsChaosMonkeySafeLeaderTest, TestRestManager, TestLuceneMatchVersion, TestSolrQueryParser, TestImpersonationWithHadoopAuth, RuleEngineTest, TestWriterPerf, TestRecovery, SharedFSAutoReplicaFailoverUtilsTest, TestMinMaxOnMultiValuedField, FullSolrCloudDistribCmdsTest, TermVectorComponentTest, TestSchemaNameResource, SolrJmxReporterTest, TestMaxScoreQueryParser, AnalyticsQueryTest, TestManagedResource, TestBinaryResponseWriter, DirectUpdateHandlerOptimizeTest, TestIndexSearcher, OpenCloseCoreStressTest, TestDistributedGrouping, TestExpandComponent, SolrCmdDistributorTest, DeleteNodeTest, TestSystemIdResolver, CoreSorterTest, SuggesterWFSTTest, TestRandomFlRTGCloud, MinimalSchemaTest, TestHashQParserPlugin, DataDrivenBlockJoinTest, TestPayloadScoreQParserPlugin, TestGraphMLResponseWriter, HdfsRecoveryZkTest, TestPerFieldSimilarityClassic, TestCustomSort, TestMiniSolrCloudClusterSSL, BadIndexSchemaTest, JvmMetricsTest, TestCloudDeleteByQuery, TestCoreAdminApis, TestQueryTypes, URLClassifyProcessorTest, TestFieldTypeCollectionResource, TestTrackingShardHandlerFactory, TestValueSourceCache, OverseerTaskQueueTest, TestSortByMinMaxFunction, FieldMutatingUpdateProcessorTest, TestBadConfig, TestSolrCoreSnapshots, BadCopyFieldTest, BufferStoreTest, TestCorePropertiesReload, AddSchemaFieldsUpdateProcessorFactoryTest, SpatialRPTFieldTypeTest, NotRequiredUniqueKeyTest, HLLSerializationTest, TestRandomCollapseQParserPlugin, TestCodecSupport, TestStressUserVersions, DebugComponentTest, SolrMetricManagerTest, IndexSchemaTest, CachingDirectoryFactoryTest, TestFieldCacheWithThreads, SimpleMLTQParserTest, SpellPossibilityIteratorTest, TestEmbeddedSolrServerSchemaAPI, UpdateRequestProcessorFactoryTest, TestExportWriter, TestFieldCache, CurrencyFieldOpenExchangeTest, ExitableDirectoryReaderTest, TestOverriddenPrefixQueryForCustomFieldType, LeaderInitiatedRecoveryOnShardRestartTest, ChangedSchemaMergeTest, SpellCheckCollatorWithCollapseTest, TestRangeQuery, TestDynamicFieldCollectionResource, ShowFileRequestHandlerTest, TestCloudManagedSchema, CollectionReloadTest, TestReload, DistributedTermsComponentTest, TestPKIAuthenticationPlugin, UUIDFieldTest, QueryParsingTest, TestPushWriter, SolrCoreCheckLockOnStartupTest, TestConfigOverlay, CdcrReplicationHandlerTest, ResourceLoaderTest, RegexBoostProcessorTest, TestBlendedInfixSuggestions, TestOmitPositions, TestJmxMonitoredMap, TestSolrCloudWithDelegationTokens, SortByFunctionTest, CoreMergeIndexesAdminHandlerTest, OverseerRolesTest]
[junit4] Completed [290/713 (1!)] on J1 in 18.19s, 1 test, 1 failure <<< FAILURES!
[...truncated 37712 lines...]
[JENKINS] Lucene-Solr-6.6-Windows (64bit/jdk1.8.0_144) - Build # 45
- Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.6-Windows/45/
Java: 64bit/jdk1.8.0_144 -XX:+UseCompressedOops -XX:+UseSerialGC
1 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([C27621E866A5063B:16336AB181F3B5C0]: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 sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 12566 lines...]
[junit4] Suite: org.apache.solr.cloud.CdcrBootstrapTest
[junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_C27621E866A5063B-001\init-core-data-001
[junit4] 2> 1516952 INFO (SUITE-CdcrBootstrapTest-seed#[C27621E866A5063B]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields
[junit4] 2> 1516953 INFO (SUITE-CdcrBootstrapTest-seed#[C27621E866A5063B]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 1516954 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testConvertClusterToCdcrAndBootstrap
[junit4] 2> 1516955 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_C27621E866A5063B-001\cdcr-target-001
[junit4] 2> 1516955 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1516956 INFO (Thread-4217) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1516956 INFO (Thread-4217) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1516958 ERROR (Thread-4217) [ ] 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> 1517056 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.ZkTestServer start zk server on port:52087
[junit4] 2> 1517063 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 0x15e3365b3700000, 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.lang.Thread.run(Thread.java:748)
[junit4] 2> 1517069 INFO (jetty-launcher-2564-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1517071 INFO (jetty-launcher-2564-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3f90929e{/solr,null,AVAILABLE}
[junit4] 2> 1517072 INFO (jetty-launcher-2564-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@129c7e2b{SSL,[ssl, http/1.1]}{127.0.0.1:52091}
[junit4] 2> 1517072 INFO (jetty-launcher-2564-thread-1) [ ] o.e.j.s.Server Started @1519785ms
[junit4] 2> 1517072 INFO (jetty-launcher-2564-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52091}
[junit4] 2> 1517073 ERROR (jetty-launcher-2564-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1517073 INFO (jetty-launcher-2564-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.1
[junit4] 2> 1517073 INFO (jetty-launcher-2564-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1517073 INFO (jetty-launcher-2564-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1517073 INFO (jetty-launcher-2564-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-30T13:47:36.804Z
[junit4] 2> 1517077 INFO (jetty-launcher-2564-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1517086 INFO (jetty-launcher-2564-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1517087 INFO (jetty-launcher-2564-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52087/solr
[junit4] 2> 1517107 INFO (jetty-launcher-2564-thread-1) [n:127.0.0.1:52091_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1517108 INFO (jetty-launcher-2564-thread-1) [n:127.0.0.1:52091_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:52091_solr
[junit4] 2> 1517108 INFO (jetty-launcher-2564-thread-1) [n:127.0.0.1:52091_solr ] o.a.s.c.Overseer Overseer (id=98572753743904771-127.0.0.1:52091_solr-n_0000000000) starting
[junit4] 2> 1517116 INFO (jetty-launcher-2564-thread-1) [n:127.0.0.1:52091_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52091_solr
[junit4] 2> 1517117 INFO (zkCallback-2571-thread-1-processing-n:127.0.0.1:52091_solr) [n:127.0.0.1:52091_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1517215 INFO (jetty-launcher-2564-thread-1) [n:127.0.0.1:52091_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_C27621E866A5063B-001\cdcr-target-001\node1\.
[junit4] 1> Target zkHost = 127.0.0.1:52087/solr
[junit4] 2> 1517233 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_C27621E866A5063B-001\cdcr-source-001
[junit4] 2> 1517233 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1517234 INFO (Thread-4230) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1517234 INFO (Thread-4230) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1517238 ERROR (Thread-4230) [ ] 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> 1517333 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.ZkTestServer start zk server on port:52111
[junit4] 2> 1517344 INFO (jetty-launcher-2576-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1517345 INFO (jetty-launcher-2576-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@55bde311{/solr,null,AVAILABLE}
[junit4] 2> 1517346 INFO (jetty-launcher-2576-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6bf9c52{SSL,[ssl, http/1.1]}{127.0.0.1:52115}
[junit4] 2> 1517346 INFO (jetty-launcher-2576-thread-1) [ ] o.e.j.s.Server Started @1520059ms
[junit4] 2> 1517346 INFO (jetty-launcher-2576-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52115}
[junit4] 2> 1517346 ERROR (jetty-launcher-2576-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1517347 INFO (jetty-launcher-2576-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.1
[junit4] 2> 1517347 INFO (jetty-launcher-2576-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1517347 INFO (jetty-launcher-2576-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1517347 INFO (jetty-launcher-2576-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-30T13:47:37.078Z
[junit4] 2> 1517350 INFO (jetty-launcher-2576-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1517361 INFO (jetty-launcher-2576-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1517362 INFO (jetty-launcher-2576-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52111/solr
[junit4] 2> 1517381 INFO (jetty-launcher-2576-thread-1) [n:127.0.0.1:52115_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1517381 INFO (jetty-launcher-2576-thread-1) [n:127.0.0.1:52115_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:52115_solr
[junit4] 2> 1517382 INFO (jetty-launcher-2576-thread-1) [n:127.0.0.1:52115_solr ] o.a.s.c.Overseer Overseer (id=98572753762254851-127.0.0.1:52115_solr-n_0000000000) starting
[junit4] 2> 1517388 INFO (jetty-launcher-2576-thread-1) [n:127.0.0.1:52115_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52115_solr
[junit4] 2> 1517389 INFO (zkCallback-2583-thread-1-processing-n:127.0.0.1:52115_solr) [n:127.0.0.1:52115_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1517473 INFO (jetty-launcher-2576-thread-1) [n:127.0.0.1:52115_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_C27621E866A5063B-001\cdcr-source-001\node1\.
[junit4] 2> 1517489 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 0x15e3365b4880005, 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.lang.Thread.run(Thread.java:748)
[junit4] 2> 1517499 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1517500 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:52111/solr ready
[junit4] 2> 1517532 INFO (qtp413648926-16070) [n:127.0.0.1:52115_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=cdcr-source&name=cdcr-source&action=CREATE&numShards=1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1517534 INFO (OverseerThreadFactory-7760-thread-1-processing-n:127.0.0.1:52115_solr) [n:127.0.0.1:52115_solr ] o.a.s.c.CreateCollectionCmd Create collection cdcr-source
[junit4] 2> 1517643 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=cdcr-source&newCollection=true&name=cdcr-source_shard1_replica1&action=CREATE&numShards=1&collection=cdcr-source&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2
[junit4] 2> 1517644 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1517751 INFO (zkCallback-2583-thread-1-processing-n:127.0.0.1:52115_solr) [n:127.0.0.1:52115_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1518662 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 1518684 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.IndexSchema [cdcr-source_shard1_replica1] Schema name=minimal
[junit4] 2> 1518688 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1518688 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'cdcr-source_shard1_replica1' using configuration from collection cdcr-source, trusted=true
[junit4] 2> 1518688 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1518688 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [[cdcr-source_shard1_replica1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_C27621E866A5063B-001\cdcr-source-001\node1\cdcr-source_shard1_replica1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_C27621E866A5063B-001\cdcr-source-001\node1\.\cdcr-source_shard1_replica1\data\]
[junit4] 2> 1518763 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1518763 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1518764 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1518764 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1518766 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@412d29b3[cdcr-source_shard1_replica1] main]
[junit4] 2> 1518767 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cdcr-source
[junit4] 2> 1518767 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/cdcr-source
[junit4] 2> 1518767 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1518767 INFO (searcherExecutor-7763-thread-1-processing-n:127.0.0.1:52115_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@412d29b3[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1518768 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577164061801447424
[junit4] 2> 1518773 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1518773 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1518773 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:52115/solr/cdcr-source_shard1_replica1/
[junit4] 2> 1518773 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1518773 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SyncStrategy https://127.0.0.1:52115/solr/cdcr-source_shard1_replica1/ has no replicas
[junit4] 2> 1518773 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 1518776 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:52115/solr/cdcr-source_shard1_replica1/ shard1
[junit4] 2> 1518880 INFO (zkCallback-2583-thread-1-processing-n:127.0.0.1:52115_solr) [n:127.0.0.1:52115_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1518928 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1518929 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=cdcr-source&newCollection=true&name=cdcr-source_shard1_replica1&action=CREATE&numShards=1&collection=cdcr-source&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2} status=0 QTime=1285
[junit4] 2> 1518932 INFO (qtp413648926-16070) [n:127.0.0.1:52115_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 1519033 INFO (zkCallback-2583-thread-2-processing-n:127.0.0.1:52115_solr) [n:127.0.0.1:52115_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1519536 INFO (OverseerCollectionConfigSetProcessor-98572753762254851-127.0.0.1:52115_solr-n_0000000000) [n:127.0.0.1:52115_solr ] 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> 1519932 INFO (qtp413648926-16070) [n:127.0.0.1:52115_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=cdcr-source&name=cdcr-source&action=CREATE&numShards=1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2} status=0 QTime=2399
[junit4] 1> Adding 10 docs with commit=true, numDocs=100
[junit4] 2> 1519940 INFO (qtp413648926-16066) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_0 (1577164063026184192), source_1 (1577164063029329920), source_2 (1577164063029329921), source_3 (1577164063029329922), source_4 (1577164063029329923), source_5 (1577164063029329924), source_6 (1577164063029329925), source_7 (1577164063029329926), source_8 (1577164063029329927), source_9 (1577164063029329928), ... (100 adds)]} 0 3
[junit4] 2> 1519941 INFO (qtp413648926-16068) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1519941 INFO (qtp413648926-16068) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27a57a3c
[junit4] 2> 1519964 INFO (qtp413648926-16068) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@533ffd5c[cdcr-source_shard1_replica1] main]
[junit4] 2> 1519965 INFO (searcherExecutor-7763-thread-1-processing-n:127.0.0.1:52115_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@533ffd5c[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.1):C100)))}
[junit4] 2> 1519965 INFO (qtp413648926-16068) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1519965 INFO (qtp413648926-16068) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 23
[junit4] 1> Adding 10 docs with commit=true, numDocs=200
[junit4] 2> 1519968 INFO (qtp413648926-16069) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_100 (1577164063057641472), source_101 (1577164063058690048), source_102 (1577164063058690049), source_103 (1577164063058690050), source_104 (1577164063058690051), source_105 (1577164063058690052), source_106 (1577164063058690053), source_107 (1577164063058690054), source_108 (1577164063059738624), source_109 (1577164063059738625), ... (100 adds)]} 0 2
[junit4] 2> 1519970 INFO (qtp413648926-16071) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1519970 INFO (qtp413648926-16071) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27a57a3c
[junit4] 2> 1519987 INFO (qtp413648926-16071) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7460722b[cdcr-source_shard1_replica1] main]
[junit4] 2> 1519988 INFO (searcherExecutor-7763-thread-1-processing-n:127.0.0.1:52115_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@7460722b[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.1):C100) Uninverting(_1(6.6.1):C100)))}
[junit4] 2> 1519988 INFO (qtp413648926-16071) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1519988 INFO (qtp413648926-16071) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 18
[junit4] 1> Adding 10 docs with commit=true, numDocs=300
[junit4] 2> 1519994 INFO (qtp413648926-16072) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_200 (1577164063083855872), source_201 (1577164063085953024), source_202 (1577164063085953025), source_203 (1577164063085953026), source_204 (1577164063085953027), source_205 (1577164063085953028), source_206 (1577164063085953029), source_207 (1577164063085953030), source_208 (1577164063085953031), source_209 (1577164063085953032), ... (100 adds)]} 0 2
[junit4] 2> 1519995 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1519995 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27a57a3c
[junit4] 2> 1520014 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@313e6c6[cdcr-source_shard1_replica1] main]
[junit4] 2> 1520015 INFO (searcherExecutor-7763-thread-1-processing-n:127.0.0.1:52115_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@313e6c6[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.1):C100) Uninverting(_1(6.6.1):C100) Uninverting(_2(6.6.1):C100)))}
[junit4] 2> 1520015 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1520015 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 20
[junit4] 1> Adding 10 docs with commit=true, numDocs=400
[junit4] 2> 1520020 INFO (qtp413648926-16070) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_300 (1577164063111118848), source_301 (1577164063114264576), source_302 (1577164063114264577), source_303 (1577164063114264578), source_304 (1577164063114264579), source_305 (1577164063114264580), source_306 (1577164063114264581), source_307 (1577164063114264582), source_308 (1577164063114264583), source_309 (1577164063114264584), ... (100 adds)]} 0 2
[junit4] 2> 1520022 INFO (qtp413648926-16066) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1520022 INFO (qtp413648926-16066) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27a57a3c
[junit4] 2> 1520045 INFO (qtp413648926-16066) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@40e2b24b[cdcr-source_shard1_replica1] main]
[junit4] 2> 1520045 INFO (qtp413648926-16066) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1520045 INFO (searcherExecutor-7763-thread-1-processing-n:127.0.0.1:52115_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@40e2b24b[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.1):C100) Uninverting(_1(6.6.1):C100) Uninverting(_2(6.6.1):C100) Uninverting(_3(6.6.1):C100)))}
[junit4] 2> 1520045 INFO (qtp413648926-16066) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 24
[junit4] 1> Adding 10 docs with commit=true, numDocs=500
[junit4] 2> 1520051 INFO (qtp413648926-16068) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_400 (1577164063143624704), source_401 (1577164063145721856), source_402 (1577164063145721857), source_403 (1577164063145721858), source_404 (1577164063145721859), source_405 (1577164063145721860), source_406 (1577164063145721861), source_407 (1577164063145721862), source_408 (1577164063145721863), source_409 (1577164063145721864), ... (100 adds)]} 0 2
[junit4] 2> 1520053 INFO (qtp413648926-16069) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1520053 INFO (qtp413648926-16069) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27a57a3c
[junit4] 2> 1520083 INFO (qtp413648926-16069) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@614076df[cdcr-source_shard1_replica1] main]
[junit4] 2> 1520083 INFO (searcherExecutor-7763-thread-1-processing-n:127.0.0.1:52115_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@614076df[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.1):C100) Uninverting(_1(6.6.1):C100) Uninverting(_2(6.6.1):C100) Uninverting(_3(6.6.1):C100) Uninverting(_4(6.6.1):C100)))}
[junit4] 2> 1520085 INFO (qtp413648926-16069) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1520085 INFO (qtp413648926-16069) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 31
[junit4] 1> Adding 10 docs with commit=true, numDocs=600
[junit4] 2> 1520089 INFO (qtp413648926-16071) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_500 (1577164063183470592), source_501 (1577164063185567744), source_502 (1577164063185567745), source_503 (1577164063185567746), source_504 (1577164063185567747), source_505 (1577164063185567748), source_506 (1577164063185567749), source_507 (1577164063185567750), source_508 (1577164063185567751), source_509 (1577164063185567752), ... (100 adds)]} 0 3
[junit4] 2> 1520092 INFO (qtp413648926-16072) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1520092 INFO (qtp413648926-16072) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27a57a3c
[junit4] 2> 1520128 INFO (qtp413648926-16072) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@fa08d90[cdcr-source_shard1_replica1] main]
[junit4] 2> 1520129 INFO (searcherExecutor-7763-thread-1-processing-n:127.0.0.1:52115_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@fa08d90[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.1):C100) Uninverting(_1(6.6.1):C100) Uninverting(_2(6.6.1):C100) Uninverting(_3(6.6.1):C100) Uninverting(_4(6.6.1):C100) Uninverting(_5(6.6.1):C100)))}
[junit4] 2> 1520129 INFO (qtp413648926-16072) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1520129 INFO (qtp413648926-16072) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 36
[junit4] 1> Adding 10 docs with commit=true, numDocs=700
[junit4] 2> 1520133 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_600 (1577164063229607936), source_601 (1577164063231705088), source_602 (1577164063231705089), source_603 (1577164063231705090), source_604 (1577164063231705091), source_605 (1577164063231705092), source_606 (1577164063231705093), source_607 (1577164063231705094), source_608 (1577164063231705095), source_609 (1577164063231705096), ... (100 adds)]} 0 2
[junit4] 2> 1520134 INFO (qtp413648926-16070) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1520134 INFO (qtp413648926-16070) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27a57a3c
[junit4] 2> 1520169 INFO (qtp413648926-16070) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@34f7eae0[cdcr-source_shard1_replica1] main]
[junit4] 2> 1520171 INFO (searcherExecutor-7763-thread-1-processing-n:127.0.0.1:52115_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@34f7eae0[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.1):C100) Uninverting(_1(6.6.1):C100) Uninverting(_2(6.6.1):C100) Uninverting(_3(6.6.1):C100) Uninverting(_4(6.6.1):C100) Uninverting(_5(6.6.1):C100) Uninverting(_6(6.6.1):C100)))}
[junit4] 2> 1520171 INFO (qtp413648926-16070) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1520171 INFO (qtp413648926-16070) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 36
[junit4] 1> Adding 10 docs with commit=true, numDocs=800
[junit4] 2> 1520175 INFO (qtp413648926-16066) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_700 (1577164063274696704), source_701 (1577164063275745280), source_702 (1577164063275745281), source_703 (1577164063275745282), source_704 (1577164063275745283), source_705 (1577164063275745284), source_706 (1577164063275745285), source_707 (1577164063275745286), source_708 (1577164063275745287), source_709 (1577164063275745288), ... (100 adds)]} 0 2
[junit4] 2> 1520177 INFO (qtp413648926-16068) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1520177 INFO (qtp413648926-16068) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27a57a3c
[junit4] 2> 1520214 INFO (qtp413648926-16068) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@12f99655[cdcr-source_shard1_replica1] main]
[junit4] 2> 1520214 INFO (searcherExecutor-7763-thread-1-processing-n:127.0.0.1:52115_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@12f99655[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.1):C100) Uninverting(_1(6.6.1):C100) Uninverting(_2(6.6.1):C100) Uninverting(_3(6.6.1):C100) Uninverting(_4(6.6.1):C100) Uninverting(_5(6.6.1):C100) Uninverting(_6(6.6.1):C100) Uninverting(_7(6.6.1):C100)))}
[junit4] 2> 1520214 INFO (qtp413648926-16068) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1520216 INFO (qtp413648926-16068) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 37
[junit4] 1> Adding 10 docs with commit=true, numDocs=900
[junit4] 2> 1520219 INFO (qtp413648926-16069) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_800 (1577164063320834048), source_801 (1577164063322931200), source_802 (1577164063322931201), source_803 (1577164063322931202), source_804 (1577164063322931203), source_805 (1577164063322931204), source_806 (1577164063322931205), source_807 (1577164063322931206), source_808 (1577164063322931207), source_809 (1577164063322931208), ... (100 adds)]} 0 2
[junit4] 2> 1520221 INFO (qtp413648926-16071) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1520221 INFO (qtp413648926-16071) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27a57a3c
[junit4] 2> 1520257 INFO (qtp413648926-16071) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@10d58981[cdcr-source_shard1_replica1] main]
[junit4] 2> 1520258 INFO (searcherExecutor-7763-thread-1-processing-n:127.0.0.1:52115_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@10d58981[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.1):C100) Uninverting(_1(6.6.1):C100) Uninverting(_2(6.6.1):C100) Uninverting(_3(6.6.1):C100) Uninverting(_4(6.6.1):C100) Uninverting(_5(6.6.1):C100) Uninverting(_6(6.6.1):C100) Uninverting(_7(6.6.1):C100) Uninverting(_8(6.6.1):C100)))}
[junit4] 2> 1520258 INFO (qtp413648926-16071) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1520258 INFO (qtp413648926-16071) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 36
[junit4] 1> Adding 10 docs with commit=true, numDocs=1000
[junit4] 2> 1520262 INFO (qtp413648926-16072) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_900 (1577164063364874240), source_901 (1577164063366971392), source_902 (1577164063366971393), source_903 (1577164063366971394), source_904 (1577164063366971395), source_905 (1577164063366971396), source_906 (1577164063366971397), source_907 (1577164063366971398), source_908 (1577164063366971399), source_909 (1577164063366971400), ... (100 adds)]} 0 2
[junit4] 2> 1520263 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1520263 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27a57a3c
[junit4] 2> 1520308 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5e8faf2f[cdcr-source_shard1_replica1] main]
[junit4] 2> 1520308 INFO (searcherExecutor-7763-thread-1-processing-n:127.0.0.1:52115_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@5e8faf2f[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.1):C100) Uninverting(_1(6.6.1):C100) Uninverting(_2(6.6.1):C100) Uninverting(_3(6.6.1):C100) Uninverting(_4(6.6.1):C100) Uninverting(_5(6.6.1):C100) Uninverting(_6(6.6.1):C100) Uninverting(_7(6.6.1):C100) Uninverting(_8(6.6.1):C100) Uninverting(_9(6.6.1):C100)))}
[junit4] 2> 1520308 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1520309 INFO (qtp413648926-16073) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 45
[junit4] 2> 1520310 INFO (qtp413648926-16070) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/select params={q=*:*&_stateVer_=cdcr-source:3&wt=javabin&version=2} hits=1000 status=0 QTime=0
[junit4] 2> 1520312 INFO (qtp413648926-16066) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/get params={qt=/get&_stateVer_=cdcr-source:3&getVersions=1000&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1520327 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 0x15e3365b4880008, 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.lang.Thread.run(Thread.java:748)
[junit4] 2> 1520329 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@6bf9c52{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 1520330 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1485398529
[junit4] 2> 1520330 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 1520330 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
[junit4] 2> 1520330 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 1520331 INFO (coreCloseExecutor-7768-thread-1) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@5b9377ee
[junit4] 2> 1520345 INFO (coreCloseExecutor-7768-thread-1) [n:127.0.0.1:52115_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.cdcr-source.shard1.replica1
[junit4] 2> 1520346 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.Overseer Overseer (id=98572753762254851-127.0.0.1:52115_solr-n_0000000000) closing
[junit4] 2> 1520347 INFO (OverseerStateUpdate-98572753762254851-127.0.0.1:52115_solr-n_0000000000) [n:127.0.0.1:52115_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:52115_solr
[junit4] 2> 1520350 WARN (zkCallback-2583-thread-2-processing-n:127.0.0.1:52115_solr) [n:127.0.0.1:52115_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1520351 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@55bde311{/solr,null,UNAVAILABLE}
[junit4] 2> 1520351 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 0x15e3365b4880003, 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.lang.Thread.run(Thread.java:748)
[junit4] 2> 1520351 INFO (zkCallback-2590-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 1520354 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1520355 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@68d73fd{/solr,null,AVAILABLE}
[junit4] 2> 1520356 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@64fcf762{SSL,[ssl, http/1.1]}{127.0.0.1:52177}
[junit4] 2> 1520356 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.e.j.s.Server Started @1523069ms
[junit4] 2> 1520356 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52177}
[junit4] 2> 1520357 ERROR (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1520357 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.1
[junit4] 2> 1520357 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1520357 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1520357 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-30T13:47:40.088Z
[junit4] 2> 1520361 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1520371 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1520371 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52111/solr
[junit4] 2> 1520384 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [n:127.0.0.1:52177_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1520384 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [n:127.0.0.1:52177_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:52177_solr
[junit4] 2> 1520385 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [n:127.0.0.1:52177_solr ] o.a.s.c.Overseer Overseer (id=98572753762254859-127.0.0.1:52177_solr-n_0000000001) starting
[junit4] 2> 1520390 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [n:127.0.0.1:52177_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52177_solr
[junit4] 2> 1520397 INFO (zkCallback-2590-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1520397 INFO (zkCallback-2596-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1520466 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [n:127.0.0.1:52177_solr ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_C27621E866A5063B-001\cdcr-source-001\node1\.
[junit4] 2> 1520466 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [n:127.0.0.1:52177_solr ] o.a.s.c.CorePropertiesLocator Cores are: [cdcr-source_shard1_replica1]
[junit4] 2> 1520467 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1520571 INFO (zkCallback-2596-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1521483 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 1521486 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 1521490 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.IndexSchema [cdcr-source_shard1_replica1] Schema name=minimal
[junit4] 2> 1521507 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1521509 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/cdcr-source/managed-schema
[junit4] 2> 1521512 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/cdcr-source/schema.xml to /configs/cdcr-source/schema.xml.bak
[junit4] 2> 1521512 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'cdcr-source_shard1_replica1' using configuration from collection cdcr-source, trusted=true
[junit4] 2> 1521512 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1521512 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [[cdcr-source_shard1_replica1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_C27621E866A5063B-001\cdcr-source-001\node1\cdcr-source_shard1_replica1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_C27621E866A5063B-001\cdcr-source-001\node1\.\cdcr-source_shard1_replica1\data\]
[junit4] 2> 1521637 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 1521637 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1521642 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1521642 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1521673 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@40a24da[cdcr-source_shard1_replica1] main]
[junit4] 2> 1521674 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cdcr-source
[junit4] 2> 1521674 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/cdcr-source
[junit4] 2> 1521674 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/cdcr-source/managed-schema
[junit4] 2> 1521675 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 1521675 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1521678 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.h.CdcrBufferStateManager Created znode /collections/cdcr-source/cdcr/state/buffer
[junit4] 2> 1521679 INFO (coreLoadExecutor-7777-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.h.CdcrProcessStateManager Created znode /collections/cdcr-source/cdcr/state/process
[junit4] 2> 1521687 INFO (searcherExecutor-7778-thread-1-processing-n:127.0.0.1:52177_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@40a24da[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(6.6.1):C1000)))}
[junit4] 2> 1521692 INFO (coreZkRegister-7770-thread-1-processing-n:127.0.0.1:52177_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 1521795 INFO (zkCallback-2596-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1521978 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: cdcr-source failOnTimeout:true timeout (sec):330
[junit4] 1> -
[junit4] 1> replica:core_node1 rstate:down live:false
[junit4] 1> replica:core_node2 rstate:down live:true
[junit4] 2> 1522698 WARN (cdcr-update-log-synchronizer-7783-thread-1) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.h.CdcrUpdateLogSynchronizer Couldn't get last processed version from leader https://127.0.0.1:52115/solr/cdcr-source_shard1_replica1/: Server refused connection at: https://127.0.0.1:52115/solr/cdcr-source_shard1_replica1
[junit4] 1> -
[junit4] 1> replica:core_node1 rstate:down live:false
[junit4] 1> replica:core_node2 rstate:down live:true
[junit4] 1> -
[junit4] 1> replica:core_node1 rstate:down live:false
[junit4] 1> replica:core_node2 rstate:down live:true
[junit4] 1> -
[junit4] 1> replica:core_node1 rstate:down live:false
[junit4] 1> replica:core_node2 rstate:down live:true
[junit4] 1> -
[junit4] 1> replica:core_node1 rstate:down live:false
[junit4] 1> replica:core_node2 rstate:down live:true
[junit4] 1> -
[junit4] 1> replica:core_node1 rstate:down live:false
[junit4] 1> replica:core_node2 rstate:down live:true
[junit4] 1> -
[junit4] 1> replica:core_node1 rstate:down live:false
[junit4] 1> replica:core_node2 rstate:down live:true
[junit4] 1> -
[junit4] 1> replica:core_node1 rstate:down live:false
[junit4] 1> replica:core_node2 rstate:down live:true
[junit4] 1> -
[junit4] 1> replica:core_node1 rstate:down live:false
[junit4] 1> replica:core_node2 rstate:down live:true
[junit4] 1> -
[junit4] 1> replica:core_node1 rstate:down live:false
[junit4] 1> replica:core_node2 rstate:down live:true
[junit4] 2> 1531706 INFO (coreZkRegister-7770-thread-1-processing-n:127.0.0.1:52177_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Was waiting for replicas to come up, but they are taking too long - assuming they won't come back till later
[junit4] 2> 1531706 INFO (coreZkRegister-7770-thread-1-processing-n:127.0.0.1:52177_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1531706 INFO (coreZkRegister-7770-thread-1-processing-n:127.0.0.1:52177_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:52177/solr/cdcr-source_shard1_replica1/
[junit4] 2> 1531706 INFO (coreZkRegister-7770-thread-1-processing-n:127.0.0.1:52177_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1531706 INFO (coreZkRegister-7770-thread-1-processing-n:127.0.0.1:52177_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.c.SyncStrategy https://127.0.0.1:52177/solr/cdcr-source_shard1_replica1/ has no replicas
[junit4] 2> 1531708 INFO (zkCallback-2596-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr ] o.a.s.h.CdcrLeaderStateManager Received new leader state @ cdcr-source:shard1
[junit4] 2> 1531709 INFO (coreZkRegister-7770-thread-1-processing-n:127.0.0.1:52177_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:52177/solr/cdcr-source_shard1_replica1/ shard1
[junit4] 2> 1531712 INFO (zkCallback-2596-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1531761 INFO (coreZkRegister-7770-thread-1-processing-n:127.0.0.1:52177_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1531866 INFO (zkCallback-2596-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1])
[junit4] 1> -
[junit4] 1> replica:core_node1 rstate:down live:false
[junit4] 1> replica:core_node2 rstate:active live:true
[junit4] 1> no one is recoverying
[junit4] 2> 1531993 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.AbstractDistribZkTestBase Recoveries finished - collection: cdcr-source
[junit4] 2> 1531994 ERROR (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.s.i.CloudSolrClient Request to collection cdcr-source failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry? 0
[junit4] 2> 1531994 WARN (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) cdcr-source after stale state error from server.
[junit4] 2> 1532019 INFO (qtp445889117-16126) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/select params={q=*:*&_stateVer_=cdcr-source:8&wt=javabin&version=2} hits=1000 status=0 QTime=0
[junit4] 2> 1532026 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 0x15e3365b3700006, 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.lang.Thread.run(Thread.java:748)
[junit4] 2> 1532030 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1532031 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[C27621E866A5063B]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:52087/solr ready
[junit4] 2> 1532059 INFO (qtp377469771-16027) [n:127.0.0.1:52091_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=cdcr-target&name=cdcr-target&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1532062 INFO (OverseerThreadFactory-7752-thread-1-processing-n:127.0.0.1:52091_solr) [n:127.0.0.1:52091_solr ] o.a.s.c.CreateCollectionCmd Create collection cdcr-target
[junit4] 2> 1532175 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=cdcr-target&newCollection=true&name=cdcr-target_shard1_replica1&action=CREATE&numShards=1&collection=cdcr-target&shard=shard1&wt=javabin&version=2
[junit4] 2> 1532177 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1532290 INFO (zkCallback-2571-thread-1-processing-n:127.0.0.1:52091_solr) [n:127.0.0.1:52091_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-target/state.json] for collection [cdcr-target] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1533200 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 1533204 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 1533206 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.s.IndexSchema [cdcr-target_shard1_replica1] Schema name=minimal
[junit4] 2> 1533207 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1533207 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/cdcr-target/managed-schema
[junit4] 2> 1533213 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/cdcr-target/schema.xml to /configs/cdcr-target/schema.xml.bak
[junit4] 2> 1533213 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'cdcr-target_shard1_replica1' using configuration from collection cdcr-target, trusted=true
[junit4] 2> 1533214 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1533214 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.c.SolrCore [[cdcr-target_shard1_replica1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_C27621E866A5063B-001\cdcr-target-001\node1\cdcr-target_shard1_replica1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_C27621E866A5063B-001\cdcr-target-001\node1\.\cdcr-target_shard1_replica1\data\]
[junit4] 2> 1533293 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 1533294 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1533295 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1533295 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1533296 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2e9e2439[cdcr-target_shard1_replica1] main]
[junit4] 2> 1533297 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cdcr-target
[junit4] 2> 1533297 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/cdcr-target
[junit4] 2> 1533297 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/cdcr-target/managed-schema
[junit4] 2> 1533298 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 1533298 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1533300 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.h.CdcrBufferStateManager Created znode /collections/cdcr-target/cdcr/state/buffer
[junit4] 2> 1533301 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.h.CdcrProcessStateManager Created znode /collections/cdcr-target/cdcr/state/process
[junit4] 2> 1533302 INFO (searcherExecutor-7784-thread-1-processing-n:127.0.0.1:52091_solr x:cdcr-target_shard1_replica1 s:shard1 c:cdcr-target) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.c.SolrCore [cdcr-target_shard1_replica1] Registered new searcher Searcher@2e9e2439[cdcr-target_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1533302 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577164077041451008
[junit4] 2> 1533307 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1533307 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1533307 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:52091/solr/cdcr-target_shard1_replica1/
[junit4] 2> 1533307 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1533307 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.c.SyncStrategy https://127.0.0.1:52091/solr/cdcr-target_shard1_replica1/ has no replicas
[junit4] 2> 1533307 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 1533310 INFO (zkCallback-2571-thread-1-processing-n:127.0.0.1:52091_solr) [n:127.0.0.1:52091_solr ] o.a.s.h.CdcrLeaderStateManager Received new leader state @ cdcr-target:shard1
[junit4] 2> 1533312 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:52091/solr/cdcr-target_shard1_replica1/ shard1
[junit4] 2> 1533415 INFO (zkCallback-2571-thread-1-processing-n:127.0.0.1:52091_solr) [n:127.0.0.1:52091_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-target/state.json] for collection [cdcr-target] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1533464 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1533465 INFO (qtp377469771-16028) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 x:cdcr-target_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=cdcr-target&newCollection=true&name=cdcr-target_shard1_replica1&action=CREATE&numShards=1&collection=cdcr-target&shard=shard1&wt=javabin&version=2} status=0 QTime=1289
[junit4] 2> 1533467 INFO (qtp377469771-16027) [n:127.0.0.1:52091_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 1533568 INFO (zkCallback-2571-thread-1-processing-n:127.0.0.1:52091_solr) [n:127.0.0.1:52091_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-target/state.json] for collection [cdcr-target] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1534065 INFO (OverseerCollectionConfigSetProcessor-98572753743904771-127.0.0.1:52091_solr-n_0000000000) [n:127.0.0.1:52091_solr ] 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> 1534467 INFO (qtp377469771-16027) [n:127.0.0.1:52091_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=cdcr-target&name=cdcr-target&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=2407
[junit4] 2> 1535471 INFO (zkCallback-2571-thread-1-processing-n:127.0.0.1:52091_solr) [n:127.0.0.1:52091_solr ] o.a.s.h.CdcrProcessStateManager The CDCR process state has changed: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-target/cdcr/state/process @ cdcr-target:shard1
[junit4] 2> 1535471 INFO (qtp377469771-16029) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica1] o.a.s.c.S.Request [cdcr-target_shard1_replica1] webapp=/solr path=/cdcr params={qt=/cdcr&_stateVer_=cdcr-target:3&action=start&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 1535471 INFO (zkCallback-2571-thread-1-processing-n:127.0.0.1:52091_solr) [n:127.0.0.1:52091_solr ] o.a.s.h.CdcrProcessStateManager Received new CDCR process state from watcher: STARTED @ cdcr-target:shard1
[junit4] 2> 1535476 INFO (qtp445889117-16126) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1535477 INFO (qtp445889117-16126) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:52087/solr ready
[junit4] 2> 1535498 INFO (qtp377469771-16027) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica1] o.a.s.h.CdcrRequestHandler Found maxVersionFromRecent 0 maxVersionFromIndex 0
[junit4] 2> 1535498 INFO (qtp377469771-16027) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica1] o.a.s.c.S.Request [cdcr-target_shard1_replica1] webapp=/solr path=/cdcr params={action=SHARDCHECKPOINT&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 1535498 INFO (qtp377469771-16033) [n:127.0.0.1:52091_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica1] o.a.s.c.S.Request [cdcr-target_shard1_replica1] webapp=/solr path=/cdcr params={_stateVer_=cdcr-target:3&action=COLLECTIONCHECKPOINT&wt=javabin&version=2} status=0 QTime=8
[junit4] 2> 1535498 INFO (qtp445889117-16126) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.h.CdcrReplicatorManager Create new update log reader for target cdcr-target with checkpoint -1 @ cdcr-source:shard1
[junit4] 2> 1535498 INFO (qtp445889117-16126) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.h.CdcrReplicatorManager Attempting to bootstrap target collection: cdcr-target, shard: shard1
[junit4] 2> 1535498 INFO (qtp445889117-16126) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.h.CdcrReplicatorManager Submitting bootstrap task to executor
[junit4] 2> 1535500 INFO (zkCallback-2596-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr ] o.a.s.h.CdcrProcessStateManager The CDCR process state has changed: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/cdcr/state/process @ cdcr-source:shard1
[junit4] 2> 1535500 INFO (qtp445889117-16126) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request [cdcr-source_shard1_replica1] webapp=/solr path=/cdcr params={qt=/cdcr&_stateVer_=cdcr-source:8&action=start&wt=javabin&version=2} status=0 QTime=27
[junit4] 2> 1535501 INFO (zkCallback-2596-thread-1-processing-n:127.0.0.1:52177_solr) [n:127.0.0.1:52177_solr ] o.a.s.h.CdcrProcessStateManager Received new CDCR process state from watcher: STARTED @ cdcr-source:shard1
[junit4] 2> 1535503 INFO (cdcr-bootstrap-status-2602-thread-1-processing-n:127.0.0.1:52177_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node2) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.h.CdcrReplicatorManager Attempting to bootstrap target collection: cdcr-target shard: shard1 leader: https://127.0.0.1:52091/solr/cdcr-target_shard1_replica1/
[junit4] 2> 1535504 INFO (qtp445889117-16120) [n:127.0.0.1:52177_solr c:cdcr-source s:shard1 r:core_node2 x:cdcr-source_shard1_replica1] o.a.s.c.S.Request
[...truncated too long message...]
O (jetty-closer-2640-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 1677649 INFO (coreCloseExecutor-7903-thread-1) [n:127.0.0.1:52921_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica1] o.a.s.c.SolrCore [cdcr-target_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@3a0190b6
[junit4] 2> 1677650 INFO (coreCloseExecutor-7903-thread-1) [n:127.0.0.1:52921_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica1] o.a.s.h.CdcrRequestHandler Solr core is being closed - shutting down CDCR handler @ cdcr-target:shard1
[junit4] 2> 1677650 INFO (coreCloseExecutor-7903-thread-1) [n:127.0.0.1:52921_solr c:cdcr-target s:shard1 r:core_node1 x:cdcr-target_shard1_replica1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.cdcr-target.shard1.replica1
[junit4] 2> 1677652 INFO (zkCallback-2646-thread-2-processing-n:127.0.0.1:52921_solr) [n:127.0.0.1:52921_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-target/state.json] for collection [cdcr-target] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1677653 INFO (jetty-closer-2640-thread-1) [ ] o.a.s.c.Overseer Overseer (id=98572763604647939-127.0.0.1:52921_solr-n_0000000000) closing
[junit4] 2> 1677653 INFO (OverseerStateUpdate-98572763604647939-127.0.0.1:52921_solr-n_0000000000) [n:127.0.0.1:52921_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:52921_solr
[junit4] 2> 1677656 INFO (jetty-closer-2640-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2db15c45{/solr,null,UNAVAILABLE}
[junit4] 2> 1677657 ERROR (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[C27621E866A5063B]) [ ] 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> 1677657 INFO (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[C27621E866A5063B]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:52917 52917
[junit4] 2> 1677658 INFO (Thread-4281) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:52917 52917
[junit4] 2> 1677658 WARN (Thread-4281) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/configs/cdcr-target/managed-schema
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 3 /solr/collections/cdcr-target/leaders/shard1/leader
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 4 /solr/collections/cdcr-target/cdcr/state/process
[junit4] 2> 3 /solr/collections/cdcr-target/cdcr/state/buffer
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2> 3 /solr/clusterprops.json
[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> 1677658 INFO (TEST-CdcrBootstrapTest.testBootstrapWithSourceCluster-seed#[C27621E866A5063B]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testBootstrapWithSourceCluster
[junit4] 2> 1677660 INFO (SUITE-CdcrBootstrapTest-seed#[C27621E866A5063B]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_C27621E866A5063B-001
[junit4] 2> Aug 30, 2017 1:50:17 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 6 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62): {_version_=Lucene50(blocksize=128), xyz=PostingsFormat(name=LuceneVarGapDocFreqInterval), id=PostingsFormat(name=Memory doPackFST= true)}, docValues:{}, maxPointsInLeafNode=1740, maxMBSortInHeap=5.518753168901797, sim=RandomSimilarity(queryNorm=true,coord=crazy): {}, locale=ca-ES, timezone=Pacific/Kwajalein
[junit4] 2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=3,threads=1,free=160179272,total=454139904
[junit4] 2> NOTE: All tests run in this JVM: [TestLockTree, DocumentBuilderTest, StandardRequestHandlerTest, TestCustomStream, TestDefaultStatsCache, XmlUpdateRequestHandlerTest, VersionInfoTest, TestDynamicFieldResource, TestConfigsApi, TestCSVLoader, SchemaVersionSpecificBehaviorTest, ClassificationUpdateProcessorFactoryTest, TestRemoteStreaming, TestDocumentBuilder, TestDistributedSearch, UnloadDistributedZkTest, SubstringBytesRefFilterTest, TestTolerantSearch, LeaderElectionTest, SolrMetricReporterTest, TestSolrConfigHandlerConcurrent, TestConfigSetsAPIExclusivity, TestSearcherReuse, TestJettySolrRunner, TermsComponentTest, DistributedSuggestComponentTest, TestRandomDVFaceting, FastVectorHighlighterTest, DistributedDebugComponentTest, TestStressReorder, CloudMLTQParserTest, RequestLoggingTest, PrimUtilsTest, CollectionStateFormat2Test, DistributedQueryComponentCustomSortTest, OverseerStatusTest, ReplicationFactorTest, HardAutoCommitTest, SynonymTokenizerTest, TestPivotHelperCode, SolrTestCaseJ4Test, TestXIncludeConfig, TestSolrDynamicMBean, TestUseDocValuesAsStored, HighlighterTest, TestAuthenticationFramework, CdcrReplicationDistributedZkTest, TestHighFrequencyDictionaryFactory, TestSchemaResource, TestNestedDocsSort, TestLeaderInitiatedRecoveryThread, TestLRUStatsCache, OverriddenZkACLAndCredentialsProvidersTest, TestUniqueKeyFieldResource, TestIBSimilarityFactory, HttpSolrCallGetCoreTest, TestFastLRUCache, TestFieldResource, TestReplicationHandlerBackup, ConjunctionSolrSpellCheckerTest, TestScoreJoinQPScore, AddBlockUpdateTest, TestExactSharedStatsCache, SimpleFacetsTest, TestDistribDocBasedVersion, TestIntervalFaceting, SimpleCollectionCreateDeleteTest, TestFieldSortValues, TestSolrCoreParser, TestConfigReload, TestSolrCloudSnapshots, IndexBasedSpellCheckerTest, EnumFieldTest, QueryElevationComponentTest, PeerSyncWithIndexFingerprintCachingTest, HdfsDirectoryTest, TestBulkSchemaConcurrent, TestPerFieldSimilarityWithDefaultOverride, MultiTermTest, TestFieldCacheSort, TestExtendedDismaxParser, RollingRestartTest, PreAnalyzedFieldManagedSchemaCloudTest, TestRequestStatusCollectionAPI, TestPseudoReturnFields, TestSimpleTextCodec, TestManagedSynonymFilterFactory, TestSweetSpotSimilarityFactory, TestSolrJ, LeaderInitiatedRecoveryOnCommitTest, TestSQLHandlerNonCloud, TestJavabinTupleStreamParser, PathHierarchyTokenizerFactoryTest, TestStressLucene, TestRuleBasedAuthorizationPlugin, TestSubQueryTransformerDistrib, DeleteLastCustomShardedReplicaTest, TestSolrCloudWithKerberosAlt, TestApiFramework, TestManagedSchemaThreadSafety, TestRTGBase, SortSpecParsingTest, NodeMutatorTest, TestFaceting, TestSolrQueryParserDefaultOperatorResource, TestCharFilters, TestNumericTerms64, XsltUpdateRequestHandlerTest, SolrCoreTest, TestSchemaManager, DeleteReplicaTest, MigrateRouteKeyTest, TestCloudInspectUtil, CollectionsAPIAsyncDistributedZkTest, DocValuesMultiTest, TestUnifiedSolrHighlighter, DateFieldTest, SimplePostToolTest, TestImplicitCoreProperties, SolrJmxReporterCloudTest, ZkControllerTest, SolrPluginUtilsTest, RequiredFieldsTest, TestSurroundQueryParser, TestElisionMultitermQuery, TestLeaderElectionWithEmptyReplica, BasicDistributedZkTest, TestReplicationHandler, PeerSyncTest, SuggesterFSTTest, TestCustomDocTransformer, TestLazyCores, DistributedQueryElevationComponentTest, DocumentAnalysisRequestHandlerTest, TestCloudPivotFacet, ConfigureRecoveryStrategyTest, TestJsonFacets, TestMacros, TestCollationField, CoreAdminRequestStatusTest, TestClassicSimilarityFactory, HLLUtilTest, StatelessScriptUpdateProcessorFactoryTest, TestSort, DistributedQueueTest, BlockJoinFacetRandomTest, TestSchemaVersionResource, RemoteQueryErrorTest, TestSmileRequest, TestSubQueryTransformer, TestCryptoKeys, BadComponentTest, TestPhraseSuggestions, OpenExchangeRatesOrgProviderTest, MoveReplicaTest, TestRecoveryHdfs, ClassificationUpdateProcessorTest, SyncSliceTest, SoftAutoCommitTest, AnalysisAfterCoreReloadTest, HdfsRestartWhileUpdatingTest, BigEndianAscendingWordDeserializerTest, TestConfigSets, DirectUpdateHandlerTest, TestInitParams, SampleTest, SegmentsInfoRequestHandlerTest, TestFieldCacheVsDocValues, TestTolerantUpdateProcessorRandomCloud, TestGeoJSONResponseWriter, RulesTest, TestPostingsSolrHighlighter, TestAuthorizationFramework, TriLevelCompositeIdRoutingTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest, TestZkChroot, ZkCLITest, TestRecovery, DistributedSpellCheckComponentTest, TestRealTimeGet, TestStressVersions, DistributedTermsComponentTest, ConvertedLegacyTest, TestFunctionQuery, ShowFileRequestHandlerTest, CurrencyFieldXmlFileTest, SignatureUpdateProcessorFactoryTest, DocValuesTest, TestWordDelimiterFilterFactory, DefaultValueUpdateProcessorTest, DistanceFunctionTest, SolrInfoMBeanTest, DirectSolrSpellCheckerTest, PrimitiveFieldTypeTest, RequestHandlersTest, TestValueSourceCache, IndexSchemaRuntimeFieldTest, TestJmxIntegration, ReturnFieldsTest, JSONWriterTest, MBeansHandlerTest, TestAnalyzedSuggestions, TestPartialUpdateDeduplication, TestComponentsName, TestBinaryResponseWriter, TestLFUCache, TestDocSet, TestBinaryField, NumericFieldsTest, MinimalSchemaTest, OutputWriterTest, TestSolrCoreProperties, NotRequiredUniqueKeyTest, SpellPossibilityIteratorTest, EchoParamsTest, TestPerFieldSimilarity, TestLMDirichletSimilarityFactory, TestBM25SimilarityFactory, TestFastOutputStream, PluginInfoTest, ChaosMonkeyNothingIsSafeTest, TestHighlightDedupGrouping, ActionThrottleTest, CdcrBootstrapTest]
[junit4] Completed [502/713 (1!)] on J0 in 161.47s, 3 tests, 1 failure <<< FAILURES!
[...truncated 44228 lines...]