You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2020/05/24 10:02:43 UTC
[JENKINS] Lucene-Solr-8.x-Linux (32bit/jdk1.8.0_201) - Build # 3173
- Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Linux/3173/
Java: 32bit/jdk1.8.0_201 -server -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.client.solrj.io.stream.StreamDecoratorTest.testParallelTerminatingDaemonUpdateStream
Error Message:
Error from server at http://127.0.0.1:39177/solr: Underlying core creation failed while creating collection: parallelDestinationCollection1
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:39177/solr: Underlying core creation failed while creating collection: parallelDestinationCollection1
at __randomizedtesting.SeedInfo.seed([DF73F68A268EC4:F1BBAB9EDE4C41DA]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:663)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:265)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:248)
at org.apache.solr.client.solrj.impl.LBSolrClient.doRequest(LBSolrClient.java:368)
at org.apache.solr.client.solrj.impl.LBSolrClient.request(LBSolrClient.java:296)
at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.sendRequest(BaseCloudSolrClient.java:1147)
at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.requestWithRetryOnStaleState(BaseCloudSolrClient.java:910)
at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.request(BaseCloudSolrClient.java:842)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:211)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:228)
at org.apache.solr.client.solrj.io.stream.StreamDecoratorTest.testParallelTerminatingDaemonUpdateStream(StreamDecoratorTest.java:3044)
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:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
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:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
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 17623 lines...]
[junit4] Suite: org.apache.solr.client.solrj.io.stream.StreamDecoratorTest
[junit4] 2> 102663 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/server/solr/configsets/_default/conf'
[junit4] 2> 102663 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-solrj/test/J5/temp/solr.client.solrj.io.stream.StreamDecoratorTest_DF73F68A268EC4-001/data-dir-11-001
[junit4] 2> 102663 WARN (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=4 numCloses=4
[junit4] 2> 102663 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 102664 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None)
[junit4] 2> 102665 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 102665 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-solrj/test/J5/temp/solr.client.solrj.io.stream.StreamDecoratorTest_DF73F68A268EC4-001/tempDir-001
[junit4] 2> 102665 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 102665 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port: 0.0.0.0/0.0.0.0:0
[junit4] 2> 102666 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 102766 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port: 44143
[junit4] 2> 102766 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:44143
[junit4] 2> 102766 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:44143
[junit4] 2> 102766 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 44143
[junit4] 2> 102767 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 102775 INFO (zkConnectionManagerCallback-2119-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 102775 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 102781 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 102782 INFO (zkConnectionManagerCallback-2121-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 102782 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 102784 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 102789 INFO (zkConnectionManagerCallback-2123-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 102789 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 102900 WARN (jetty-launcher-2124-thread-1) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 102900 INFO (jetty-launcher-2124-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 102900 INFO (jetty-launcher-2124-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 102900 INFO (jetty-launcher-2124-thread-1) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 1.8.0_201-b09
[junit4] 2> 102901 WARN (jetty-launcher-2124-thread-2) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 102901 INFO (jetty-launcher-2124-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 102901 INFO (jetty-launcher-2124-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 102901 WARN (jetty-launcher-2124-thread-3) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 102901 INFO (jetty-launcher-2124-thread-2) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 1.8.0_201-b09
[junit4] 2> 102901 INFO (jetty-launcher-2124-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 102901 INFO (jetty-launcher-2124-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 102901 WARN (jetty-launcher-2124-thread-4) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 102901 INFO (jetty-launcher-2124-thread-3) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 1.8.0_201-b09
[junit4] 2> 102901 INFO (jetty-launcher-2124-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 102901 INFO (jetty-launcher-2124-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 102901 INFO (jetty-launcher-2124-thread-4) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 1.8.0_201-b09
[junit4] 2> 102908 INFO (jetty-launcher-2124-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 102908 INFO (jetty-launcher-2124-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 102908 INFO (jetty-launcher-2124-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 102908 INFO (jetty-launcher-2124-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 102908 INFO (jetty-launcher-2124-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 102908 INFO (jetty-launcher-2124-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 102909 INFO (jetty-launcher-2124-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@d05772{/solr,null,AVAILABLE}
[junit4] 2> 102913 INFO (jetty-launcher-2124-thread-4) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 102913 INFO (jetty-launcher-2124-thread-4) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 102913 INFO (jetty-launcher-2124-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@270d65{/solr,null,AVAILABLE}
[junit4] 2> 102913 INFO (jetty-launcher-2124-thread-4) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 102918 INFO (jetty-launcher-2124-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 102918 INFO (jetty-launcher-2124-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 102918 INFO (jetty-launcher-2124-thread-3) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 102918 INFO (jetty-launcher-2124-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@23f925{/solr,null,AVAILABLE}
[junit4] 2> 102918 INFO (jetty-launcher-2124-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@193dc94{/solr,null,AVAILABLE}
[junit4] 2> 102918 INFO (jetty-launcher-2124-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@82312b{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:44821}
[junit4] 2> 102918 INFO (jetty-launcher-2124-thread-1) [ ] o.e.j.s.Server Started @102955ms
[junit4] 2> 102918 INFO (jetty-launcher-2124-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44821}
[junit4] 2> 102918 ERROR (jetty-launcher-2124-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 102919 INFO (jetty-launcher-2124-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 102919 INFO (jetty-launcher-2124-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.6.0
[junit4] 2> 102919 INFO (jetty-launcher-2124-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 102919 INFO (jetty-launcher-2124-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr
[junit4] 2> 102919 INFO (jetty-launcher-2124-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T09:54:10.080Z
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@cd8ad6{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:33893}
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-2) [ ] o.e.j.s.Server Started @102957ms
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=33893}
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1be1ac5{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:39713}
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-4) [ ] o.e.j.s.Server Started @102957ms
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39713}
[junit4] 2> 102920 ERROR (jetty-launcher-2124-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.6.0
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr
[junit4] 2> 102920 ERROR (jetty-launcher-2124-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-4) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T09:54:10.081Z
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.6.0
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T09:54:10.081Z
[junit4] 2> 102920 INFO (jetty-launcher-2124-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 102921 INFO (jetty-launcher-2124-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@deddd7{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:39177}
[junit4] 2> 102921 INFO (jetty-launcher-2124-thread-3) [ ] o.e.j.s.Server Started @102958ms
[junit4] 2> 102921 INFO (jetty-launcher-2124-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39177}
[junit4] 2> 102921 ERROR (jetty-launcher-2124-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 102921 INFO (jetty-launcher-2124-thread-3) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 102921 INFO (jetty-launcher-2124-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.6.0
[junit4] 2> 102921 INFO (jetty-launcher-2124-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 102921 INFO (jetty-launcher-2124-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr
[junit4] 2> 102921 INFO (jetty-launcher-2124-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T09:54:10.082Z
[junit4] 2> 102922 INFO (jetty-launcher-2124-thread-4) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 102923 INFO (jetty-launcher-2124-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 102923 INFO (jetty-launcher-2124-thread-3) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 102923 INFO (zkConnectionManagerCallback-2126-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 102923 INFO (jetty-launcher-2124-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 102923 INFO (zkConnectionManagerCallback-2128-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 102923 INFO (jetty-launcher-2124-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 102924 INFO (jetty-launcher-2124-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 102925 INFO (zkConnectionManagerCallback-2130-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 102925 INFO (jetty-launcher-2124-thread-4) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 102925 INFO (zkConnectionManagerCallback-2132-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 102925 INFO (jetty-launcher-2124-thread-3) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 102925 INFO (jetty-launcher-2124-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 102925 INFO (jetty-launcher-2124-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 102925 INFO (jetty-launcher-2124-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 103363 INFO (jetty-launcher-2124-thread-4) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 103365 WARN (jetty-launcher-2124-thread-4) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@e1ee05[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 103365 WARN (jetty-launcher-2124-thread-4) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@e1ee05[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 103389 WARN (jetty-launcher-2124-thread-4) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@12d4c79[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 103389 WARN (jetty-launcher-2124-thread-4) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@12d4c79[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 103390 INFO (jetty-launcher-2124-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44143/solr
[junit4] 2> 103400 INFO (jetty-launcher-2124-thread-4) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 103409 INFO (zkConnectionManagerCallback-2152-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 103409 INFO (jetty-launcher-2124-thread-4) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 103520 INFO (jetty-launcher-2124-thread-4) [n:127.0.0.1:39713_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 103524 INFO (zkConnectionManagerCallback-2154-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 103524 INFO (jetty-launcher-2124-thread-4) [n:127.0.0.1:39713_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 103563 INFO (jetty-launcher-2124-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 103584 WARN (jetty-launcher-2124-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@9d0ce4[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 103584 WARN (jetty-launcher-2124-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@9d0ce4[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 103609 WARN (jetty-launcher-2124-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@175e292[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 103609 WARN (jetty-launcher-2124-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@175e292[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 103610 INFO (jetty-launcher-2124-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44143/solr
[junit4] 2> 103617 INFO (jetty-launcher-2124-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 103643 INFO (jetty-launcher-2124-thread-4) [n:127.0.0.1:39713_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:39713_solr
[junit4] 2> 103643 INFO (jetty-launcher-2124-thread-4) [n:127.0.0.1:39713_solr ] o.a.s.c.Overseer Overseer (id=72097604903698440-127.0.0.1:39713_solr-n_0000000000) starting
[junit4] 2> 103647 INFO (zkConnectionManagerCallback-2164-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 103647 INFO (jetty-launcher-2124-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 103655 INFO (OverseerStateUpdate-72097604903698440-127.0.0.1:39713_solr-n_0000000000) [n:127.0.0.1:39713_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:39713_solr
[junit4] 2> 103656 INFO (jetty-launcher-2124-thread-4) [n:127.0.0.1:39713_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39713_solr
[junit4] 2> 103665 INFO (OverseerStateUpdate-72097604903698440-127.0.0.1:39713_solr-n_0000000000) [n:127.0.0.1:39713_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 103667 INFO (jetty-launcher-2124-thread-4) [n:127.0.0.1:39713_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 103667 WARN (jetty-launcher-2124-thread-4) [n:127.0.0.1:39713_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 103672 INFO (jetty-launcher-2124-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 103675 WARN (jetty-launcher-2124-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@1366ea0[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 103675 WARN (jetty-launcher-2124-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@1366ea0[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 103700 INFO (jetty-launcher-2124-thread-4) [n:127.0.0.1:39713_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 103721 INFO (jetty-launcher-2124-thread-4) [n:127.0.0.1:39713_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39713.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1653ee0
[junit4] 2> 103737 WARN (jetty-launcher-2124-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@1be9d6b[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 103737 WARN (jetty-launcher-2124-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@1be9d6b[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 103738 INFO (jetty-launcher-2124-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44143/solr
[junit4] 2> 103738 INFO (jetty-launcher-2124-thread-4) [n:127.0.0.1:39713_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39713.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1653ee0
[junit4] 2> 103739 INFO (jetty-launcher-2124-thread-4) [n:127.0.0.1:39713_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39713.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1653ee0
[junit4] 2> 103740 INFO (jetty-launcher-2124-thread-4) [n:127.0.0.1:39713_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-solrj/test/J5/temp/solr.client.solrj.io.stream.StreamDecoratorTest_DF73F68A268EC4-001/tempDir-001/node4/.
[junit4] 2> 103751 INFO (jetty-launcher-2124-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 103751 INFO (zkConnectionManagerCallback-2181-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 103751 INFO (jetty-launcher-2124-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 103781 INFO (jetty-launcher-2124-thread-1) [n:127.0.0.1:44821_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 103800 INFO (zkConnectionManagerCallback-2184-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 103800 INFO (jetty-launcher-2124-thread-1) [n:127.0.0.1:44821_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 103803 INFO (jetty-launcher-2124-thread-1) [n:127.0.0.1:44821_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 103805 INFO (jetty-launcher-2124-thread-1) [n:127.0.0.1:44821_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:44821_solr as DOWN
[junit4] 2> 103805 INFO (jetty-launcher-2124-thread-1) [n:127.0.0.1:44821_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 103805 INFO (jetty-launcher-2124-thread-1) [n:127.0.0.1:44821_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44821_solr
[junit4] 2> 103807 INFO (jetty-launcher-2124-thread-1) [n:127.0.0.1:44821_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 103807 WARN (jetty-launcher-2124-thread-1) [n:127.0.0.1:44821_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 103813 INFO (zkCallback-2183-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 103813 INFO (zkCallback-2153-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 103823 INFO (jetty-launcher-2124-thread-1) [n:127.0.0.1:44821_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 103843 INFO (jetty-launcher-2124-thread-1) [n:127.0.0.1:44821_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44821.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1653ee0
[junit4] 2> 103859 INFO (jetty-launcher-2124-thread-1) [n:127.0.0.1:44821_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44821.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1653ee0
[junit4] 2> 103859 INFO (jetty-launcher-2124-thread-1) [n:127.0.0.1:44821_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44821.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1653ee0
[junit4] 2> 103860 INFO (jetty-launcher-2124-thread-1) [n:127.0.0.1:44821_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-solrj/test/J5/temp/solr.client.solrj.io.stream.StreamDecoratorTest_DF73F68A268EC4-001/tempDir-001/node1/.
[junit4] 2> 103872 INFO (jetty-launcher-2124-thread-2) [n:127.0.0.1:33893_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 103873 INFO (zkConnectionManagerCallback-2194-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 103873 INFO (jetty-launcher-2124-thread-2) [n:127.0.0.1:33893_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 103878 INFO (jetty-launcher-2124-thread-2) [n:127.0.0.1:33893_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 103880 INFO (jetty-launcher-2124-thread-2) [n:127.0.0.1:33893_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:33893_solr as DOWN
[junit4] 2> 103880 INFO (jetty-launcher-2124-thread-2) [n:127.0.0.1:33893_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 103880 INFO (jetty-launcher-2124-thread-2) [n:127.0.0.1:33893_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33893_solr
[junit4] 2> 103881 INFO (zkCallback-2193-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 103881 INFO (zkCallback-2183-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 103881 INFO (jetty-launcher-2124-thread-2) [n:127.0.0.1:33893_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 103881 WARN (jetty-launcher-2124-thread-2) [n:127.0.0.1:33893_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 103888 INFO (zkCallback-2153-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 103897 INFO (jetty-launcher-2124-thread-2) [n:127.0.0.1:33893_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 103912 INFO (jetty-launcher-2124-thread-2) [n:127.0.0.1:33893_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33893.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1653ee0
[junit4] 2> 103919 INFO (jetty-launcher-2124-thread-2) [n:127.0.0.1:33893_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33893.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1653ee0
[junit4] 2> 103919 INFO (jetty-launcher-2124-thread-2) [n:127.0.0.1:33893_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33893.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1653ee0
[junit4] 2> 103920 INFO (jetty-launcher-2124-thread-2) [n:127.0.0.1:33893_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-solrj/test/J5/temp/solr.client.solrj.io.stream.StreamDecoratorTest_DF73F68A268EC4-001/tempDir-001/node2/.
[junit4] 2> 104220 INFO (jetty-launcher-2124-thread-3) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 104220 WARN (jetty-launcher-2124-thread-3) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@19a6e27[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 104220 WARN (jetty-launcher-2124-thread-3) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@19a6e27[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 104225 WARN (jetty-launcher-2124-thread-3) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@183e64b[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 104225 WARN (jetty-launcher-2124-thread-3) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@183e64b[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 104225 INFO (jetty-launcher-2124-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44143/solr
[junit4] 2> 104230 INFO (jetty-launcher-2124-thread-3) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 104230 INFO (zkConnectionManagerCallback-2210-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 104230 INFO (jetty-launcher-2124-thread-3) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 104332 INFO (jetty-launcher-2124-thread-3) [n:127.0.0.1:39177_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 104333 INFO (zkConnectionManagerCallback-2212-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 104333 INFO (jetty-launcher-2124-thread-3) [n:127.0.0.1:39177_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 104334 INFO (jetty-launcher-2124-thread-3) [n:127.0.0.1:39177_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 104336 INFO (jetty-launcher-2124-thread-3) [n:127.0.0.1:39177_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:39177_solr as DOWN
[junit4] 2> 104336 INFO (jetty-launcher-2124-thread-3) [n:127.0.0.1:39177_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 104336 INFO (jetty-launcher-2124-thread-3) [n:127.0.0.1:39177_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39177_solr
[junit4] 2> 104336 INFO (zkCallback-2193-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 104336 INFO (zkCallback-2153-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 104336 INFO (zkCallback-2183-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 104336 INFO (zkCallback-2211-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 104337 INFO (jetty-launcher-2124-thread-3) [n:127.0.0.1:39177_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 104337 WARN (jetty-launcher-2124-thread-3) [n:127.0.0.1:39177_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 104349 INFO (jetty-launcher-2124-thread-3) [n:127.0.0.1:39177_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 104361 INFO (jetty-launcher-2124-thread-3) [n:127.0.0.1:39177_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39177.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1653ee0
[junit4] 2> 104367 INFO (jetty-launcher-2124-thread-3) [n:127.0.0.1:39177_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39177.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1653ee0
[junit4] 2> 104367 INFO (jetty-launcher-2124-thread-3) [n:127.0.0.1:39177_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39177.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1653ee0
[junit4] 2> 104368 INFO (jetty-launcher-2124-thread-3) [n:127.0.0.1:39177_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-solrj/test/J5/temp/solr.client.solrj.io.stream.StreamDecoratorTest_DF73F68A268EC4-001/tempDir-001/node3/.
[junit4] 2> 104377 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=4
[junit4] 2> 104389 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 104396 INFO (zkConnectionManagerCallback-2225-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 104397 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 104401 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 104402 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44143/solr ready
[junit4] 2> 104414 INFO (qtp1648484-4208) [n:127.0.0.1:39177_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf&name=collection1&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 104416 INFO (OverseerThreadFactory-2169-thread-1-processing-n:127.0.0.1:39713_solr) [n:127.0.0.1:39713_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection collection1
[junit4] 2> 104521 INFO (qtp1648484-4212) [n:127.0.0.1:39177_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 104523 INFO (qtp686759-4213) [n:127.0.0.1:33893_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 104524 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 104524 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 104527 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 104529 INFO (qtp1648484-4212) [n:127.0.0.1:39177_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 104530 INFO (qtp686759-4213) [n:127.0.0.1:33893_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 104531 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 104532 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 104536 INFO (OverseerStateUpdate-72097604903698440-127.0.0.1:39713_solr-n_0000000000) [n:127.0.0.1:39713_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"collection1_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:44821/solr",
[junit4] 2> "node_name":"127.0.0.1:44821_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 104536 INFO (OverseerStateUpdate-72097604903698440-127.0.0.1:39713_solr-n_0000000000) [n:127.0.0.1:39713_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"collection1_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:39713/solr",
[junit4] 2> "node_name":"127.0.0.1:39713_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 104738 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr x:collection1_shard2_replica_n2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=collection1_shard2_replica_n2&action=CREATE&numShards=2&collection=collection1&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 104738 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr x:collection1_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=collection1_shard1_replica_n1&action=CREATE&numShards=2&collection=collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 104747 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.6.0
[junit4] 2> 104747 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.6.0
[junit4] 2> 104754 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.s.IndexSchema Schema name=test
[junit4] 2> 104755 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.s.IndexSchema Schema name=test
[junit4] 2> 104806 WARN (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.s.IndexSchema Field lowerfilt1and2 is not multivalued and destination for multiople copyFields (2)
[junit4] 2> 104806 WARN (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.s.IndexSchema Field text is not multivalued and destination for multiople copyFields (3)
[junit4] 2> 104806 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 104806 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard2_replica_n2' using configuration from configset conf, trusted=true
[junit4] 2> 104806 WARN (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.s.IndexSchema Field lowerfilt1and2 is not multivalued and destination for multiople copyFields (2)
[junit4] 2> 104806 WARN (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.s.IndexSchema Field text is not multivalued and destination for multiople copyFields (3)
[junit4] 2> 104806 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 104806 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard1_replica_n1' using configuration from configset conf, trusted=true
[junit4] 2> 104806 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39713.solr.core.collection1.shard2.replica_n2' (registry 'solr.core.collection1.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1653ee0
[junit4] 2> 104806 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44821.solr.core.collection1.shard1.replica_n1' (registry 'solr.core.collection1.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1653ee0
[junit4] 2> 104806 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.SolrCore [[collection1_shard2_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-solrj/test/J5/temp/solr.client.solrj.io.stream.StreamDecoratorTest_DF73F68A268EC4-001/tempDir-001/node4/./collection1_shard2_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-solrj/test/J5/temp/solr.client.solrj.io.stream.StreamDecoratorTest_DF73F68A268EC4-001/tempDir-001/node4/./collection1_shard2_replica_n2/data/]
[junit4] 2> 104806 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.SolrCore [[collection1_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-solrj/test/J5/temp/solr.client.solrj.io.stream.StreamDecoratorTest_DF73F68A268EC4-001/tempDir-001/node1/./collection1_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-solrj/test/J5/temp/solr.client.solrj.io.stream.StreamDecoratorTest_DF73F68A268EC4-001/tempDir-001/node1/./collection1_shard1_replica_n1/data/]
[junit4] 2> 104840 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 104840 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 104841 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 104841 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 104842 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 104842 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 104843 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 104843 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 104843 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 104843 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 104843 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
[junit4] 2> 104843 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1667565147394146304
[junit4] 2> 104846 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 104846 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 104846 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
[junit4] 2> 104846 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1667565147397292032
[junit4] 2> 104847 INFO (searcherExecutor-2229-thread-1-processing-n:127.0.0.1:44821_solr x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node3) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.SolrCore [collection1_shard1_replica_n1] Registered new searcher autowarm time: 0 ms: Collection: 'collection1'
[junit4] 2> 104848 INFO (searcherExecutor-2227-thread-1-processing-n:127.0.0.1:39713_solr x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.SolrCore [collection1_shard2_replica_n2] Registered new searcher autowarm time: 0 ms: Collection: 'collection1'
[junit4] 2> 104849 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection1/terms/shard1 to Terms{values={core_node3=0}, version=0}
[junit4] 2> 104849 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/collection1/leaders/shard1
[junit4] 2> 104849 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection1/terms/shard2 to Terms{values={core_node4=0}, version=0}
[junit4] 2> 104849 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/collection1/leaders/shard2
[junit4] 2> 104850 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 104850 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 104850 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:44821/solr/collection1_shard1_replica_n1/
[junit4] 2> 104850 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 104850 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.SyncStrategy http://127.0.0.1:44821/solr/collection1_shard1_replica_n1/ has no replicas
[junit4] 2> 104850 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 104850 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 104850 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:39713/solr/collection1_shard2_replica_n2/
[junit4] 2> 104850 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1/leaders/shard1/leader after winning as /collections/collection1/leader_elect/shard1/election/72097604903698443-core_node3-n_0000000000
[junit4] 2> 104850 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 104851 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.SyncStrategy http://127.0.0.1:39713/solr/collection1_shard2_replica_n2/ has no replicas
[junit4] 2> 104851 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1/leaders/shard2/leader after winning as /collections/collection1/leader_elect/shard2/election/72097604903698440-core_node4-n_0000000000
[junit4] 2> 104851 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:44821/solr/collection1_shard1_replica_n1/ shard1
[junit4] 2> 104851 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:39713/solr/collection1_shard2_replica_n2/ shard2
[junit4] 2> 104952 INFO (zkCallback-2153-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 104952 INFO (zkCallback-2183-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 104952 INFO (zkCallback-2153-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 104952 INFO (zkCallback-2183-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 104953 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 104953 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 104954 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=collection1_shard1_replica_n1&action=CREATE&numShards=2&collection=collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=216
[junit4] 2> 104954 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=collection1_shard2_replica_n2&action=CREATE&numShards=2&collection=collection1&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=216
[junit4] 2> 104955 INFO (qtp1648484-4208) [n:127.0.0.1:39177_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 45 seconds. Check all shard replicas
[junit4] 2> 105057 INFO (zkCallback-2183-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 105057 INFO (zkCallback-2183-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 105057 INFO (zkCallback-2183-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 105057 INFO (zkCallback-2211-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 105057 INFO (zkCallback-2153-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 105057 INFO (zkCallback-2153-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 105057 INFO (qtp1648484-4208) [n:127.0.0.1:39177_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf&name=collection1&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=643
[junit4] 2> 105057 INFO (zkCallback-2153-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 105058 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForActiveCollection: collection1
[junit4] 2> 105063 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: collection1 failOnTimeout: true timeout (sec):
[junit4] 2> 105064 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.AbstractDistribZkTestBase Recoveries finished - collection: collection1
[junit4] 2> 105099 INFO (TEST-StreamDecoratorTest.testStream-seed#[DF73F68A268EC4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testStream
[junit4] 2> 105115 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection1/terms/shard2 to Terms{values={core_node4=1}, version=1}
[junit4] 2> 105115 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:44821/solr/collection1_shard1_replica_n1/&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 105119 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/update params={update.distrib=TOLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:44821/solr/collection1_shard1_replica_n1/&commit_end_point=leaders&wt=javabin&version=2&expungeDeletes=false} status=0 QTime=0
[junit4] 2> 105121 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection1/terms/shard1 to Terms{values={core_node3=1}, version=1}
[junit4] 2> 105121 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1:4&commit=true&wt=javabin&version=2} status=0 QTime=20
[junit4] 2> 105132 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=collection1:4&wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 105144 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=TOLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:39713/solr/collection1_shard2_replica_n2/&commit_end_point=leaders&wt=javabin&version=2&expungeDeletes=false} status=0 QTime=0
[junit4] 2> 105167 INFO (searcherExecutor-2227-thread-1-processing-n:127.0.0.1:39713_solr x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.SolrCore [collection1_shard2_replica_n2] Registered new searcher autowarm time: 0 ms: Collection: 'collection1'
[junit4] 2> 105169 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=collection1:4&commit=true&wt=javabin&version=2} status=0 QTime=35
[junit4] 2> 105172 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/stream params={indent=off&expr=let(a+%3Dsearch(collection1,+q%3D"id:hello1",+fl%3D"id,test_t,+test_i",+sort%3D"id+desc"),stream(a))&wt=json&version=2.2} status=0 QTime=1
[junit4] 2> 105173 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 105174 INFO (zkConnectionManagerCallback-2242-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 105174 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 105177 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 105177 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44143/solr ready
[junit4] 2> 105190 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=collection1:4&fl=id&shards.purpose=4&start=0&fsv=true&sort=id+desc&shard.url=http://127.0.0.1:44821/solr/collection1_shard1_replica_n1/&rows=10&version=2&q=id:hello1&omitHeader=false&NOW=1590314052339&isShard=true&wt=javabin} hits=0 status=0 QTime=1
[junit4] 2> 105192 INFO (qtp24768602-4253) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=collection1:4&fl=id&shards.purpose=4&start=0&fsv=true&sort=id+desc&shard.url=http://127.0.0.1:39713/solr/collection1_shard2_replica_n2/&rows=10&version=2&q=id:hello1&omitHeader=false&NOW=1590314052339&isShard=true&wt=javabin} hits=1 status=0 QTime=1
[junit4] 2> 105198 INFO (qtp24768602-4253) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=collection1:4&fl=id,test_t,+test_i&shards.purpose=64&shard.url=http://127.0.0.1:39713/solr/collection1_shard2_replica_n2/&version=2&q=id:hello1&omitHeader=false&NOW=1590314052339&ids=hello1&isShard=true&wt=javabin} status=0 QTime=0
[junit4] 2> 105199 INFO (qtp24768602-4247) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/select params={q=id:hello1&_stateVer_=collection1:4&fl=id,test_t,+test_i&sort=id+desc&wt=javabin&version=2} hits=1 status=0 QTime=21
[junit4] 2> 105200 INFO (TEST-StreamDecoratorTest.testStream-seed#[DF73F68A268EC4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testStream
[junit4] 2> 105237 INFO (TEST-StreamDecoratorTest.testParallelIntersectStream-seed#[DF73F68A268EC4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testParallelIntersectStream
[junit4] 2> 105240 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:39713/solr/collection1_shard2_replica_n2/&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 105243 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=TOLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:39713/solr/collection1_shard2_replica_n2/&commit_end_point=leaders&wt=javabin&version=2&expungeDeletes=false} status=0 QTime=0
[junit4] 2> 105246 INFO (searcherExecutor-2227-thread-1-processing-n:127.0.0.1:39713_solr x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.SolrCore [collection1_shard2_replica_n2] Registered new searcher autowarm time: 0 ms: Collection: 'collection1'
[junit4] 2> 105247 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=collection1:4&commit=true&wt=javabin&version=2} status=0 QTime=9
[junit4] 2> 105252 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1:4&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 105253 INFO (qtp24768602-4253) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=collection1:4&wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 105271 INFO (searcherExecutor-2229-thread-1-processing-n:127.0.0.1:44821_solr x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node3) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.SolrCore [collection1_shard1_replica_n1] Registered new searcher autowarm time: 0 ms: Collection: 'collection1'
[junit4] 2> 105272 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=TOLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:39713/solr/collection1_shard2_replica_n2/&commit_end_point=leaders&wt=javabin&version=2&expungeDeletes=false} status=0 QTime=13
[junit4] 2> 105282 INFO (searcherExecutor-2227-thread-1-processing-n:127.0.0.1:39713_solr x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.SolrCore [collection1_shard2_replica_n2] Registered new searcher autowarm time: 0 ms: Collection: 'collection1'
[junit4] 2> 105283 INFO (qtp24768602-4247) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=collection1:4&commit=true&wt=javabin&version=2} status=0 QTime=26
[junit4] 2> 105287 INFO (TEST-StreamDecoratorTest.testParallelIntersectStream-seed#[DF73F68A268EC4]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 105288 INFO (zkConnectionManagerCallback-2247-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 105288 INFO (TEST-StreamDecoratorTest.testParallelIntersectStream-seed#[DF73F68A268EC4]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 105289 INFO (TEST-StreamDecoratorTest.testParallelIntersectStream-seed#[DF73F68A268EC4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 105289 INFO (TEST-StreamDecoratorTest.testParallelIntersectStream-seed#[DF73F68A268EC4]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44143/solr ready
[junit4] 2> 105297 INFO (qtp24768602-4253) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/stream params={distrib=false&workerID=0&indent=off&numWorkers=2&expr=intersect(search(collection1,q%3D"a_s:(setA+||+setAB)",fl%3D"id,a_s,a_i",sort%3D"a_i+asc,+a_s+asc",partitionKeys%3Da_i,qt%3D"/export",zkHost%3D"127.0.0.1:44143/solr"),search(collection1,q%3D"a_s:(setB+||+setAB)",fl%3D"id,a_s,a_i",sort%3D"a_i+asc",partitionKeys%3Da_i,qt%3D"/export",zkHost%3D"127.0.0.1:44143/solr"),on%3Da_i)&wt=json&version=2.2} status=0 QTime=0
[junit4] 2> 105298 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/stream params={distrib=false&workerID=1&indent=off&numWorkers=2&expr=intersect(search(collection1,q%3D"a_s:(setA+||+setAB)",fl%3D"id,a_s,a_i",sort%3D"a_i+asc,+a_s+asc",partitionKeys%3Da_i,qt%3D"/export",zkHost%3D"127.0.0.1:44143/solr"),search(collection1,q%3D"a_s:(setB+||+setAB)",fl%3D"id,a_s,a_i",sort%3D"a_i+asc",partitionKeys%3Da_i,qt%3D"/export",zkHost%3D"127.0.0.1:44143/solr"),on%3Da_i)&wt=json&version=2.2} status=0 QTime=1
[junit4] 2> 105304 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 105312 INFO (zkConnectionManagerCallback-2254-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 105312 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 105313 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 105313 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44143/solr ready
[junit4] 2> 105317 INFO (qtp4578963-4268) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/export params={q=a_s:(setA+||+setAB)&distrib=false&indent=off&fl=id,a_s,a_i&sort=a_i+asc,+a_s+asc&partitionKeys=a_i&fq={!hash+workers%3D2+worker%3D0}&wt=json&version=2.2} hits=2 status=0 QTime=4
[junit4] 2> 105317 INFO (qtp24768602-4247) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/export params={q=a_s:(setA+||+setAB)&distrib=false&indent=off&fl=id,a_s,a_i&sort=a_i+asc,+a_s+asc&partitionKeys=a_i&fq={!hash+workers%3D2+worker%3D0}&wt=json&version=2.2} hits=2 status=0 QTime=15
[junit4] 2> 105322 INFO (qtp24768602-4247) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/export params={q=a_s:(setA+||+setAB)&distrib=false&indent=off&fl=id,a_s,a_i&sort=a_i+asc,+a_s+asc&partitionKeys=a_i&fq={!hash+workers%3D2+worker%3D1}&wt=json&version=2.2} hits=1 status=0 QTime=1
[junit4] 2> 105326 INFO (qtp4578963-4268) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/export params={q=a_s:(setA+||+setAB)&distrib=false&indent=off&fl=id,a_s,a_i&sort=a_i+asc,+a_s+asc&partitionKeys=a_i&fq={!hash+workers%3D2+worker%3D1}&wt=json&version=2.2} hits=1 status=0 QTime=1
[junit4] 2> 105326 INFO (qtp24768602-4247) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/export params={q=a_s:(setB+||+setAB)&distrib=false&indent=off&fl=id,a_s,a_i&sort=a_i+asc&partitionKeys=a_i&fq={!hash+workers%3D2+worker%3D0}&wt=json&version=2.2} hits=2 status=0 QTime=0
[junit4] 2> 105330 INFO (qtp4578963-4268) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/export params={q=a_s:(setB+||+setAB)&distrib=false&indent=off&fl=id,a_s,a_i&sort=a_i+asc&partitionKeys=a_i&fq={!hash+workers%3D2+worker%3D0}&wt=json&version=2.2} hits=1 status=0 QTime=1
[junit4] 2> 105335 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/export params={q=a_s:(setB+||+setAB)&distrib=false&indent=off&fl=id,a_s,a_i&sort=a_i+asc&partitionKeys=a_i&fq={!hash+workers%3D2+worker%3D1}&wt=json&version=2.2} hits=1 status=0 QTime=0
[junit4] 2> 105338 INFO (qtp4578963-4268) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/export params={q=a_s:(setB+||+setAB)&distrib=false&indent=off&fl=id,a_s,a_i&sort=a_i+asc&partitionKeys=a_i&fq={!hash+workers%3D2+worker%3D1}&wt=json&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 105439 INFO (TEST-StreamDecoratorTest.testParallelIntersectStream-seed#[DF73F68A268EC4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testParallelIntersectStream
[junit4] 2> 105494 INFO (TEST-StreamDecoratorTest.testParallelMergeStream-seed#[DF73F68A268EC4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testParallelMergeStream
[junit4] 2> 105502 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:44821/solr/collection1_shard1_replica_n1/&wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 105508 INFO (searcherExecutor-2227-thread-1-processing-n:127.0.0.1:39713_solr x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.SolrCore [collection1_shard2_replica_n2] Registered new searcher autowarm time: 0 ms: Collection: 'collection1'
[junit4] 2> 105508 INFO (qtp24768602-4247) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/update params={update.distrib=TOLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:44821/solr/collection1_shard1_replica_n1/&commit_end_point=leaders&wt=javabin&version=2&expungeDeletes=false} status=0 QTime=2
[junit4] 2> 105513 INFO (searcherExecutor-2229-thread-1-processing-n:127.0.0.1:44821_solr x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node3) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.SolrCore [collection1_shard1_replica_n1] Registered new searcher autowarm time: 0 ms: Collection: 'collection1'
[junit4] 2> 105513 INFO (qtp4578963-4268) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1:4&commit=true&wt=javabin&version=2} status=0 QTime=17
[junit4] 2> 105516 INFO (qtp4578963-4277) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=collection1:4&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 105517 INFO (qtp24768602-4253) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=collection1:4&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 105524 INFO (searcherExecutor-2229-thread-1-processing-n:127.0.0.1:44821_solr x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node3) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.SolrCore [collection1_shard1_replica_n1] Registered new searcher autowarm time: 0 ms: Collection: 'collection1'
[junit4] 2> 105524 INFO (qtp4578963-4217) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=TOLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:39713/solr/collection1_shard2_replica_n2/&commit_end_point=leaders&wt=javabin&version=2&expungeDeletes=false} status=0 QTime=5
[junit4] 2> 105531 INFO (searcherExecutor-2227-thread-1-processing-n:127.0.0.1:39713_solr x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.SolrCore [collection1_shard2_replica_n2] Registered new searcher autowarm time: 0 ms: Collection: 'collection1'
[junit4] 2> 105532 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=collection1:4&commit=true&wt=javabin&version=2} status=0 QTime=14
[junit4] 2> 105535 INFO (TEST-StreamDecoratorTest.testParallelMergeStream-seed#[DF73F68A268EC4]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 105537 INFO (zkConnectionManagerCallback-2262-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 105537 INFO (TEST-StreamDecoratorTest.testParallelMergeStream-seed#[DF73F68A268EC4]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 105539 INFO (TEST-StreamDecoratorTest.testParallelMergeStream-seed#[DF73F68A268EC4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 105539 INFO (TEST-StreamDecoratorTest.testParallelMergeStream-seed#[DF73F68A268EC4]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44143/solr ready
[junit4] 2> 105542 INFO (qtp24768602-4253) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/stream params={distrib=false&workerID=0&indent=off&numWorkers=2&expr=merge(search(collection1,q%3D"id:(4+1+8+7+9)",fl%3D"id,a_s,a_i",sort%3D"a_i+asc",partitionKeys%3Da_i,qt%3D"/export",zkHost%3D"127.0.0.1:44143/solr"),search(collection1,q%3D"id:(0+2+3+6)",fl%3D"id,a_s,a_i",sort%3D"a_i+asc",partitionKeys%3Da_i,qt%3D"/export",zkHost%3D"127.0.0.1:44143/solr"),on%3D"a_i+asc")&wt=json&version=2.2} status=0 QTime=0
[junit4] 2> 105543 INFO (qtp4578963-4275) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1] webapp=/solr path=/stream params={distrib=false&workerID=1&indent=off&numWorkers=2&expr=merge(search(collection1,q%3D"id:(4+1+8+7+9)",fl%3D"id,a_s,a_i",sort%3D"a_i+asc",partitionKeys%3Da_i,qt%3D"/export",zkHost%3D"127.0.0.1:44143/solr"),search(collection1,q%3D"id:(0+2+3+6)",fl%3D"id,a_s,a_i",sort%3D"a_i+asc",partitionKeys%3Da_i,qt%3D"/export",zkHost%3D"127.0.0.1:44143/solr"),on%3D"a_i+asc")&wt=json&version=2.2} status=0 QTime=0
[junit4] 2> 105545 INFO (qtp24768602-4215) [n:127.0.0.1:39713_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2 ] o.a.s.c.S.Request [collection1_shard2_replica_n2] webapp=/solr path=/export params={q=id:(4+1+8+7+9)&distrib=false&indent=off&fl=id,a_s,a_i&sort=a_i+asc&partitionKeys=a_i&fq={!hash+workers%3D2+worker%3D1}&wt=json&version=2.2} hits=1 status=0 QTime=0
[junit4] 2> 105545 INFO (qtp4578963-4277) [n:127.0.0.1:44821_solr c:collection1 s:shard1 r:core
[...truncated too long message...]
s/uknownCollection/state.json
[junit4] 2> 8 /solr/collections/destinationCollection/terms/shard1
[junit4] 2> 7 /solr/collections/checkpointCollection/state.json
[junit4] 2> 7 /solr/collections/parallelDestinationCollection/terms/shard1
[junit4] 2> 7 /solr/collections/destinationCollection/terms/shard2
[junit4] 2> 6 /solr/collections/mainCorpus1/state.json
[junit4] 2> 6 /solr/collections/parallelDestinationCollection/terms/shard2
[junit4] 2> 5 /solr/collections/parallelDestinationCollection1/state.json
[junit4] 2> 4 /solr/collections/workQueue1/terms/shard2
[junit4] 2> 4 /solr/collections/workQueue1/terms/shard1
[junit4] 2> 4 /solr/collections/mainCorpus1/terms/shard1
[junit4] 2> 4 /solr/collections/modelCollection/terms/shard2
[junit4] 2> 4 /solr/packages.json
[junit4] 2> 4 /solr/configs/ml
[junit4] 2> 4 /solr/collections/checkpointCollection/terms/shard2
[junit4] 2> 4 /solr/collections/checkpointCollection/terms/shard1
[junit4] 2> 4 /solr/collections/mainCorpus/terms/shard2
[junit4] 2> 4 /solr/security.json
[junit4] 2> 4 /solr/collections/uknownCollection/terms/shard1
[junit4] 2> 4 /solr/collections/workQueue/terms/shard2
[junit4] 2> 4 /solr/collections/workQueue/terms/shard1
[junit4] 2> 3 /solr/collections/destination1/terms/shard1
[junit4] 2> 3 /solr/collections/destination1/terms/shard2
[junit4] 2> 3 /solr/collections/mainCorpus1/terms/shard2
[junit4] 2> 3 /solr/collections/modelCollection/terms/shard1
[junit4] 2> 3 /solr/collections/destination/terms/shard2
[junit4] 2> 3 /solr/collections/destination/terms/shard1
[junit4] 2> 3 /solr/collections/mainCorpus/terms/shard1
[junit4] 2> 3 /solr/collections/collection1/terms/shard1
[junit4] 2> 3 /solr/collections/collection1/terms/shard2
[junit4] 2> 3 /solr/collections/uknownCollection/terms/shard2
[junit4] 2> 2 /solr/collections/collection1/collectionprops.json
[junit4] 2> 2 /solr/collections/mainCorpus1/collectionprops.json
[junit4] 2> 2 /solr/collections/checkpointCollection/collectionprops.json
[junit4] 2> 2 /solr/collections/destinationCollection/collectionprops.json
[junit4] 2> 2 /solr/collections/workQueue/collectionprops.json
[junit4] 2> 2 /solr/collections/destination/collectionprops.json
[junit4] 2> 2 /solr/collections/parallelDestinationCollection1/collectionprops.json
[junit4] 2> 2 /solr/collections/destination1/collectionprops.json
[junit4] 2> 2 /solr/collections/workQueue1/collectionprops.json
[junit4] 2> 2 /solr/collections/parallelDestinationCollection/collectionprops.json
[junit4] 2> 2 /solr/collections/modelCollection/collectionprops.json
[junit4] 2> 2 /solr/collections/uknownCollection/collectionprops.json
[junit4] 2> 2 /solr/collections/mainCorpus/collectionprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 67 /solr/clusterstate.json
[junit4] 2> 63 /solr/collections/parallelDestinationCollection1/state.json
[junit4] 2> 48 /solr/collections/parallelDestinationCollection/state.json
[junit4] 2> 44 /solr/collections/destinationCollection/state.json
[junit4] 2> 34 /solr/collections/collection1/state.json
[junit4] 2> 27 /solr/collections/workQueue/state.json
[junit4] 2> 25 /solr/collections/uknownCollection/state.json
[junit4] 2> 24 /solr/collections/destination/state.json
[junit4] 2> 24 /solr/collections/destination1/state.json
[junit4] 2> 24 /solr/collections/workQueue1/state.json
[junit4] 2> 24 /solr/collections/modelCollection/state.json
[junit4] 2> 23 /solr/collections/mainCorpus/state.json
[junit4] 2> 20 /solr/collections/checkpointCollection/state.json
[junit4] 2> 19 /solr/collections/mainCorpus1/state.json
[junit4] 2> 2 /solr/overseer_elect/election/72097604903698443-127.0.0.1:44821_solr-n_0000000001
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 328 /solr/collections
[junit4] 2> 260 /solr/overseer/queue
[junit4] 2> 99 /solr/overseer/collection-queue-work
[junit4] 2> 83 /solr/live_nodes
[junit4] 2>
[junit4] 2> 171447 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:44143
[junit4] 2> 171447 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:44143
[junit4] 2> 171447 INFO (SUITE-StreamDecoratorTest-seed#[DF73F68A268EC4]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 44143
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-solrj/test/J5/temp/solr.client.solrj.io.stream.StreamDecoratorTest_DF73F68A268EC4-001
[junit4] 2> May 24, 2020 9:55:18 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(Lucene86): {name_s=FST50, expr_s=PostingsFormat(name=MockRandom), terms_ss=PostingsFormat(name=LuceneVarGapDocFreqInterval), join2_s=PostingsFormat(name=LuceneVarGapDocFreqInterval), field_s=Lucene84, multiDefault=PostingsFormat(name=LuceneVarGapDocFreqInterval), subject=PostingsFormat(name=LuceneVarGapDocFreqInterval), a1_s=PostingsFormat(name=LuceneVarGapDocFreqInterval), a2_s=FST50, body_t=FST50, s_multi=FST50, a_ss=Lucene84, a_s=FST50, tv_text=Lucene84, text_s=PostingsFormat(name=MockRandom), id=PostingsFormat(name=MockRandom), text=FST50, bbid_s=FST50, type_s=Lucene84, checkpoint_ss=FST50, test_t=FST50, ident_s=PostingsFormat(name=LuceneVarGapDocFreqInterval), extra_s=PostingsFormat(name=LuceneVarGapDocFreqInterval), ykey_s=Lucene84, side_s=FST50, deletable_s=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{name_s=DocValuesFormat(name=Lucene80), expr_s=DocValuesFormat(name=Asserting), iteration_i=DocValuesFormat(name=Asserting), terms_ss=DocValuesFormat(name=Lucene80), join2_s=DocValuesFormat(name=Lucene80), field_s=DocValuesFormat(name=Direct), multiDefault=DocValuesFormat(name=Lucene80), a1_s=DocValuesFormat(name=Lucene80), intDefault=DocValuesFormat(name=Direct), a_f=DocValuesFormat(name=Lucene80), join1_i=DocValuesFormat(name=Asserting), falseNegative_i=DocValuesFormat(name=Direct), a2_s=DocValuesFormat(name=Lucene80), a_i=DocValuesFormat(name=Asserting), test_i=DocValuesFormat(name=Lucene80), join3_i=DocValuesFormat(name=Lucene80), falsePositive_i=DocValuesFormat(name=Direct), field_i=DocValuesFormat(name=Lucene80), s_multi=DocValuesFormat(name=Lucene80), a_ss=DocValuesFormat(name=Direct), a_s=DocValuesFormat(name=Lucene80), text_s=DocValuesFormat(name=Asserting), id=DocValuesFormat(name=Asserting), bbid_s=DocValuesFormat(name=Lucene80), timestamp=DocValuesFormat(name=Direct), idfs_ds=DocValuesFormat(name=Direct), type_s=DocValuesFormat(name=Direct), alpha_d=DocValuesFormat(name=Lucene80), i_multi=DocValuesFormat(name=Asserting), weights_ds=DocValuesFormat(name=Lucene80), trueNegative_i=DocValuesFormat(name=Lucene80), b_ls=DocValuesFormat(name=Lucene80), out_i=DocValuesFormat(name=Lucene80), checkpoint_ss=DocValuesFormat(name=Lucene80), ident_s=DocValuesFormat(name=Lucene80), _version_=DocValuesFormat(name=Direct), error_d=DocValuesFormat(name=Asserting), extra_s=DocValuesFormat(name=Lucene80), ykey_s=DocValuesFormat(name=Direct), side_s=DocValuesFormat(name=Lucene80), truePositive_i=DocValuesFormat(name=Asserting), deletable_s=DocValuesFormat(name=Lucene80)}, maxPointsInLeafNode=1832, maxMBSortInHeap=7.2673908787107715, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@1d66e45), locale=en-GB, timezone=Etc/GMT-10
[junit4] 2> NOTE: Linux 5.3.0-51-generic i386/Oracle Corporation 1.8.0_201 (32-bit)/cpus=16,threads=1,free=103995408,total=347865088
[junit4] 2> NOTE: All tests run in this JVM: [ExclusiveOrEvaluatorTest, ShufflingReplicaListTransformerTest, SolrPingTest, SineEvaluatorTest, TestCollectionStateWatchers, HyperbolicSineEvaluatorTest, ShardParamsTest, CloudHttp2SolrClientRetryTest, ArrayEvaluatorTest, TestPathTrie, QueryFacetMapTest, CosineEvaluatorTest, JdbcDriverTest, UuidEvaluatorTest, SolrExampleStreamingTest, ConcurrentUpdateHttp2SolrClientTest, HttpSolrClientConPoolTest, JdbcTest, StreamDecoratorTest]
[junit4] Completed [208/208 (1!)] on J5 in 69.77s, 52 tests, 1 error <<< FAILURES!
[...truncated 46609 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Linux/3173/consoleText
[repro] Revision: 5e7be63ca7fbd234526fceb2d7a0594a54f90670
[repro] Ant options: "-Dargs=-server -XX:+UseParallelGC"
[repro] Repro line: ant test -Dtestcase=StreamDecoratorTest -Dtests.method=testParallelTerminatingDaemonUpdateStream -Dtests.seed=DF73F68A268EC4 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en-GB -Dtests.timezone=Etc/GMT-10 -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[repro] JUnit rest result XML files will be moved to: ./repro-reports
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/solrj
[repro] StreamDecoratorTest
[repro] ant compile-test
[...truncated 2595 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.StreamDecoratorTest" -Dtests.showOutput=onerror "-Dargs=-server -XX:+UseParallelGC" -Dtests.seed=DF73F68A268EC4 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en-GB -Dtests.timezone=Etc/GMT-10 -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[...truncated 331 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.client.solrj.io.stream.StreamDecoratorTest
[repro] Exiting with code 0
[...truncated 43 lines...]
[JENKINS] Lucene-Solr-8.x-Linux (64bit/jdk-13.0.2) - Build # 3174 -
Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Linux/3174/
Java: 64bit/jdk-13.0.2 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.TestSolrCloudWithSecureImpersonation.testForwarding
Error Message:
Error from server at http://127.0.0.1:45581/solr/forwardingCollection: Expected mime type application/octet-stream but got text/html. <html> <head> <meta http-equiv="Content-Type" content="text/html;charset=utf-8"/> <title>Error 401 Authentication required</title> </head> <body><h2>HTTP ERROR 401 Authentication required</h2> <table> <tr><th>URI:</th><td>/solr/forwardingCollection/select</td></tr> <tr><th>STATUS:</th><td>401</td></tr> <tr><th>MESSAGE:</th><td>Authentication required</td></tr> <tr><th>SERVLET:</th><td>org.apache.solr.client.solrj.embedded.JettySolrRunner$Servlet404-655489a7</td></tr> </table> <hr><a href="http://eclipse.org/jetty">Powered by Jetty:// 9.4.27.v20200227</a><hr/> </body> </html>
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:45581/solr/forwardingCollection: Expected mime type application/octet-stream but got text/html. <html>
<head>
<meta http-equiv="Content-Type" content="text/html;charset=utf-8"/>
<title>Error 401 Authentication required</title>
</head>
<body><h2>HTTP ERROR 401 Authentication required</h2>
<table>
<tr><th>URI:</th><td>/solr/forwardingCollection/select</td></tr>
<tr><th>STATUS:</th><td>401</td></tr>
<tr><th>MESSAGE:</th><td>Authentication required</td></tr>
<tr><th>SERVLET:</th><td>org.apache.solr.client.solrj.embedded.JettySolrRunner$Servlet404-655489a7</td></tr>
</table>
<hr><a href="http://eclipse.org/jetty">Powered by Jetty:// 9.4.27.v20200227</a><hr/>
</body>
</html>
at __randomizedtesting.SeedInfo.seed([2E0CA7DFC3EDEB86:CF8ACE21DEDB0D6F]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:628)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:265)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:248)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:211)
at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:1003)
at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:1018)
at org.apache.solr.cloud.TestSolrCloudWithSecureImpersonation.testForwarding(TestSolrCloudWithSecureImpersonation.java:328)
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:567)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
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:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
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:830)
Build Log:
[...truncated 14711 lines...]
[junit4] Suite: org.apache.solr.cloud.TestSolrCloudWithSecureImpersonation
[junit4] 2> 491762 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/server/solr/configsets/_default/conf'
[junit4] 2> 491762 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 491762 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestSolrCloudWithSecureImpersonation_2E0CA7DFC3EDEB86-001/data-dir-67-001
[junit4] 2> 491763 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 491763 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 491894 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestSolrCloudWithSecureImpersonation_2E0CA7DFC3EDEB86-001/tempDir-001
[junit4] 2> 491894 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 491894 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port: 0.0.0.0/0.0.0.0:0
[junit4] 2> 491894 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 491994 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port: 37633
[junit4] 2> 491994 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:37633
[junit4] 2> 491994 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:37633
[junit4] 2> 491994 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 37633
[junit4] 2> 491995 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 491997 INFO (zkConnectionManagerCallback-5702-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 491997 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 491998 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 491999 INFO (zkConnectionManagerCallback-5704-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 491999 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 491999 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 492001 INFO (zkConnectionManagerCallback-5706-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 492001 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 492104 WARN (jetty-launcher-5707-thread-1) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 492104 WARN (jetty-launcher-5707-thread-2) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 492104 INFO (jetty-launcher-5707-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 492104 INFO (jetty-launcher-5707-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 492104 INFO (jetty-launcher-5707-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 492104 INFO (jetty-launcher-5707-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 492104 INFO (jetty-launcher-5707-thread-1) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 13.0.2+8
[junit4] 2> 492104 INFO (jetty-launcher-5707-thread-2) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 13.0.2+8
[junit4] 2> 492109 INFO (jetty-launcher-5707-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 492109 INFO (jetty-launcher-5707-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 492110 INFO (jetty-launcher-5707-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 492110 INFO (jetty-launcher-5707-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 492110 INFO (jetty-launcher-5707-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 492110 INFO (jetty-launcher-5707-thread-2) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 492110 INFO (jetty-launcher-5707-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@99f6fab{/solr,null,AVAILABLE}
[junit4] 2> 492113 INFO (jetty-launcher-5707-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@629834dc{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:35093}
[junit4] 2> 492113 INFO (jetty-launcher-5707-thread-1) [ ] o.e.j.s.Server Started @492140ms
[junit4] 2> 492113 INFO (jetty-launcher-5707-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7b56f0bf{/solr,null,AVAILABLE}
[junit4] 2> 492113 INFO (jetty-launcher-5707-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35093}
[junit4] 2> 492113 ERROR (jetty-launcher-5707-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 492113 INFO (jetty-launcher-5707-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 492113 INFO (jetty-launcher-5707-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.6.0
[junit4] 2> 492114 INFO (jetty-launcher-5707-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 492114 INFO (jetty-launcher-5707-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr
[junit4] 2> 492114 INFO (jetty-launcher-5707-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T11:31:19.050025Z
[junit4] 2> 492117 INFO (jetty-launcher-5707-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@53a2aef7{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:45581}
[junit4] 2> 492117 INFO (jetty-launcher-5707-thread-2) [ ] o.e.j.s.Server Started @492145ms
[junit4] 2> 492118 INFO (jetty-launcher-5707-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 492118 INFO (jetty-launcher-5707-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45581}
[junit4] 2> 492118 ERROR (jetty-launcher-5707-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 492118 INFO (jetty-launcher-5707-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 492118 INFO (jetty-launcher-5707-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.6.0
[junit4] 2> 492118 INFO (jetty-launcher-5707-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 492118 INFO (jetty-launcher-5707-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr
[junit4] 2> 492118 INFO (jetty-launcher-5707-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T11:31:19.054438Z
[junit4] 2> 492119 INFO (jetty-launcher-5707-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 492119 INFO (zkConnectionManagerCallback-5709-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 492119 INFO (jetty-launcher-5707-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 492119 INFO (jetty-launcher-5707-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 492126 INFO (zkConnectionManagerCallback-5711-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 492126 INFO (jetty-launcher-5707-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 492126 INFO (jetty-launcher-5707-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 492345 INFO (jetty-launcher-5707-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 492362 WARN (jetty-launcher-5707-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@28d560b1[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 492362 WARN (jetty-launcher-5707-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@28d560b1[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 492366 WARN (jetty-launcher-5707-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@582cb680[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 492366 WARN (jetty-launcher-5707-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@582cb680[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 492366 INFO (jetty-launcher-5707-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37633/solr
[junit4] 2> 492385 INFO (jetty-launcher-5707-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 492386 INFO (zkConnectionManagerCallback-5725-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 492386 INFO (jetty-launcher-5707-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 492448 INFO (jetty-launcher-5707-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 492449 WARN (jetty-launcher-5707-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@50e08981[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 492449 WARN (jetty-launcher-5707-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@50e08981[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 492458 WARN (jetty-launcher-5707-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@43532cb5[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 492458 WARN (jetty-launcher-5707-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@43532cb5[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 492459 INFO (jetty-launcher-5707-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37633/solr
[junit4] 2> 492460 INFO (jetty-launcher-5707-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 492460 INFO (zkConnectionManagerCallback-5733-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 492460 INFO (jetty-launcher-5707-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 492490 INFO (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 492491 INFO (zkConnectionManagerCallback-5735-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 492491 INFO (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 492528 INFO (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35093_solr
[junit4] 2> 492528 INFO (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.c.Overseer Overseer (id=72097986913042439-127.0.0.1:35093_solr-n_0000000000) starting
[junit4] 2> 492530 INFO (OverseerStateUpdate-72097986913042439-127.0.0.1:35093_solr-n_0000000000) [n:127.0.0.1:35093_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:35093_solr
[junit4] 2> 492531 INFO (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35093_solr
[junit4] 2> 492532 INFO (zkCallback-5734-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 492532 INFO (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 492533 INFO (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: org.apache.solr.security.HttpParamDelegationTokenPlugin
[junit4] 2> 492536 WARN (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.c.s.i.Krb5HttpClientBuilder org.apache.solr.client.solrj.impl.Krb5HttpClientBuilder is configured without specifying system property 'java.security.auth.login.config'
[junit4] 2> 492544 INFO (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.s.KerberosPlugin Params: {solr.kerberos.impersonator.user.noGroups.hosts=*, solr.kerberos.impersonator.user.bogusGroup.groups=__some_bogus_group, token.valid=30, cookie.domain=127.0.0.1, solr.kerberos.impersonator.user.anyHostAnyUser.groups=*, solr.kerberos.impersonator.user.bogusGroup.hosts=*, solr.kerberos.impersonator.user.anyHostAnyUser.hosts=*, token.validity=36000, solr.kerberos.impersonator.user.noHosts.groups=*, type=kerberos, solr.kerberos.impersonator.user.localHostAnyGroup.groups=*, delegation-token.token-kind=solr-dt, solr.kerberos.impersonator.user.wrongHost.hosts=[::1]:4, cookie.path=/, zk-dt-secret-manager.znodeWorkingPath=solr/security/zkdtsm, solr.kerberos.impersonator.user.localHostAnyGroup.hosts=localhost.localdomain,localhost,127.0.0.1, signer.secret.provider.zookeeper.path=/token, solr.kerberos.impersonator.user.anyHostUsersGroup.groups=supergroup, zk-dt-secret-manager.enable=true, solr.kerberos.impersonator.user.wrongHost.groups=*, kerberos.name.rules=DEFAULT, signer.secret.provider=zookeeper, delegation-token.json-mapper.AUTO_CLOSE_TARGET=false, solr.kerberos.impersonator.user.anyHostUsersGroup.hosts=*}
[junit4] 2> 492591 INFO (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 492591 INFO (zkConnectionManagerCallback-5744-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 492591 INFO (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 492594 INFO (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 492597 INFO (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:45581_solr as DOWN
[junit4] 2> 492597 INFO (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.c.f.i.CuratorFrameworkImpl Starting
[junit4] 2> 492597 INFO (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 492597 INFO (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45581_solr
[junit4] 2> 492598 INFO (zkCallback-5734-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 492599 INFO (zkCallback-5743-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 492600 INFO (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 492600 INFO (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: org.apache.solr.security.HttpParamDelegationTokenPlugin
[junit4] 2> 492600 WARN (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.c.s.i.Krb5HttpClientBuilder org.apache.solr.client.solrj.impl.Krb5HttpClientBuilder is configured without specifying system property 'java.security.auth.login.config'
[junit4] 2> 492600 INFO (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.s.KerberosPlugin Params: {solr.kerberos.impersonator.user.noGroups.hosts=*, solr.kerberos.impersonator.user.bogusGroup.groups=__some_bogus_group, token.valid=30, cookie.domain=127.0.0.1, solr.kerberos.impersonator.user.anyHostAnyUser.groups=*, solr.kerberos.impersonator.user.bogusGroup.hosts=*, solr.kerberos.impersonator.user.anyHostAnyUser.hosts=*, token.validity=36000, solr.kerberos.impersonator.user.noHosts.groups=*, type=kerberos, solr.kerberos.impersonator.user.localHostAnyGroup.groups=*, delegation-token.token-kind=solr-dt, solr.kerberos.impersonator.user.wrongHost.hosts=[::1]:4, cookie.path=/, zk-dt-secret-manager.znodeWorkingPath=solr/security/zkdtsm, solr.kerberos.impersonator.user.localHostAnyGroup.hosts=localhost.localdomain,localhost,127.0.0.1, signer.secret.provider.zookeeper.path=/token, solr.kerberos.impersonator.user.anyHostUsersGroup.groups=supergroup, zk-dt-secret-manager.enable=true, solr.kerberos.impersonator.user.wrongHost.groups=*, kerberos.name.rules=DEFAULT, signer.secret.provider=zookeeper, delegation-token.json-mapper.AUTO_CLOSE_TARGET=false, solr.kerberos.impersonator.user.anyHostUsersGroup.hosts=*}
[junit4] 2> 492601 INFO (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.c.f.i.CuratorFrameworkImpl Starting
[junit4] 2> 492607 INFO (jetty-launcher-5707-thread-1-EventThread) [ ] o.a.c.f.s.ConnectionStateManager State change: CONNECTED
[junit4] 2> 492613 INFO (jetty-launcher-5707-thread-2-EventThread) [ ] o.a.c.f.s.ConnectionStateManager State change: CONNECTED
[junit4] 2> 492701 WARN (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.c.s.i.Krb5HttpClientBuilder org.apache.solr.client.solrj.impl.Krb5HttpClientBuilder is configured without specifying system property 'java.security.auth.login.config'
[junit4] 2> 492701 WARN (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.c.s.i.Krb5HttpClientBuilder org.apache.solr.client.solrj.impl.Krb5HttpClientBuilder is configured without specifying system property 'java.security.auth.login.config'
[junit4] 2> 492701 WARN (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=enabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 492701 WARN (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=enabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 492717 INFO (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 492719 INFO (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 492733 INFO (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45581.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@22f271a0
[junit4] 2> 492734 INFO (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35093.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@22f271a0
[junit4] 2> 492739 INFO (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45581.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@22f271a0
[junit4] 2> 492739 INFO (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45581.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@22f271a0
[junit4] 2> 492739 INFO (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35093.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@22f271a0
[junit4] 2> 492739 INFO (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35093.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@22f271a0
[junit4] 2> 492740 INFO (jetty-launcher-5707-thread-2) [n:127.0.0.1:45581_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestSolrCloudWithSecureImpersonation_2E0CA7DFC3EDEB86-001/tempDir-001/node2/.
[junit4] 2> 492740 INFO (jetty-launcher-5707-thread-1) [n:127.0.0.1:35093_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestSolrCloudWithSecureImpersonation_2E0CA7DFC3EDEB86-001/tempDir-001/node1/.
[junit4] 2> 492746 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 492747 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 492748 INFO (zkConnectionManagerCallback-5762-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 492748 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 492748 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 492749 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37633/solr ready
[junit4] 2> 492766 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyValidateHost-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testProxyValidateHost
[junit4] 2> 492786 INFO (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params doAs=bar&action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 492786 INFO (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={doAs=bar&action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 492789 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyValidateHost-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testProxyValidateHost
[junit4] 2> 492807 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyInvalidProxyUser-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testProxyInvalidProxyUser
[junit4] 2> 492817 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.h.s.a.s.AuthenticationFilter AuthenticationToken ignored: Invalid AuthenticationToken type
[junit4] 2> 492855 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.h.s.t.d.w.DelegationTokenAuthenticationFilter Authentication exception: User: bar is not allowed to impersonate anyHostAnyUser
[junit4] 2> 492856 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyInvalidProxyUser-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testProxyInvalidProxyUser
[junit4] 2> 492875 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyValidateAnyHostAnyUser-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testProxyValidateAnyHostAnyUser
[junit4] 2> 492876 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.h.s.a.s.AuthenticationFilter AuthenticationToken ignored: Invalid AuthenticationToken type
[junit4] 2> 492876 INFO (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params doAs=bar&action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 492876 INFO (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={doAs=bar&action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 492877 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyValidateAnyHostAnyUser-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testProxyValidateAnyHostAnyUser
[junit4] 2> 492896 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyNoConfigHosts-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testProxyNoConfigHosts
[junit4] 2> 492898 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.h.s.a.s.AuthenticationFilter AuthenticationToken ignored: Invalid AuthenticationToken type
[junit4] 2> 492898 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.h.s.t.d.w.DelegationTokenAuthenticationFilter Authentication exception: Unauthorized connection for super-user: noHosts from IP 127.0.0.1
[junit4] 2> 492899 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyNoConfigHosts-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testProxyNoConfigHosts
[junit4] 2> 492920 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyNoConfigGroups-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testProxyNoConfigGroups
[junit4] 2> 492921 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.h.s.a.s.AuthenticationFilter AuthenticationToken ignored: Invalid AuthenticationToken type
[junit4] 2> 492922 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.h.s.t.d.w.DelegationTokenAuthenticationFilter Authentication exception: User: noGroups is not allowed to impersonate bar
[junit4] 2> 492922 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyNoConfigGroups-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testProxyNoConfigGroups
[junit4] 2> 492954 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyUnknownRemote-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testProxyUnknownRemote
[junit4] 2> 492955 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.h.s.a.s.AuthenticationFilter AuthenticationToken ignored: Invalid AuthenticationToken type
[junit4] 2> 492956 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.h.s.t.d.w.DelegationTokenAuthenticationFilter Authentication exception: Unauthorized connection for super-user: localHostAnyGroup from IP 255.255.255.255
[junit4] 2> 492957 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyUnknownRemote-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testProxyUnknownRemote
[junit4] 2> 492979 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyInvalidRemote-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testProxyInvalidRemote
[junit4] 2> 492981 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.h.s.a.s.AuthenticationFilter AuthenticationToken ignored: Invalid AuthenticationToken type
[junit4] 2> 492981 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.h.s.t.d.w.DelegationTokenAuthenticationFilter Authentication exception: Unauthorized connection for super-user: localHostAnyGroup from IP [::1]:6
[junit4] 2> 492983 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyInvalidRemote-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testProxyInvalidRemote
[junit4] 2> 493014 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyValidateGroup-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testProxyValidateGroup
[junit4] 2> 493015 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.h.s.a.s.AuthenticationFilter AuthenticationToken ignored: Invalid AuthenticationToken type
[junit4] 2> 493030 INFO (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params doAs=jenkins&action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 493030 INFO (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={doAs=jenkins&action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 493031 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyValidateGroup-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testProxyValidateGroup
[junit4] 2> 493047 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyNullProxyUser-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testProxyNullProxyUser
[junit4] 2> 493048 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.h.s.a.s.AuthenticationFilter AuthenticationToken ignored: Invalid AuthenticationToken type
[junit4] 2> 493048 INFO (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.s.s.SolrDispatchFilter Error authenticating
[junit4] 2> => java.lang.IllegalArgumentException: userName is NULL, empty or contains a '&'
[junit4] 2> at org.apache.hadoop.security.authentication.util.AuthToken.checkForIllegalArgument(AuthToken.java:91)
[junit4] 2> java.lang.IllegalArgumentException: userName is NULL, empty or contains a '&'
[junit4] 2> at org.apache.hadoop.security.authentication.util.AuthToken.checkForIllegalArgument(AuthToken.java:91) ~[hadoop-auth-3.2.0.jar:?]
[junit4] 2> at org.apache.hadoop.security.authentication.util.AuthToken.<init>(AuthToken.java:73) ~[hadoop-auth-3.2.0.jar:?]
[junit4] 2> at org.apache.hadoop.security.authentication.server.AuthenticationToken.<init>(AuthenticationToken.java:59) ~[hadoop-auth-3.2.0.jar:?]
[junit4] 2> at org.apache.solr.security.HttpParamDelegationTokenPlugin$HttpParamDelegationTokenAuthenticationHandler$HttpParamAuthenticationHandler.authenticate(HttpParamDelegationTokenPlugin.java:233) ~[test/:?]
[junit4] 2> at org.apache.hadoop.security.token.delegation.web.DelegationTokenAuthenticationHandler.authenticate(DelegationTokenAuthenticationHandler.java:411) ~[hadoop-common-3.2.0.jar:?]
[junit4] 2> at org.apache.solr.security.RequestContinuesRecorderAuthenticationHandler.authenticate(RequestContinuesRecorderAuthenticationHandler.java:69) ~[java/:?]
[junit4] 2> at org.apache.hadoop.security.authentication.server.AuthenticationFilter.doFilter(AuthenticationFilter.java:536) ~[hadoop-auth-3.2.0.jar:?]
[junit4] 2> at org.apache.solr.security.DelegationTokenKerberosFilter.doFilter(DelegationTokenKerberosFilter.java:126) ~[java/:?]
[junit4] 2> at org.apache.solr.security.HttpParamDelegationTokenPlugin$HttpParamToRequestFilter.doFilter(HttpParamDelegationTokenPlugin.java:265) ~[test/:?]
[junit4] 2> at org.apache.solr.security.KerberosPlugin.doAuthenticate(KerberosPlugin.java:234) ~[java/:?]
[junit4] 2> at org.apache.solr.security.AuthenticationPlugin.authenticate(AuthenticationPlugin.java:88) ~[java/:?]
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.authenticateRequest(SolrDispatchFilter.java:505) ~[java/:?]
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:399) ~[java/:?]
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:345) ~[java/:?]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604) ~[jetty-servlet-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:166) ~[java/:?]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604) ~[jetty-servlet-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:545) ~[jetty-servlet-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1300) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:485) ~[jetty-servlet-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1215) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:322) ~[jetty-rewrite-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:767) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:500) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:547) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) ~[jetty-io-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) ~[jetty-io-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) ~[jetty-io-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806) ~[jetty-util-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938) ~[jetty-util-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at java.lang.Thread.run(Thread.java:830) [?:?]
[junit4] 2> 493049 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.e.j.s.HttpChannel /solr/admin/collections
[junit4] 2> => org.apache.solr.common.SolrException: Error during request authentication,
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.authenticateRequest(SolrDispatchFilter.java:511)
[junit4] 2> org.apache.solr.common.SolrException: Error during request authentication,
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.authenticateRequest(SolrDispatchFilter.java:511) ~[java/:?]
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:399) ~[java/:?]
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:345) ~[java/:?]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604) ~[jetty-servlet-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:166) ~[java/:?]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604) ~[jetty-servlet-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:545) ~[jetty-servlet-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1300) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:485) ~[jetty-servlet-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1215) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:322) ~[jetty-rewrite-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:767) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:500) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:547) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273) ~[jetty-server-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) ~[jetty-io-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) ~[jetty-io-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) ~[jetty-io-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806) ~[jetty-util-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938) ~[jetty-util-9.4.27.v20200227.jar:9.4.27.v20200227]
[junit4] 2> at java.lang.Thread.run(Thread.java:830) [?:?]
[junit4] 2> Caused by: java.lang.IllegalArgumentException: userName is NULL, empty or contains a '&'
[junit4] 2> at org.apache.hadoop.security.authentication.util.AuthToken.checkForIllegalArgument(AuthToken.java:91) ~[hadoop-auth-3.2.0.jar:?]
[junit4] 2> at org.apache.hadoop.security.authentication.util.AuthToken.<init>(AuthToken.java:73) ~[hadoop-auth-3.2.0.jar:?]
[junit4] 2> at org.apache.hadoop.security.authentication.server.AuthenticationToken.<init>(AuthenticationToken.java:59) ~[hadoop-auth-3.2.0.jar:?]
[junit4] 2> at org.apache.solr.security.HttpParamDelegationTokenPlugin$HttpParamDelegationTokenAuthenticationHandler$HttpParamAuthenticationHandler.authenticate(HttpParamDelegationTokenPlugin.java:233) ~[test/:?]
[junit4] 2> at org.apache.hadoop.security.token.delegation.web.DelegationTokenAuthenticationHandler.authenticate(DelegationTokenAuthenticationHandler.java:411) ~[hadoop-common-3.2.0.jar:?]
[junit4] 2> at org.apache.solr.security.RequestContinuesRecorderAuthenticationHandler.authenticate(RequestContinuesRecorderAuthenticationHandler.java:69) ~[java/:?]
[junit4] 2> at org.apache.hadoop.security.authentication.server.AuthenticationFilter.doFilter(AuthenticationFilter.java:536) ~[hadoop-auth-3.2.0.jar:?]
[junit4] 2> at org.apache.solr.security.DelegationTokenKerberosFilter.doFilter(DelegationTokenKerberosFilter.java:126) ~[java/:?]
[junit4] 2> at org.apache.solr.security.HttpParamDelegationTokenPlugin$HttpParamToRequestFilter.doFilter(HttpParamDelegationTokenPlugin.java:265) ~[test/:?]
[junit4] 2> at org.apache.solr.security.KerberosPlugin.doAuthenticate(KerberosPlugin.java:234) ~[java/:?]
[junit4] 2> at org.apache.solr.security.AuthenticationPlugin.authenticate(AuthenticationPlugin.java:88) ~[java/:?]
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.authenticateRequest(SolrDispatchFilter.java:505) ~[java/:?]
[junit4] 2> ... 31 more
[junit4] 2> 493052 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyNullProxyUser-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testProxyNullProxyUser
[junit4] 2> 493092 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyInvalidGroup-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testProxyInvalidGroup
[junit4] 2> 493096 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.h.s.a.s.AuthenticationFilter AuthenticationToken ignored: Invalid AuthenticationToken type
[junit4] 2> 493097 WARN (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.h.s.t.d.w.DelegationTokenAuthenticationFilter Authentication exception: User: bogusGroup is not allowed to impersonate bar
[junit4] 2> 493098 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyInvalidGroup-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testProxyInvalidGroup
[junit4] 2> 493131 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyWrongHost-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testProxyWrongHost
[junit4] 2> 493133 WARN (qtp1566919467-10088) [ ] o.a.h.s.a.s.AuthenticationFilter AuthenticationToken ignored: Invalid AuthenticationToken type
[junit4] 2> 493134 WARN (qtp1566919467-10088) [ ] o.a.h.s.t.d.w.DelegationTokenAuthenticationFilter Authentication exception: Unauthorized connection for super-user: wrongHost from IP 127.0.0.1
[junit4] 2> 493135 INFO (TEST-TestSolrCloudWithSecureImpersonation.testProxyWrongHost-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testProxyWrongHost
[junit4] 2> 493168 INFO (TEST-TestSolrCloudWithSecureImpersonation.testForwarding-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testForwarding
[junit4] 2> 493197 INFO (TEST-TestSolrCloudWithSecureImpersonation.testForwarding-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 493198 INFO (zkConnectionManagerCallback-5764-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 493198 INFO (TEST-TestSolrCloudWithSecureImpersonation.testForwarding-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 493539 INFO (qtp1818216231-10092) [n:127.0.0.1:35093_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params pullReplicas=0&collection.configName=conf1&maxShardsPerNode=1&name=forwardingCollection&nrtReplicas=1&action=CREATE&numShards=1&tlogReplicas=0&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 493540 INFO (OverseerThreadFactory-5742-thread-1-processing-n:127.0.0.1:35093_solr) [n:127.0.0.1:35093_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection forwardingCollection
[junit4] 2> 493650 INFO (qtp1818216231-10097) [n:127.0.0.1:35093_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/key params={omitHeader=true&wt=json} status=0 QTime=0
[junit4] 2> 493651 INFO (qtp1818216231-10096) [ ] o.a.s.s.PKIAuthenticationPlugin New Key obtained from node: 127.0.0.1:35093_solr / MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAlvK174hVkN274A3x0V8PcC3DBD/BQGW8XiazUH1oNM46lTaUIBGKrRB/J5l1EsTwffEs4u7HjPuLXUqu4WImX84ljXADla0zHHatlxCws0GEzuKndoHHeJXFqoutW8uUrV9nwLzZbtvihQ8RJFJG8Y3Xh/wVN5VbW+bG3OohqnW05WYO5J4BSADL308ftGp+hlY4pcU95uCdIAJuBgGsqg7SSvvDXA2pEX7qqdEN8w15YvlR8W8m67eCbywyQFTSOOK50MMwrrwsmmr2jZIePzLEEFLOrVRUbrbeT/mwicB7Mhx3mj+DcE/qiP4ipCeiAPpbrnA6z/5/LAgTmYbgZwIDAQAB
[junit4] 2> 493652 INFO (qtp1818216231-10096) [n:127.0.0.1:35093_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 493652 INFO (qtp1818216231-10096) [n:127.0.0.1:35093_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 493656 INFO (qtp1818216231-10097) [n:127.0.0.1:35093_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/key params={omitHeader=true&wt=json} status=0 QTime=0
[junit4] 2> 493656 INFO (qtp1566919467-10088) [ ] o.a.s.s.PKIAuthenticationPlugin New Key obtained from node: 127.0.0.1:35093_solr / MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAlvK174hVkN274A3x0V8PcC3DBD/BQGW8XiazUH1oNM46lTaUIBGKrRB/J5l1EsTwffEs4u7HjPuLXUqu4WImX84ljXADla0zHHatlxCws0GEzuKndoHHeJXFqoutW8uUrV9nwLzZbtvihQ8RJFJG8Y3Xh/wVN5VbW+bG3OohqnW05WYO5J4BSADL308ftGp+hlY4pcU95uCdIAJuBgGsqg7SSvvDXA2pEX7qqdEN8w15YvlR8W8m67eCbywyQFTSOOK50MMwrrwsmmr2jZIePzLEEFLOrVRUbrbeT/mwicB7Mhx3mj+DcE/qiP4ipCeiAPpbrnA6z/5/LAgTmYbgZwIDAQAB
[junit4] 2> 493657 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 493662 INFO (qtp1818216231-10096) [n:127.0.0.1:35093_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 493666 INFO (qtp1566919467-10086) [n:127.0.0.1:45581_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 493670 INFO (OverseerStateUpdate-72097986913042439-127.0.0.1:35093_solr-n_0000000000) [n:127.0.0.1:35093_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"forwardingCollection",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"forwardingCollection_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:45581/solr",
[junit4] 2> "node_name":"127.0.0.1:45581_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 493876 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr x:forwardingCollection_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf1&newCollection=true&name=forwardingCollection_shard1_replica_n1&action=CREATE&numShards=1&collection=forwardingCollection&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 493895 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.6.0
[junit4] 2> 493934 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.s.IndexSchema Schema name=test
[junit4] 2> 494022 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 494056 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'forwardingCollection_shard1_replica_n1' using configuration from configset conf1, trusted=true
[junit4] 2> 494056 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45581.solr.core.forwardingCollection.shard1.replica_n1' (registry 'solr.core.forwardingCollection.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@22f271a0
[junit4] 2> 494056 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.c.SolrCore [[forwardingCollection_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestSolrCloudWithSecureImpersonation_2E0CA7DFC3EDEB86-001/tempDir-001/node2/./forwardingCollection_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestSolrCloudWithSecureImpersonation_2E0CA7DFC3EDEB86-001/tempDir-001/node2/./forwardingCollection_shard1_replica_n1/data/]
[junit4] 2> 494058 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=35, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=100.005859375, floorSegmentMB=2.1728515625, forceMergeDeletesPctAllowed=13.354102455822535, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5209625342800429, deletesPctAllowed=29.038502939056507
[junit4] 2> 494103 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 494104 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 494105 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 494105 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 494106 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=43, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.33002935722629]
[junit4] 2> 494107 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 494113 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 494130 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
[junit4] 2> 494130 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1667571259608662016
[junit4] 2> 494134 INFO (searcherExecutor-5766-thread-1-processing-n:127.0.0.1:45581_solr x:forwardingCollection_shard1_replica_n1 c:forwardingCollection s:shard1 r:core_node2) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 494135 INFO (searcherExecutor-5766-thread-1-processing-n:127.0.0.1:45581_solr x:forwardingCollection_shard1_replica_n1 c:forwardingCollection s:shard1 r:core_node2) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 494135 INFO (searcherExecutor-5766-thread-1-processing-n:127.0.0.1:45581_solr x:forwardingCollection_shard1_replica_n1 c:forwardingCollection s:shard1 r:core_node2) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 494135 INFO (searcherExecutor-5766-thread-1-processing-n:127.0.0.1:45581_solr x:forwardingCollection_shard1_replica_n1 c:forwardingCollection s:shard1 r:core_node2) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 494135 INFO (searcherExecutor-5766-thread-1-processing-n:127.0.0.1:45581_solr x:forwardingCollection_shard1_replica_n1 c:forwardingCollection s:shard1 r:core_node2) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 494136 INFO (searcherExecutor-5766-thread-1-processing-n:127.0.0.1:45581_solr x:forwardingCollection_shard1_replica_n1 c:forwardingCollection s:shard1 r:core_node2) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 494136 INFO (searcherExecutor-5766-thread-1-processing-n:127.0.0.1:45581_solr x:forwardingCollection_shard1_replica_n1 c:forwardingCollection s:shard1 r:core_node2) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 494136 INFO (searcherExecutor-5766-thread-1-processing-n:127.0.0.1:45581_solr x:forwardingCollection_shard1_replica_n1 c:forwardingCollection s:shard1 r:core_node2) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 494137 INFO (searcherExecutor-5766-thread-1-processing-n:127.0.0.1:45581_solr x:forwardingCollection_shard1_replica_n1 c:forwardingCollection s:shard1 r:core_node2) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 494137 INFO (searcherExecutor-5766-thread-1-processing-n:127.0.0.1:45581_solr x:forwardingCollection_shard1_replica_n1 c:forwardingCollection s:shard1 r:core_node2) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.c.SolrCore [forwardingCollection_shard1_replica_n1] Registered new searcher autowarm time: 0 ms: Collection: 'forwardingCollection'
[junit4] 2> 494137 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/forwardingCollection/terms/shard1 to Terms{values={core_node2=0}, version=0}
[junit4] 2> 494137 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/forwardingCollection/leaders/shard1
[junit4] 2> 494143 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 494143 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 494143 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:45581/solr/forwardingCollection_shard1_replica_n1/
[junit4] 2> 494143 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 494144 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.c.SyncStrategy http://127.0.0.1:45581/solr/forwardingCollection_shard1_replica_n1/ has no replicas
[junit4] 2> 494144 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/forwardingCollection/leaders/shard1/leader after winning as /collections/forwardingCollection/leader_elect/shard1/election/72097986913042440-core_node2-n_0000000000
[junit4] 2> 494145 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:45581/solr/forwardingCollection_shard1_replica_n1/ shard1
[junit4] 2> 494246 INFO (zkCallback-5743-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forwardingCollection/state.json] for collection [forwardingCollection] has occurred - updating... (live nodes size: [2])
[junit4] 2> 494246 INFO (zkCallback-5743-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forwardingCollection/state.json] for collection [forwardingCollection] has occurred - updating... (live nodes size: [2])
[junit4] 2> 494250 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr c:forwardingCollection s:shard1 r:core_node2 x:forwardingCollection_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 494251 INFO (qtp1566919467-10088) [n:127.0.0.1:45581_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf1&newCollection=true&name=forwardingCollection_shard1_replica_n1&action=CREATE&numShards=1&collection=forwardingCollection&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=375
[junit4] 2> 494252 INFO (qtp1818216231-10092) [n:127.0.0.1:35093_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 45 seconds. Check all shard replicas
[junit4] 2> 494352 INFO (zkCallback-5743-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forwardingCollection/state.json] for collection [forwardingCollection] has occurred - updating... (live nodes size: [2])
[junit4] 2> 494352 INFO (zkCallback-5734-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forwardingCollection/state.json] for collection [forwardingCollection] has occurred - updating... (live nodes size: [2])
[junit4] 2> 494352 INFO (zkCallback-5743-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forwardingCollection/state.json] for collection [forwardingCollection] has occurred - updating... (live nodes size: [2])
[junit4] 2> 494352 INFO (zkCallback-5743-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forwardingCollection/state.json] for collection [forwardingCollection] has occurred - updating... (live nodes size: [2])
[junit4] 2> 494352 INFO (qtp1818216231-10092) [n:127.0.0.1:35093_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={pullReplicas=0&collection.configName=conf1&maxShardsPerNode=1&name=forwardingCollection&nrtReplicas=1&action=CREATE&numShards=1&tlogReplicas=0&wt=javabin&version=2} status=0 QTime=813
[junit4] 2> 494352 INFO (TEST-TestSolrCloudWithSecureImpersonation.testForwarding-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.c.MiniSolrCloudCluster waitForActiveCollection: forwardingCollection
[junit4] 2> 494364 INFO (TEST-TestSolrCloudWithSecureImpersonation.testForwarding-seed#[2E0CA7DFC3EDEB86]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testForwarding
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestSolrCloudWithSecureImpersonation -Dtests.method=testForwarding -Dtests.seed=2E0CA7DFC3EDEB86 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=nl-BQ -Dtests.timezone=Etc/GMT0 -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 1.23s J0 | TestSolrCloudWithSecureImpersonation.testForwarding <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:45581/solr/forwardingCollection: Expected mime type application/octet-stream but got text/html. <html>
[junit4] > <head>
[junit4] > <meta http-equiv="Content-Type" content="text/html;charset=utf-8"/>
[junit4] > <title>Error 401 Authentication required</title>
[junit4] > </head>
[junit4] > <body><h2>HTTP ERROR 401 Authentication required</h2>
[junit4] > <table>
[junit4] > <tr><th>URI:</th><td>/solr/forwardingCollection/select</td></tr>
[junit4] > <tr><th>STATUS:</th><td>401</td></tr>
[junit4] > <tr><th>MESSAGE:</th><td>Authentication required</td></tr>
[junit4] > <tr><th>SERVLET:</th><td>org.apache.solr.client.solrj.embedded.JettySolrRunner$Servlet404-655489a7</td></tr>
[junit4] > </table>
[junit4] > <hr><a href="http://eclipse.org/jetty">Powered by Jetty:// 9.4.27.v20200227</a><hr/>
[junit4] > </body>
[junit4] > </html>
[junit4] > at __randomizedtesting.SeedInfo.seed([2E0CA7DFC3EDEB86:CF8ACE21DEDB0D6F]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:628)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:265)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:248)
[junit4] > at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:211)
[junit4] > at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:1003)
[junit4] > at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:1018)
[junit4] > at org.apache.solr.cloud.TestSolrCloudWithSecureImpersonation.testForwarding(TestSolrCloudWithSecureImpersonation.java:328)
[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:567)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:830)
[junit4] 2> 494466 INFO (jetty-closer-5771-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=143227446
[junit4] 2> 494467 INFO (jetty-closer-5771-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:45581_solr
[junit4] 2> 494468 INFO (jetty-closer-5771-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1929301752
[junit4] 2> 494468 INFO (jetty-closer-5771-thread-2) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:35093_solr
[junit4] 2> 494470 INFO (jetty-closer-5771-thread-1) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 494470 INFO (jetty-closer-5771-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:45581_solr as DOWN
[junit4] 2> 494470 INFO (jetty-closer-5771-thread-2) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 494470 INFO (jetty-closer-5771-thread-2) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:35093_solr as DOWN
[junit4] 2> 494471 INFO (coreCloseExecutor-5779-thread-1) [n:127.0.0.1:45581_solr ] o.a.s.c.SolrCore [forwardingCollection_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@5b4d0ab2
[junit4] 2> 494471 INFO (coreCloseExecutor-5779-thread-1) [n:127.0.0.1:45581_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.forwardingCollection.shard1.replica_n1 tag=SolrCore@5b4d0ab2
[junit4] 2> 494471 INFO (coreCloseExecutor-5779-thread-1) [n:127.0.0.1:45581_solr ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@23ca266a: rootName = solr_45581, domain = solr.core.forwardingCollection.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.forwardingCollection.shard1.replica_n1/com.codahale.metrics.MetricRegistry@6a2660ee
[junit4] 2> 494471 INFO (jetty-closer-5771-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node tag=null
[junit4] 2> 494471 INFO (jetty-closer-5771-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4f8909d3: rootName = solr_35093, domain = solr.node, service url = null, agent id = null] for registry solr.node/com.codahale.metrics.MetricRegistry@31135025
[junit4] 2> 494475 INFO (jetty-closer-5771-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm tag=null
[junit4] 2> 494475 INFO (jetty-closer-5771-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@b59c5af: rootName = solr_35093, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm/com.codahale.metrics.MetricRegistry@21585de0
[junit4] 2> 494476 INFO (jetty-closer-5771-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty tag=null
[junit4] 2> 494476 INFO (jetty-closer-5771-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2c24a743: rootName = solr_35093, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty/com.codahale.metrics.MetricRegistry@12c33d24
[junit4] 2> 494477 INFO (jetty-closer-5771-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster tag=null
[junit4] 2> 494477 INFO (closeThreadPool-5780-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72097986913042439-127.0.0.1:35093_solr-n_0000000000) closing
[junit4] 2> 494478 INFO (OverseerStateUpdate-72097986913042439-127.0.0.1:35093_solr-n_0000000000) [n:127.0.0.1:35093_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:35093_solr
[junit4] 2> 494478 INFO (OverseerAutoScalingTriggerThread-72097986913042439-127.0.0.1:35093_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 494484 INFO (coreCloseExecutor-5779-thread-1) [n:127.0.0.1:45581_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.forwardingCollection.shard1.leader tag=SolrCore@5b4d0ab2
[junit4] 2> 494485 INFO (coreCloseExecutor-5779-thread-1) [n:127.0.0.1:45581_solr ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() ... SKIPPED (unnecessary).
[junit4] 2> 494489 INFO (zkCallback-5743-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 494491 INFO (jetty-closer-5771-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node tag=null
[junit4] 2> 494491 INFO (closeThreadPool-5780-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72097986913042439-127.0.0.1:35093_solr-n_0000000000) closing
[junit4] 2> 494491 INFO (jetty-closer-5771-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2f49179d: rootName = solr_45581, domain = solr.node, service url = null, agent id = null] for registry solr.node/com.codahale.metrics.MetricRegistry@1044e903
[junit4] 2> 494494 INFO (jetty-closer-5771-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm tag=null
[junit4] 2> 494494 INFO (jetty-closer-5771-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@be54481: rootName = solr_45581, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm/com.codahale.metrics.MetricRegistry@21585de0
[junit4] 2> 494495 INFO (jetty-closer-5771-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty tag=null
[junit4] 2> 494495 INFO (jetty-closer-5771-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@9df6ae0: rootName = solr_45581, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty/com.codahale.metrics.MetricRegistry@12c33d24
[junit4] 2> 494495 INFO (jetty-closer-5771-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster tag=null
[junit4] 2> 494589 INFO (jetty-closer-5771-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72097986913042439-127.0.0.1:35093_solr-n_0000000000) closing
[junit4] 2> 494589 ERROR (Thread[Thread-1892,5,TGRP-TestSolrCloudWithSecureImpersonation]) [ ] o.a.h.s.t.d.AbstractDelegationTokenSecretManager ExpiredTokenRemover received java.lang.InterruptedException: sleep interrupted
[junit4] 2> 494591 INFO (Curator-Framework-0) [ ] o.a.c.f.i.CuratorFrameworkImpl backgroundOperationsLoop exiting
[junit4] 2> 494689 ERROR (Thread[Thread-1891,5,TGRP-TestSolrCloudWithSecureImpersonation]) [ ] o.a.h.s.t.d.AbstractDelegationTokenSecretManager ExpiredTokenRemover received java.lang.InterruptedException: sleep interrupted
[junit4] 2> 494689 INFO (Curator-Framework-0) [ ] o.a.c.f.i.CuratorFrameworkImpl backgroundOperationsLoop exiting
[junit4] 2> 494791 INFO (jetty-closer-5771-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@629834dc{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:0}
[junit4] 2> 494791 INFO (jetty-closer-5771-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@99f6fab{/solr,null,UNAVAILABLE}
[junit4] 2> 494791 INFO (jetty-closer-5771-thread-2) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 494890 INFO (jetty-closer-5771-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@53a2aef7{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:0}
[junit4] 2> 494890 INFO (jetty-closer-5771-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7b56f0bf{/solr,null,UNAVAILABLE}
[junit4] 2> 494891 INFO (jetty-closer-5771-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 494892 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 495094 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2> 2 /solr/packages.json
[junit4] 2> 2 /solr/security.json
[junit4] 2> 2 /solr/collections/forwardingCollection/terms/shard1
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 12 /solr/collections/forwardingCollection/state.json
[junit4] 2> 11 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMKeyIdRoot
[junit4] 2> 4 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoot/DK_1
[junit4] 2> 4 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoot/DK_2
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoot/DK_3
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoot/DK_4
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMSeqNumRoot
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 14 /solr/overseer/queue
[junit4] 2> 10 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMMasterKeyRoot
[junit4] 2> 7 /solr/live_nodes
[junit4] 2> 6 /solr/collections
[junit4] 2> 4 /solr/overseer/collection-queue-work
[junit4] 2> 2 /solr/security/zkdtsm/ZKDTSMRoot/ZKDTSMTokensRoot
[junit4] 2>
[junit4] 2> 495096 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:37633
[junit4] 2> 495096 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:37633
[junit4] 2> 495096 INFO (SUITE-TestSolrCloudWithSecureImpersonation-seed#[2E0CA7DFC3EDEB86]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 37633
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestSolrCloudWithSecureImpersonation_2E0CA7DFC3EDEB86-001
[junit4] 2> May 24, 2020 11:31:22 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(Lucene86): {}, docValues:{}, maxPointsInLeafNode=1511, maxMBSortInHeap=5.089914605988335, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@2b4a7c7d), locale=nl-BQ, timezone=Etc/GMT0
[junit4] 2> NOTE: Linux 5.3.0-51-generic amd64/AdoptOpenJDK 13.0.2 (64-bit)/cpus=16,threads=1,free=112998784,total=526385152
[junit4] 2> NOTE: All tests run in this JVM: [ReplaceNodeNoTargetTest, CleanupOldIndexTest, TestAuthenticationFramework, TestMaxTokenLenTokenizer, BitVectorTest, BasicZkTest, RangeFacetCloudTest, TestInPlaceUpdatesStandalone, CategoryRoutedAliasUpdateProcessorTest, TestDownShardTolerantSearch, NoCacheHeaderTest, DeleteStatusTest, TestHalfAndHalfDocValues, TestBinaryField, NumericFieldsTest, SplitHandlerTest, TestSolrCoreParser, PluginInfoTest, CustomCollectionTest, DistributedFacetPivotLongTailTest, InfixSuggestersTest, TestLFUCache, TestFieldCollectionResource, TestManagedSynonymGraphFilterFactory, TestSolrCoreProperties, HighlighterMaxOffsetTest, SolrMetricsIntegrationTest, WordBreakSolrSpellCheckerTest, TestRealTimeGet, JWTAuthPluginIntegrationTest, HttpPartitionWithTlogReplicasTest, SearchHandlerTest, TestCaffeineCache, TestConfigSetsAPIExclusivity, TestTermsQParserPlugin, IndexBasedSpellCheckerTest, TestSearcherReuse, AddBlockUpdateTest, SparseHLLTest, TestSQLHandlerNonCloud, TestSimNodeAddedTrigger, AnalysisAfterCoreReloadTest, CollectionReloadTest, MaxSizeAutoCommitTest, TestFieldCacheVsDocValues, TestNRTOpen, AutoAddReplicasPlanActionTest, TestQueryingOnDownCollection, NodeAddedTriggerTest, HdfsSyncSliceTest, TestGroupingSearch, OverseerRolesTest, SearchHandlerTest, BlockJoinFacetDistribTest, TestSegmentSorting, TestDocSet, TestCrossCoreJoin, MetricsHistoryHandlerTest, TestWriterPerf, TestSolrConfigHandler, TestLRUStatsCache, ReturnFieldsTest, SolrCoreCheckLockOnStartupTest, TestImplicitCoreProperties, TestCharFilters, SimpleMLTQParserTest, TestClusterStateMutator, UpdateParamsTest, ScheduledTriggerIntegrationTest, TestLogWatcher, TestPhraseSuggestions, ActionThrottleTest, TestSolrCloudWithSecureImpersonation]
[junit4] Completed [390/910 (1!)] on J0 in 4.01s, 12 tests, 1 error <<< FAILURES!
[...truncated 49619 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Linux/3174/consoleText
[repro] Revision: 5e7be63ca7fbd234526fceb2d7a0594a54f90670
[repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UseParallelGC"
[repro] Repro line: ant test -Dtestcase=TestSolrCloudWithSecureImpersonation -Dtests.method=testForwarding -Dtests.seed=2E0CA7DFC3EDEB86 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=nl-BQ -Dtests.timezone=Etc/GMT0 -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[repro] JUnit rest result XML files will be moved to: ./repro-reports
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] TestSolrCloudWithSecureImpersonation
[repro] ant compile-test
[...truncated 3464 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.TestSolrCloudWithSecureImpersonation" -Dtests.showOutput=onerror "-Dargs=-XX:-UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=2E0CA7DFC3EDEB86 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=nl-BQ -Dtests.timezone=Etc/GMT0 -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 136 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.cloud.TestSolrCloudWithSecureImpersonation
[repro] Exiting with code 0
[...truncated 43 lines...]