You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2019/05/07 17:09:24 UTC
[JENKINS] Lucene-Solr-Tests-8.1 - Build # 42 - Unstable
Build: https://builds.apache.org/job/Lucene-Solr-Tests-8.1/42/
2 tests failed.
FAILED: org.apache.solr.security.JWTAuthPluginIntegrationTest.createCollectionUpdateAndQueryDistributed
Error Message:
Expected metric minimums for prefix SECURITY./authentication/pki.: {failMissingCredentials=0, authenticated=12, passThrough=0, failWrongCredentials=0, requests=12, errors=0}, but got: {failMissingCredentials=0, authenticated=4, passThrough=0, totalTime=18761268, failWrongCredentials=0, requestTimes=352, requests=4, errors=0}
Stack Trace:
java.lang.AssertionError: Expected metric minimums for prefix SECURITY./authentication/pki.: {failMissingCredentials=0, authenticated=12, passThrough=0, failWrongCredentials=0, requests=12, errors=0}, but got: {failMissingCredentials=0, authenticated=4, passThrough=0, totalTime=18761268, failWrongCredentials=0, requestTimes=352, requests=4, errors=0}
at __randomizedtesting.SeedInfo.seed([D251F4D3C6FA0825:D479F6BDA44D9E96]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.solr.cloud.SolrCloudAuthTestCase.assertAuthMetricsMinimums(SolrCloudAuthTestCase.java:129)
at org.apache.solr.cloud.SolrCloudAuthTestCase.assertPkiAuthMetricsMinimums(SolrCloudAuthTestCase.java:74)
at org.apache.solr.security.JWTAuthPluginIntegrationTest.createCollectionUpdateAndQueryDistributed(JWTAuthPluginIntegrationTest.java:173)
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)
FAILED: org.apache.solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin.testBasics
Error Message:
Expected metric minimums for prefix SECURITY./authentication.: {failMissingCredentials=0, authenticated=8, passThrough=0, failWrongCredentials=8, requests=16, errors=0}, but got: {failMissingCredentials=0, authenticated=8, passThrough=0, totalTime=579767495, failWrongCredentials=6, requestTimes=1521, requests=14, errors=0}
Stack Trace:
java.lang.AssertionError: Expected metric minimums for prefix SECURITY./authentication.: {failMissingCredentials=0, authenticated=8, passThrough=0, failWrongCredentials=8, requests=16, errors=0}, but got: {failMissingCredentials=0, authenticated=8, passThrough=0, totalTime=579767495, failWrongCredentials=6, requestTimes=1521, requests=14, errors=0}
at __randomizedtesting.SeedInfo.seed([D251F4D3C6FA0825:EF895AFFFE145655]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.solr.cloud.SolrCloudAuthTestCase.assertAuthMetricsMinimums(SolrCloudAuthTestCase.java:129)
at org.apache.solr.cloud.SolrCloudAuthTestCase.assertAuthMetricsMinimums(SolrCloudAuthTestCase.java:83)
at org.apache.solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin.testCollectionCreateSearchDelete(TestSolrCloudWithHadoopAuthPlugin.java:139)
at org.apache.solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin.testBasics(TestSolrCloudWithHadoopAuthPlugin.java:108)
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 13255 lines...]
[junit4] Suite: org.apache.solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin
[junit4] 2> 851548 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/init-core-data-001
[junit4] 2> 851561 WARN (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=2 numCloses=2
[junit4] 2> 851561 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 851562 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 853462 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-002
[junit4] 2> 853462 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 853467 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 853467 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 853564 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:39325
[junit4] 2> 853564 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:39325
[junit4] 2> 853564 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 39325
[junit4] 2> 853636 WARN (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
[junit4] 2> 853715 WARN (zkConnectionManagerCallback-1476-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@38e00e56 name: ZooKeeperConnection Watcher:127.0.0.1:39325 got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
[junit4] 2> 853715 WARN (zkConnectionManagerCallback-1476-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
[junit4] 2> 853724 INFO (zkConnectionManagerCallback-1476-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 853748 WARN (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
[junit4] 2> 853764 WARN (zkConnectionManagerCallback-1478-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@55bcbfb name: ZooKeeperConnection Watcher:127.0.0.1:39325/solr got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
[junit4] 2> 853764 WARN (zkConnectionManagerCallback-1478-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
[junit4] 2> 853784 INFO (zkConnectionManagerCallback-1478-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 853785 WARN (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
[junit4] 2> 853800 WARN (zkConnectionManagerCallback-1480-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1cd36c29 name: ZooKeeperConnection Watcher:127.0.0.1:39325 got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
[junit4] 2> 853800 WARN (zkConnectionManagerCallback-1480-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
[junit4] 2> 853801 INFO (zkConnectionManagerCallback-1480-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 853818 WARN (jetty-launcher-1481-thread-1) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
[junit4] 2> 853819 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
[junit4] 2> 853819 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 853819 INFO (jetty-launcher-1481-thread-1) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
[junit4] 2> 853857 INFO (jetty-launcher-1481-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 853857 INFO (jetty-launcher-1481-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 853857 INFO (jetty-launcher-1481-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 853860 INFO (jetty-launcher-1481-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2373f6d2{/solr,null,AVAILABLE}
[junit4] 2> 853864 INFO (jetty-launcher-1481-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@21797c98{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:36456}
[junit4] 2> 853864 INFO (jetty-launcher-1481-thread-1) [ ] o.e.j.s.Server Started @854259ms
[junit4] 2> 853864 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36456}
[junit4] 2> 853865 ERROR (jetty-launcher-1481-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 853865 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 853865 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.1.0
[junit4] 2> 853865 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 853865 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 853901 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-05-07T15:09:12.331Z
[junit4] 2> 853954 WARN (jetty-launcher-1481-thread-1-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
[junit4] 2> 853970 WARN (zkConnectionManagerCallback-1483-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@10ba3824 name: ZooKeeperConnection Watcher:127.0.0.1:39325/solr got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
[junit4] 2> 853970 WARN (zkConnectionManagerCallback-1483-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
[junit4] 2> 853970 INFO (zkConnectionManagerCallback-1483-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 853975 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 854540 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 854555 WARN (jetty-launcher-1481-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@4be5c573[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 854575 WARN (jetty-launcher-1481-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@154bf116[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 854576 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:39325/solr
[junit4] 2> 854576 WARN (jetty-launcher-1481-thread-1-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
[junit4] 2> 854577 WARN (zkConnectionManagerCallback-1490-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@74da40c9 name: ZooKeeperConnection Watcher:127.0.0.1:39325 got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
[junit4] 2> 854577 WARN (zkConnectionManagerCallback-1490-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
[junit4] 2> 854591 INFO (zkConnectionManagerCallback-1490-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 854592 WARN (jetty-launcher-1481-thread-1-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
[junit4] 2> 854659 WARN (zkConnectionManagerCallback-1492-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2b200736 name: ZooKeeperConnection Watcher:127.0.0.1:39325/solr got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
[junit4] 2> 854659 WARN (zkConnectionManagerCallback-1492-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
[junit4] 2> 854659 INFO (zkConnectionManagerCallback-1492-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 855397 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:36456_solr
[junit4] 2> 855450 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.Overseer Overseer (id=74651453398122501-127.0.0.1:36456_solr-n_0000000000) starting
[junit4] 2> 855538 WARN (jetty-launcher-1481-thread-1-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
[junit4] 2> 855558 WARN (zkConnectionManagerCallback-1499-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@70ed8ca8 name: ZooKeeperConnection Watcher:127.0.0.1:39325/solr got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
[junit4] 2> 855559 WARN (zkConnectionManagerCallback-1499-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
[junit4] 2> 855559 INFO (zkConnectionManagerCallback-1499-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 855576 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:39325/solr ready
[junit4] 2> 855577 INFO (OverseerStateUpdate-74651453398122501-127.0.0.1:36456_solr-n_0000000000) [n:127.0.0.1:36456_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:36456_solr
[junit4] 2> 855577 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36456_solr
[junit4] 2> 855592 INFO (OverseerStateUpdate-74651453398122501-127.0.0.1:36456_solr-n_0000000000) [n:127.0.0.1:36456_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 855593 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: org.apache.solr.security.ConfigurableInternodeAuthHadoopPlugin
[junit4] 2> 855754 INFO (zkCallback-1498-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 855756 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.s.i.Krb5HttpClientBuilder Setting up SPNego auth with config: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf
[junit4] 2> 855773 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.s.HadoopAuthPlugin Params: {kerberos.principal=HTTP/127.0.0.1, kerberos.keytab=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/keytabs, type=kerberos, kerberos.name.rules=RULE:[1:$1@$0](.*EXAMPLE.COM)s/@.*//
[junit4] 2> RULE:[2:$2@$0](.*EXAMPLE.COM)s/@.*//
[junit4] 2> DEFAULT, delegation-token.json-mapper.AUTO_CLOSE_TARGET=false}
[junit4] 2> 856013 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.s.i.Krb5HttpClientBuilder Setting up SPNego auth with config: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf
[junit4] 2> 856110 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 856262 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36456.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d3ec300
[junit4] 2> 856296 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36456.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d3ec300
[junit4] 2> 856296 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36456.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d3ec300
[junit4] 2> 856297 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-002/node1/.
[junit4] 2> 856401 WARN (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
[junit4] 2> 856402 WARN (zkConnectionManagerCallback-1505-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@137ad575 name: ZooKeeperConnection Watcher:127.0.0.1:39325/solr got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
[junit4] 2> 856402 WARN (zkConnectionManagerCallback-1505-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
[junit4] 2> 856402 INFO (zkConnectionManagerCallback-1505-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 856417 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 856418 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:39325/solr ready
[junit4] 2> 856506 INFO (TEST-TestSolrCloudWithHadoopAuthPlugin.testBasics-seed#[D251F4D3C6FA0825]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBasics
[junit4] 1> Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt false ticketCache is null isInitiator true KeyTab is /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/keytabs refreshKrb5Config is true principal is solr tryFirstPass is false useFirstPass is false storePass is false clearPass is false
[junit4] 1> Refreshing Kerberos configuration
[junit4] 2> 857098 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.KdcRequest The preauth data is empty.
[junit4] 2> 857137 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.KdcHandler KRB error occurred while processing request:Additional pre-authentication required
[junit4] 2> 857295 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.AsRequest AS_REQ ISSUE: authtime 1557241755722,solr@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM
[junit4] 1> principal is solr@EXAMPLE.COM
[junit4] 1> Will use keytab
[junit4] 1> Commit Succeeded
[junit4] 1>
[junit4] 2> 857591 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.TgsRequest TGS_REQ ISSUE: authtime 1557241755988,solr for HTTP/127.0.0.1@EXAMPLE.COM
[junit4] 2> 857743 INFO (qtp722099044-4908) [n:127.0.0.1:36456_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf1&name=testkerberoscollection&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 857795 INFO (OverseerThreadFactory-1875-thread-1-processing-n:127.0.0.1:36456_solr) [n:127.0.0.1:36456_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection testkerberoscollection
[junit4] 1> Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt false ticketCache is null isInitiator true KeyTab is /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/keytabs refreshKrb5Config is true principal is solr tryFirstPass is false useFirstPass is false storePass is false clearPass is false
[junit4] 1> Refreshing Kerberos configuration
[junit4] 2> 858026 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.KdcRequest The preauth data is empty.
[junit4] 2> 858026 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.KdcHandler KRB error occurred while processing request:Additional pre-authentication required
[junit4] 2> 858269 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.AsRequest AS_REQ ISSUE: authtime 1557241756590,solr@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM
[junit4] 1> principal is solr@EXAMPLE.COM
[junit4] 1> Will use keytab
[junit4] 1> Commit Succeeded
[junit4] 1>
[junit4] 2> 858417 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.TgsRequest TGS_REQ ISSUE: authtime 1557241756846,solr for HTTP/127.0.0.1@EXAMPLE.COM
[junit4] 2> 858711 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
[junit4] 2> 858741 INFO (OverseerStateUpdate-74651453398122501-127.0.0.1:36456_solr-n_0000000000) [n:127.0.0.1:36456_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testkerberoscollection",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testkerberoscollection_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:36456/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 1> Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt false ticketCache is null isInitiator true KeyTab is /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/keytabs refreshKrb5Config is true principal is solr tryFirstPass is false useFirstPass is false storePass is false clearPass is false
[junit4] 1> Refreshing Kerberos configuration
[junit4] 2> 858977 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.KdcRequest The preauth data is empty.
[junit4] 2> 858978 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.KdcHandler KRB error occurred while processing request:Additional pre-authentication required
[junit4] 2> 859018 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.AsRequest AS_REQ ISSUE: authtime 1557241757448,solr@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM
[junit4] 1> principal is solr@EXAMPLE.COM
[junit4] 1> Will use keytab
[junit4] 1> Commit Succeeded
[junit4] 1>
[junit4] 2> 859087 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.TgsRequest TGS_REQ ISSUE: authtime 1557241757517,solr for HTTP/127.0.0.1@EXAMPLE.COM
[junit4] 2> 859160 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf1&newCollection=true&name=testkerberoscollection_shard1_replica_n1&action=CREATE&numShards=1&collection=testkerberoscollection&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 859160 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 860214 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.1.0
[junit4] 2> 860251 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.s.IndexSchema [testkerberoscollection_shard1_replica_n1] Schema name=minimal
[junit4] 2> 860262 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 860262 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'testkerberoscollection_shard1_replica_n1' using configuration from collection testkerberoscollection, trusted=true
[junit4] 2> 860264 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36456.solr.core.testkerberoscollection.shard1.replica_n1' (registry 'solr.core.testkerberoscollection.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d3ec300
[junit4] 2> 860264 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SolrCore [[testkerberoscollection_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-002/node1/testkerberoscollection_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-002/node1/./testkerberoscollection_shard1_replica_n1/data/]
[junit4] 2> 860480 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 860480 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 860481 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 860481 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 860482 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3b478112[testkerberoscollection_shard1_replica_n1] main]
[junit4] 2> 860509 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 860509 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 860509 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 860510 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1632886334622269440
[junit4] 2> 860531 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testkerberoscollection/terms/shard1 to Terms{values={core_node2=0}, version=0}
[junit4] 2> 860531 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testkerberoscollection/leaders/shard1
[junit4] 2> 860537 INFO (searcherExecutor-1880-thread-1-processing-n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1 c:testkerberoscollection s:shard1 r:core_node2) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SolrCore [testkerberoscollection_shard1_replica_n1] Registered new searcher Searcher@3b478112[testkerberoscollection_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 860568 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 860568 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 860568 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:36456/solr/testkerberoscollection_shard1_replica_n1/
[junit4] 2> 860568 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 860568 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:36456/solr/testkerberoscollection_shard1_replica_n1/ has no replicas
[junit4] 2> 860568 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/testkerberoscollection/leaders/shard1/leader after winning as /collections/testkerberoscollection/leader_elect/shard1/election/74651453398122501-core_node2-n_0000000000
[junit4] 2> 860582 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:36456/solr/testkerberoscollection_shard1_replica_n1/ shard1
[junit4] 2> 860743 INFO (zkCallback-1491-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 860744 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 860746 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf1&newCollection=true&name=testkerberoscollection_shard1_replica_n1&action=CREATE&numShards=1&collection=testkerberoscollection&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1586
[junit4] 2> 860791 INFO (zkCallback-1491-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 860858 INFO (qtp722099044-4908) [n:127.0.0.1:36456_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> 860966 INFO (zkCallback-1491-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 860966 INFO (zkCallback-1491-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 860967 INFO (qtp722099044-4908) [n:127.0.0.1:36456_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf1&name=testkerberoscollection&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=3223
[junit4] 2> 860974 INFO (zkCallback-1491-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
[junit4] 1> Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt false ticketCache is null isInitiator true KeyTab is /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/keytabs refreshKrb5Config is true principal is solr tryFirstPass is false useFirstPass is false storePass is false clearPass is false
[junit4] 1> Refreshing Kerberos configuration
[junit4] 2> 861121 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.KdcRequest The preauth data is empty.
[junit4] 2> 861122 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.KdcHandler KRB error occurred while processing request:Additional pre-authentication required
[junit4] 1> principal is solr@EXAMPLE.COM
[junit4] 1> Will use keytab
[junit4] 1> Commit Succeeded
[junit4] 1>
[junit4] 2> 861158 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.AsRequest AS_REQ ISSUE: authtime 1557241759587,solr@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM
[junit4] 2> 861223 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.TgsRequest TGS_REQ ISSUE: authtime 1557241759653,solr for HTTP/127.0.0.1@EXAMPLE.COM
[junit4] 2> 861541 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testkerberoscollection/terms/shard1 to Terms{values={core_node2=1}, version=1}
[junit4] 2> 861541 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [testkerberoscollection_shard1_replica_n1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1 (1632886335510413312)]} 0 183
[junit4] 1> Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt false ticketCache is null isInitiator true KeyTab is /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/keytabs refreshKrb5Config is true principal is solr tryFirstPass is false useFirstPass is false storePass is false clearPass is false
[junit4] 1> Refreshing Kerberos configuration
[junit4] 2> 861612 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.KdcRequest The preauth data is empty.
[junit4] 2> 861612 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.KdcHandler KRB error occurred while processing request:Additional pre-authentication required
[junit4] 2> 861721 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.AsRequest AS_REQ ISSUE: authtime 1557241760151,solr@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM
[junit4] 1> principal is solr@EXAMPLE.COM
[junit4] 1> Will use keytab
[junit4] 1> Commit Succeeded
[junit4] 1>
[junit4] 2> 861795 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.TgsRequest TGS_REQ ISSUE: authtime 1557241760224,solr for HTTP/127.0.0.1@EXAMPLE.COM
[junit4] 2> 861974 INFO (OverseerCollectionConfigSetProcessor-74651453398122501-127.0.0.1:36456_solr-n_0000000000) [n:127.0.0.1:36456_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 862052 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1632886336239173632,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 862052 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@4afe318f commitCommandVersion:1632886336239173632
[junit4] 2> 862054 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@28f166d[testkerberoscollection_shard1_replica_n1] main]
[junit4] 2> 862064 INFO (searcherExecutor-1880-thread-1-processing-n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1 c:testkerberoscollection s:shard1 r:core_node2) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SolrCore [testkerberoscollection_shard1_replica_n1] Registered new searcher Searcher@28f166d[testkerberoscollection_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.1.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.1.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1557241760483}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 862065 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 862065 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [testkerberoscollection_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=testkerberoscollection:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 50
[junit4] 2> 862293 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.S.Request [testkerberoscollection_shard1_replica_n1] webapp=/solr path=/select params={q=*:*&_stateVer_=testkerberoscollection:4&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4] 2> 862307 INFO (qtp722099044-4908) [n:127.0.0.1:36456_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=testkerberoscollection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 862412 INFO (OverseerThreadFactory-1875-thread-2-processing-n:127.0.0.1:36456_solr) [n:127.0.0.1:36456_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler Executing Collection Cmd=action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true&deleteMetricsHistory=true, asyncId=null
[junit4] 1> Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt false ticketCache is null isInitiator true KeyTab is /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/keytabs refreshKrb5Config is true principal is solr tryFirstPass is false useFirstPass is false storePass is false clearPass is false
[junit4] 1> Refreshing Kerberos configuration
[junit4] 2> 862430 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.KdcRequest The preauth data is empty.
[junit4] 2> 862431 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.KdcHandler KRB error occurred while processing request:Additional pre-authentication required
[junit4] 2> 862528 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.AsRequest AS_REQ ISSUE: authtime 1557241760957,solr@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM
[junit4] 1> principal is solr@EXAMPLE.COM
[junit4] 1> Will use keytab
[junit4] 1> Commit Succeeded
[junit4] 1>
[junit4] 2> 862622 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.TgsRequest TGS_REQ ISSUE: authtime 1557241761051,solr for HTTP/127.0.0.1@EXAMPLE.COM
[junit4] 2> 862724 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.testkerberoscollection.shard1.replica_n1, tag=null
[junit4] 2> 862740 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@19afa9f2: rootName = solr_36456, domain = solr.core.testkerberoscollection.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.testkerberoscollection.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@1d910d7
[junit4] 2> 862852 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SolrCore [testkerberoscollection_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@3b20424a
[junit4] 2> 862852 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.testkerberoscollection.shard1.replica_n1, tag=3b20424a
[junit4] 2> 862852 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.testkerberoscollection.shard1.leader, tag=3b20424a
[junit4] 2> 862908 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testkerberoscollection/terms/shard1 to Terms{values={}, version=2}
[junit4] 2> 862940 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&deleteMetricsHistory=true&core=testkerberoscollection_shard1_replica_n1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=217
[junit4] 2> 863012 INFO (zkCallback-1491-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 863012 INFO (zkCallback-1491-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 863015 INFO (zkCallback-1491-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 863138 INFO (zkCallback-1491-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 863138 INFO (zkCallback-1491-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 863138 INFO (zkCallback-1491-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 863182 INFO (qtp722099044-4908) [n:127.0.0.1:36456_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=testkerberoscollection&action=DELETE&wt=javabin&version=2} status=0 QTime=874
[junit4] 2> 863198 INFO (TEST-TestSolrCloudWithHadoopAuthPlugin.testBasics-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for collection to disappear - collection: testkerberoscollection failOnTimeout:true timeout (sec):330
[junit4] 2> 863206 INFO (TEST-TestSolrCloudWithHadoopAuthPlugin.testBasics-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.AbstractDistribZkTestBase Collection has disappeared - collection: testkerberoscollection
[junit4] 2> 863206 INFO (TEST-TestSolrCloudWithHadoopAuthPlugin.testBasics-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.SolrCloudAuthTestCase First metrics count assert failed, pausing 2s before re-attempt
[junit4] 2> 864413 INFO (OverseerCollectionConfigSetProcessor-74651453398122501-127.0.0.1:36456_solr-n_0000000000) [n:127.0.0.1:36456_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 865220 INFO (TEST-TestSolrCloudWithHadoopAuthPlugin.testBasics-seed#[D251F4D3C6FA0825]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testBasics
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestSolrCloudWithHadoopAuthPlugin -Dtests.method=testBasics -Dtests.seed=D251F4D3C6FA0825 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=ru-RU -Dtests.timezone=Asia/Qyzylorda -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 8.79s J1 | TestSolrCloudWithHadoopAuthPlugin.testBasics <<<
[junit4] > Throwable #1: java.lang.AssertionError: Expected metric minimums for prefix SECURITY./authentication.: {failMissingCredentials=0, authenticated=8, passThrough=0, failWrongCredentials=8, requests=16, errors=0}, but got: {failMissingCredentials=0, authenticated=8, passThrough=0, totalTime=579767495, failWrongCredentials=6, requestTimes=1521, requests=14, errors=0}
[junit4] > at __randomizedtesting.SeedInfo.seed([D251F4D3C6FA0825:EF895AFFFE145655]:0)
[junit4] > at org.apache.solr.cloud.SolrCloudAuthTestCase.assertAuthMetricsMinimums(SolrCloudAuthTestCase.java:129)
[junit4] > at org.apache.solr.cloud.SolrCloudAuthTestCase.assertAuthMetricsMinimums(SolrCloudAuthTestCase.java:83)
[junit4] > at org.apache.solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin.testCollectionCreateSearchDelete(TestSolrCloudWithHadoopAuthPlugin.java:139)
[junit4] > at org.apache.solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin.testBasics(TestSolrCloudWithHadoopAuthPlugin.java:108)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 865223 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.k.k.k.s.i.DefaultInternalKdcServerImpl Default Internal kdc server stopped.
[junit4] 2> 866257 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=721276841
[junit4] 2> 866257 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:36456_solr
[junit4] 2> 866272 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 866273 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:36456_solr as DOWN
[junit4] 2> 866402 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 866402 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@14ced5e5: rootName = solr_36456, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@5bd478de
[junit4] 2> 866405 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 866405 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1185f71c: rootName = solr_36456, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@375c45ab
[junit4] 2> 866440 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 866440 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@69436321: rootName = solr_36456, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@7158613a
[junit4] 2> 866440 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 866459 INFO (closeThreadPool-1511-thread-2) [ ] o.a.s.c.Overseer Overseer (id=74651453398122501-127.0.0.1:36456_solr-n_0000000000) closing
[junit4] 2> 866511 INFO (OverseerStateUpdate-74651453398122501-127.0.0.1:36456_solr-n_0000000000) [n:127.0.0.1:36456_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:36456_solr
[junit4] 2> 866527 INFO (OverseerAutoScalingTriggerThread-74651453398122501-127.0.0.1:36456_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 866533 INFO (closeThreadPool-1511-thread-1) [ ] o.a.s.c.Overseer Overseer (id=74651453398122501-127.0.0.1:36456_solr-n_0000000000) closing
[junit4] 2> 866537 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.c.Overseer Overseer (id=74651453398122501-127.0.0.1:36456_solr-n_0000000000) closing
[junit4] 2> 866545 INFO (jetty-closer-1507-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@21797c98{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0}
[junit4] 2> 866545 INFO (jetty-closer-1507-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2373f6d2{/solr,null,UNAVAILABLE}
[junit4] 2> 866545 INFO (jetty-closer-1507-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 866546 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 866547 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> 4 /solr/collections/testkerberoscollection/terms/shard1
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 3 /solr/collections/testkerberoscollection/state.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 8 /solr/collections/testkerberoscollection/state.json
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/collections
[junit4] 2>
[junit4] 2> 866549 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:39325
[junit4] 2> 866549 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 39325
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene80): {_version_=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), _root_=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), id=PostingsFormat(name=Asserting)}, docValues:{}, maxPointsInLeafNode=877, maxMBSortInHeap=6.778557654438232, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@11ff40e4), locale=ru-RU, timezone=Asia/Qyzylorda
[junit4] 2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation 1.8.0_191 (64-bit)/cpus=4,threads=1,free=206373112,total=476053504
[junit4] 2> NOTE: All tests run in this JVM: [ChaosMonkeyNothingIsSafeWithPullReplicasTest, StatsComponentTest, MetricsConfigTest, TestHdfsBackupRestoreCore, TestComplexPhraseQParserPlugin, AssignTest, TestSimLargeCluster, CdcrWithNodesRestartsTest, SpatialRPTFieldTypeTest, TestSimPolicyCloud, TestReplicaProperties, SplitShardTest, TestCoreContainer, TestHighlightDedupGrouping, ResponseHeaderTest, TestPushWriter, TestRemoteStreaming, JavabinLoaderTest, ExitableDirectoryReaderTest, AnalysisErrorHandlingTest, TestIndexingPerformance, TestCollectionAPIs, LargeFieldTest, TestSearcherReuse, DistributedFacetPivotWhiteBoxTest, TestReplicationHandlerDiskOverFlow, TestNestedDocsSort, MoreLikeThisHandlerTest, ZkNodePropsTest, TestLeaderElectionWithEmptyReplica, LeaderElectionIntegrationTest, TestConfigSetImmutable, ReplicaListTransformerTest, ManagedSchemaRoundRobinCloudTest, TestGraphMLResponseWriter, AtomicUpdateRemovalJavabinTest, TestDistributedStatsComponentCardinality, HdfsRestartWhileUpdatingTest, InfixSuggestersTest, TestCSVResponseWriter, TestNumericTokenStream, FullHLLTest, TestSolrDeletionPolicy2, TestCSVLoader, TestEmbeddedSolrServerConstructors, TestSolrCloudWithHadoopAuthPlugin]
[junit4] Completed [105/855 (1!)] on J1 in 15.31s, 1 test, 1 failure <<< FAILURES!
[...truncated 817 lines...]
[junit4] Suite: org.apache.solr.security.JWTAuthPluginIntegrationTest
[junit4] 2> 2113737 INFO (SUITE-JWTAuthPluginIntegrationTest-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J2/temp/solr.security.JWTAuthPluginIntegrationTest_D251F4D3C6FA0825-001/init-core-data-001
[junit4] 2> 2113737 WARN (SUITE-JWTAuthPluginIntegrationTest-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=42 numCloses=42
[junit4] 2> 2113738 INFO (SUITE-JWTAuthPluginIntegrationTest-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 2113739 INFO (SUITE-JWTAuthPluginIntegrationTest-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None)
[junit4] 2> 2113741 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.SolrTestCaseJ4 ###Starting infoRequestWithoutToken
[junit4] 2> 2113742 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J2/temp/solr.security.JWTAuthPluginIntegrationTest_D251F4D3C6FA0825-001/tempDir-001
[junit4] 2> 2113742 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2113754 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2113754 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2113854 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.ZkTestServer start zk server on port:44837
[junit4] 2> 2113854 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:44837
[junit4] 2> 2113854 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 44837
[junit4] 2> 2113906 INFO (zkConnectionManagerCallback-8971-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2113950 INFO (zkConnectionManagerCallback-8973-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2113967 INFO (zkConnectionManagerCallback-8975-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2113971 WARN (jetty-launcher-8976-thread-1) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
[junit4] 2> 2113971 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
[junit4] 2> 2113971 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 2113971 INFO (jetty-launcher-8976-thread-1) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
[junit4] 2> 2113972 WARN (jetty-launcher-8976-thread-2) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
[junit4] 2> 2113972 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
[junit4] 2> 2113972 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 2113972 INFO (jetty-launcher-8976-thread-2) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
[junit4] 2> 2113972 INFO (jetty-launcher-8976-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2113972 INFO (jetty-launcher-8976-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2113972 INFO (jetty-launcher-8976-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 2113973 INFO (jetty-launcher-8976-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5209da3b{/solr,null,AVAILABLE}
[junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2a17b75a{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:44538}
[junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.e.j.s.Server Started @2114306ms
[junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44538}
[junit4] 2> 2113978 ERROR (jetty-launcher-8976-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.1.0
[junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-05-07T15:30:12.395Z
[junit4] 2> 2113979 INFO (jetty-launcher-8976-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2113979 INFO (jetty-launcher-8976-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2113979 INFO (jetty-launcher-8976-thread-2) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 2113979 INFO (jetty-launcher-8976-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1521d4c5{/solr,null,AVAILABLE}
[junit4] 2> 2113980 INFO (zkConnectionManagerCallback-8978-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@58ab8dd5{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:41707}
[junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.e.j.s.Server Started @2114308ms
[junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41707}
[junit4] 2> 2113980 ERROR (jetty-launcher-8976-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.1.0
[junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-05-07T15:30:12.397Z
[junit4] 2> 2113983 INFO (zkConnectionManagerCallback-8980-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2113983 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2114066 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 2114067 WARN (jetty-launcher-8976-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@518ea535[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2114070 WARN (jetty-launcher-8976-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@7ceb2edc[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2114071 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44837/solr
[junit4] 2> 2114072 INFO (zkConnectionManagerCallback-8988-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2114074 INFO (zkConnectionManagerCallback-8990-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2114127 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:41707_solr
[junit4] 2> 2114127 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.c.Overseer Overseer (id=74651535992160262-127.0.0.1:41707_solr-n_0000000000) starting
[junit4] 2> 2114165 INFO (zkConnectionManagerCallback-8997-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2114167 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44837/solr ready
[junit4] 2> 2114167 INFO (OverseerStateUpdate-74651535992160262-127.0.0.1:41707_solr-n_0000000000) [n:127.0.0.1:41707_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:41707_solr
[junit4] 2> 2114183 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 2114197 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41707_solr
[junit4] 2> 2114203 WARN (jetty-launcher-8976-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@399b3730[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2114205 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.JWTAuthPlugin
[junit4] 2> 2114210 INFO (zkCallback-8996-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2114215 INFO (zkCallback-8989-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2114224 WARN (jetty-launcher-8976-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@7e36f9c3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2114225 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44837/solr
[junit4] 2> 2114270 WARN (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.s.JWTAuthPlugin Warning: No adminUiScope provided, fallback to 'solr' as required scope. If this is not correct, the Admin UI login may not work
[junit4] 2> 2114290 INFO (zkConnectionManagerCallback-9003-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2114310 INFO (zkConnectionManagerCallback-9005-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2114313 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2114317 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:44538_solr as DOWN
[junit4] 2> 2114317 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2114317 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44538_solr
[junit4] 2> 2114318 INFO (zkCallback-8996-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2114319 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.JWTAuthPlugin
[junit4] 2> 2114319 WARN (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.s.JWTAuthPlugin Warning: No adminUiScope provided, fallback to 'solr' as required scope. If this is not correct, the Admin UI login may not work
[junit4] 2> 2114341 INFO (zkCallback-9004-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2114366 INFO (zkCallback-8989-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2114377 INFO (zkConnectionManagerCallback-9013-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2114379 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2114380 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44837/solr ready
[junit4] 2> 2114386 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2114406 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2114421 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41707.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@b7a6ec4
[junit4] 2> 2114431 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44538.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@b7a6ec4
[junit4] 2> 2114481 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41707.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@b7a6ec4
[junit4] 2> 2114482 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41707.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@b7a6ec4
[junit4] 2> 2114483 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J2/temp/solr.security.JWTAuthPluginIntegrationTest_D251F4D3C6FA0825-001/tempDir-001/node2/.
[junit4] 2> 2114483 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44538.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@b7a6ec4
[junit4] 2> 2114483 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44538.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@b7a6ec4
[junit4] 2> 2114484 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J2/temp/solr.security.JWTAuthPluginIntegrationTest_D251F4D3C6FA0825-001/tempDir-001/node1/.
[junit4] 2> 2114633 INFO (zkConnectionManagerCallback-9019-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2114634 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2114635 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44837/solr ready
[junit4] 2> 2114951 INFO (qtp1313089676-22886) [ ] o.a.s.s.JWTAuthPlugin JWT Authentication attempt failed: Require authentication
[junit4] 2> 2114974 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1499472627
[junit4] 2> 2114974 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:44538_solr
[junit4] 2> 2114974 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 2114974 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:44538_solr as DOWN
[junit4] 2> 2114980 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=873691572
[junit4] 2> 2114980 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:41707_solr
[junit4] 2> 2114982 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 2114982 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:41707_solr as DOWN
[junit4] 2> 2115022 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 2115022 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@cd5c633: rootName = solr_44538, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@20925144
[junit4] 2> 2115025 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 2115025 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2a1ebc2c: rootName = solr_44538, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@97060e0
[junit4] 2> 2115027 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 2115027 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@173cfa92: rootName = solr_44538, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@4b760b3f
[junit4] 2> 2115027 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 2115030 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2115046 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 2115046 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@415b98d2: rootName = solr_41707, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@3611a520
[junit4] 2> 2115050 INFO (zkCallback-8996-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 2115051 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 2115051 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@67a2f75: rootName = solr_41707, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@97060e0
[junit4] 2> 2115051 INFO (zkCallback-8989-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 2115053 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 2115053 INFO (jetty-closer-9020-threa
[...truncated too long message...]
s :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
resolve:
jar-checksums:
[mkdir] Created dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/null2046754742
[copy] Copying 239 files to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/null2046754742
[delete] Deleting directory /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/null2046754742
check-working-copy:
[ivy:cachepath] :: resolving dependencies :: #;working@lucene2-us-west.apache.org
[ivy:cachepath] confs: [default]
[ivy:cachepath] found org.eclipse.jgit#org.eclipse.jgit;5.3.0.201903130848-r in public
[ivy:cachepath] found com.jcraft#jsch;0.1.54 in public
[ivy:cachepath] found com.jcraft#jzlib;1.1.1 in public
[ivy:cachepath] found com.googlecode.javaewah#JavaEWAH;1.1.6 in public
[ivy:cachepath] found org.slf4j#slf4j-api;1.7.2 in public
[ivy:cachepath] found org.bouncycastle#bcpg-jdk15on;1.60 in public
[ivy:cachepath] found org.bouncycastle#bcprov-jdk15on;1.60 in public
[ivy:cachepath] found org.bouncycastle#bcpkix-jdk15on;1.60 in public
[ivy:cachepath] found org.slf4j#slf4j-nop;1.7.2 in public
[ivy:cachepath] :: resolution report :: resolve 64ms :: artifacts dl 20ms
---------------------------------------------------------------------
| | modules || artifacts |
| conf | number| search|dwnlded|evicted|| number|dwnlded|
---------------------------------------------------------------------
| default | 9 | 0 | 0 | 0 || 9 | 0 |
---------------------------------------------------------------------
[wc-checker] Initializing working copy...
[wc-checker] Checking working copy status...
-jenkins-base:
BUILD SUCCESSFUL
Total time: 221 minutes 45 seconds
Archiving artifacts
java.lang.InterruptedException: no matches found within 10000
at hudson.FilePath$ValidateAntFileMask.hasMatch(FilePath.java:2847)
at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2726)
at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2707)
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3086)
Also: hudson.remoting.Channel$CallSiteStackTrace: Remote call to lucene2
at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
at hudson.remoting.Channel.call(Channel.java:955)
at hudson.FilePath.act(FilePath.java:1072)
at hudson.FilePath.act(FilePath.java:1061)
at hudson.FilePath.validateAntFileMask(FilePath.java:2705)
at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
at hudson.model.Build$BuildExecution.post2(Build.java:186)
at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
at hudson.model.Run.execute(Run.java:1835)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at hudson.model.ResourceController.execute(ResourceController.java:97)
at hudson.model.Executor.run(Executor.java:429)
Caused: hudson.FilePath$TunneledInterruptedException
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3088)
at hudson.remoting.UserRequest.perform(UserRequest.java:212)
at hudson.remoting.UserRequest.perform(UserRequest.java:54)
at hudson.remoting.Request$2.run(Request.java:369)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:748)
Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000
at hudson.FilePath.act(FilePath.java:1074)
at hudson.FilePath.act(FilePath.java:1061)
at hudson.FilePath.validateAntFileMask(FilePath.java:2705)
at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
at hudson.model.Build$BuildExecution.post2(Build.java:186)
at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
at hudson.model.Run.execute(Run.java:1835)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at hudson.model.ResourceController.execute(ResourceController.java:97)
at hudson.model.Executor.run(Executor.java:429)
No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)
Re: [JENKINS] Lucene-Solr-Tests-8.1 - Build # 42 - Unstable
Posted by Ishan Chattopadhyaya <ic...@gmail.com>.
This must've been before I reverted SOLR-13449. After reverting, this
test passes.
On Tue, May 7, 2019 at 10:42 PM Apache Jenkins Server
<je...@builds.apache.org> wrote:
>
> Build: https://builds.apache.org/job/Lucene-Solr-Tests-8.1/42/
>
> 2 tests failed.
> FAILED: org.apache.solr.security.JWTAuthPluginIntegrationTest.createCollectionUpdateAndQueryDistributed
>
> Error Message:
> Expected metric minimums for prefix SECURITY./authentication/pki.: {failMissingCredentials=0, authenticated=12, passThrough=0, failWrongCredentials=0, requests=12, errors=0}, but got: {failMissingCredentials=0, authenticated=4, passThrough=0, totalTime=18761268, failWrongCredentials=0, requestTimes=352, requests=4, errors=0}
>
> Stack Trace:
> java.lang.AssertionError: Expected metric minimums for prefix SECURITY./authentication/pki.: {failMissingCredentials=0, authenticated=12, passThrough=0, failWrongCredentials=0, requests=12, errors=0}, but got: {failMissingCredentials=0, authenticated=4, passThrough=0, totalTime=18761268, failWrongCredentials=0, requestTimes=352, requests=4, errors=0}
> at __randomizedtesting.SeedInfo.seed([D251F4D3C6FA0825:D479F6BDA44D9E96]:0)
> at org.junit.Assert.fail(Assert.java:88)
> at org.junit.Assert.assertTrue(Assert.java:41)
> at org.apache.solr.cloud.SolrCloudAuthTestCase.assertAuthMetricsMinimums(SolrCloudAuthTestCase.java:129)
> at org.apache.solr.cloud.SolrCloudAuthTestCase.assertPkiAuthMetricsMinimums(SolrCloudAuthTestCase.java:74)
> at org.apache.solr.security.JWTAuthPluginIntegrationTest.createCollectionUpdateAndQueryDistributed(JWTAuthPluginIntegrationTest.java:173)
> 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)
>
>
> FAILED: org.apache.solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin.testBasics
>
> Error Message:
> Expected metric minimums for prefix SECURITY./authentication.: {failMissingCredentials=0, authenticated=8, passThrough=0, failWrongCredentials=8, requests=16, errors=0}, but got: {failMissingCredentials=0, authenticated=8, passThrough=0, totalTime=579767495, failWrongCredentials=6, requestTimes=1521, requests=14, errors=0}
>
> Stack Trace:
> java.lang.AssertionError: Expected metric minimums for prefix SECURITY./authentication.: {failMissingCredentials=0, authenticated=8, passThrough=0, failWrongCredentials=8, requests=16, errors=0}, but got: {failMissingCredentials=0, authenticated=8, passThrough=0, totalTime=579767495, failWrongCredentials=6, requestTimes=1521, requests=14, errors=0}
> at __randomizedtesting.SeedInfo.seed([D251F4D3C6FA0825:EF895AFFFE145655]:0)
> at org.junit.Assert.fail(Assert.java:88)
> at org.junit.Assert.assertTrue(Assert.java:41)
> at org.apache.solr.cloud.SolrCloudAuthTestCase.assertAuthMetricsMinimums(SolrCloudAuthTestCase.java:129)
> at org.apache.solr.cloud.SolrCloudAuthTestCase.assertAuthMetricsMinimums(SolrCloudAuthTestCase.java:83)
> at org.apache.solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin.testCollectionCreateSearchDelete(TestSolrCloudWithHadoopAuthPlugin.java:139)
> at org.apache.solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin.testBasics(TestSolrCloudWithHadoopAuthPlugin.java:108)
> 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 13255 lines...]
> [junit4] Suite: org.apache.solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin
> [junit4] 2> 851548 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
> [junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/init-core-data-001
> [junit4] 2> 851561 WARN (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=2 numCloses=2
> [junit4] 2> 851561 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=false
> [junit4] 2> 851562 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
> [junit4] 2> 853462 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-002
> [junit4] 2> 853462 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
> [junit4] 2> 853467 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
> [junit4] 2> 853467 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
> [junit4] 2> 853564 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:39325
> [junit4] 2> 853564 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:39325
> [junit4] 2> 853564 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 39325
> [junit4] 2> 853636 WARN (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
> [junit4] 2> 853715 WARN (zkConnectionManagerCallback-1476-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@38e00e56 name: ZooKeeperConnection Watcher:127.0.0.1:39325 got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
> [junit4] 2> 853715 WARN (zkConnectionManagerCallback-1476-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
> [junit4] 2> 853724 INFO (zkConnectionManagerCallback-1476-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 853748 WARN (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
> [junit4] 2> 853764 WARN (zkConnectionManagerCallback-1478-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@55bcbfb name: ZooKeeperConnection Watcher:127.0.0.1:39325/solr got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
> [junit4] 2> 853764 WARN (zkConnectionManagerCallback-1478-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
> [junit4] 2> 853784 INFO (zkConnectionManagerCallback-1478-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 853785 WARN (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
> [junit4] 2> 853800 WARN (zkConnectionManagerCallback-1480-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1cd36c29 name: ZooKeeperConnection Watcher:127.0.0.1:39325 got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
> [junit4] 2> 853800 WARN (zkConnectionManagerCallback-1480-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
> [junit4] 2> 853801 INFO (zkConnectionManagerCallback-1480-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 853818 WARN (jetty-launcher-1481-thread-1) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
> [junit4] 2> 853819 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
> [junit4] 2> 853819 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
> [junit4] 2> 853819 INFO (jetty-launcher-1481-thread-1) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
> [junit4] 2> 853857 INFO (jetty-launcher-1481-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
> [junit4] 2> 853857 INFO (jetty-launcher-1481-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
> [junit4] 2> 853857 INFO (jetty-launcher-1481-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
> [junit4] 2> 853860 INFO (jetty-launcher-1481-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2373f6d2{/solr,null,AVAILABLE}
> [junit4] 2> 853864 INFO (jetty-launcher-1481-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@21797c98{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:36456}
> [junit4] 2> 853864 INFO (jetty-launcher-1481-thread-1) [ ] o.e.j.s.Server Started @854259ms
> [junit4] 2> 853864 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36456}
> [junit4] 2> 853865 ERROR (jetty-launcher-1481-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
> [junit4] 2> 853865 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
> [junit4] 2> 853865 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.1.0
> [junit4] 2> 853865 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
> [junit4] 2> 853865 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
> [junit4] 2> 853901 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-05-07T15:09:12.331Z
> [junit4] 2> 853954 WARN (jetty-launcher-1481-thread-1-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
> [junit4] 2> 853970 WARN (zkConnectionManagerCallback-1483-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@10ba3824 name: ZooKeeperConnection Watcher:127.0.0.1:39325/solr got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
> [junit4] 2> 853970 WARN (zkConnectionManagerCallback-1483-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
> [junit4] 2> 853970 INFO (zkConnectionManagerCallback-1483-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 853975 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
> [junit4] 2> 854540 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
> [junit4] 2> 854555 WARN (jetty-launcher-1481-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@4be5c573[provider=null,keyStore=null,trustStore=null]
> [junit4] 2> 854575 WARN (jetty-launcher-1481-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@154bf116[provider=null,keyStore=null,trustStore=null]
> [junit4] 2> 854576 INFO (jetty-launcher-1481-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:39325/solr
> [junit4] 2> 854576 WARN (jetty-launcher-1481-thread-1-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
> [junit4] 2> 854577 WARN (zkConnectionManagerCallback-1490-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@74da40c9 name: ZooKeeperConnection Watcher:127.0.0.1:39325 got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
> [junit4] 2> 854577 WARN (zkConnectionManagerCallback-1490-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
> [junit4] 2> 854591 INFO (zkConnectionManagerCallback-1490-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 854592 WARN (jetty-launcher-1481-thread-1-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
> [junit4] 2> 854659 WARN (zkConnectionManagerCallback-1492-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2b200736 name: ZooKeeperConnection Watcher:127.0.0.1:39325/solr got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
> [junit4] 2> 854659 WARN (zkConnectionManagerCallback-1492-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
> [junit4] 2> 854659 INFO (zkConnectionManagerCallback-1492-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 855397 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:36456_solr
> [junit4] 2> 855450 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.Overseer Overseer (id=74651453398122501-127.0.0.1:36456_solr-n_0000000000) starting
> [junit4] 2> 855538 WARN (jetty-launcher-1481-thread-1-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
> [junit4] 2> 855558 WARN (zkConnectionManagerCallback-1499-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@70ed8ca8 name: ZooKeeperConnection Watcher:127.0.0.1:39325/solr got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
> [junit4] 2> 855559 WARN (zkConnectionManagerCallback-1499-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
> [junit4] 2> 855559 INFO (zkConnectionManagerCallback-1499-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 855576 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:39325/solr ready
> [junit4] 2> 855577 INFO (OverseerStateUpdate-74651453398122501-127.0.0.1:36456_solr-n_0000000000) [n:127.0.0.1:36456_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:36456_solr
> [junit4] 2> 855577 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36456_solr
> [junit4] 2> 855592 INFO (OverseerStateUpdate-74651453398122501-127.0.0.1:36456_solr-n_0000000000) [n:127.0.0.1:36456_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
> [junit4] 2> 855593 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: org.apache.solr.security.ConfigurableInternodeAuthHadoopPlugin
> [junit4] 2> 855754 INFO (zkCallback-1498-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
> [junit4] 2> 855756 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.s.i.Krb5HttpClientBuilder Setting up SPNego auth with config: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf
> [junit4] 2> 855773 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.s.HadoopAuthPlugin Params: {kerberos.principal=HTTP/127.0.0.1, kerberos.keytab=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/keytabs, type=kerberos, kerberos.name.rules=RULE:[1:$1@$0](.*EXAMPLE.COM)s/@.*//
> [junit4] 2> RULE:[2:$2@$0](.*EXAMPLE.COM)s/@.*//
> [junit4] 2> DEFAULT, delegation-token.json-mapper.AUTO_CLOSE_TARGET=false}
> [junit4] 2> 856013 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.s.i.Krb5HttpClientBuilder Setting up SPNego auth with config: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf
> [junit4] 2> 856110 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
> [junit4] 2> 856262 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36456.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d3ec300
> [junit4] 2> 856296 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36456.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d3ec300
> [junit4] 2> 856296 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36456.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d3ec300
> [junit4] 2> 856297 INFO (jetty-launcher-1481-thread-1) [n:127.0.0.1:36456_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-002/node1/.
> [junit4] 2> 856401 WARN (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker-SendThread(lucene2-us-west.apache.org:39325)) [ ] o.a.z.ClientCnxn SASL configuration failed: javax.security.auth.login.LoginException: No JAAS configuration section named 'Client' was found in specified JAAS configuration file: '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/jaas-client.conf'. Will continue connection to Zookeeper server without SASL authentication, if Zookeeper server allows it.
> [junit4] 2> 856402 WARN (zkConnectionManagerCallback-1505-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@137ad575 name: ZooKeeperConnection Watcher:127.0.0.1:39325/solr got event WatchedEvent state:AuthFailed type:None path:null path: null type: None
> [junit4] 2> 856402 WARN (zkConnectionManagerCallback-1505-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient received AuthFailed
> [junit4] 2> 856402 INFO (zkConnectionManagerCallback-1505-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 856417 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
> [junit4] 2> 856418 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:39325/solr ready
> [junit4] 2> 856506 INFO (TEST-TestSolrCloudWithHadoopAuthPlugin.testBasics-seed#[D251F4D3C6FA0825]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBasics
> [junit4] 1> Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt false ticketCache is null isInitiator true KeyTab is /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/keytabs refreshKrb5Config is true principal is solr tryFirstPass is false useFirstPass is false storePass is false clearPass is false
> [junit4] 1> Refreshing Kerberos configuration
> [junit4] 2> 857098 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.KdcRequest The preauth data is empty.
> [junit4] 2> 857137 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.KdcHandler KRB error occurred while processing request:Additional pre-authentication required
> [junit4] 2> 857295 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.AsRequest AS_REQ ISSUE: authtime 1557241755722,solr@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM
> [junit4] 1> principal is solr@EXAMPLE.COM
> [junit4] 1> Will use keytab
> [junit4] 1> Commit Succeeded
> [junit4] 1>
> [junit4] 2> 857591 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.TgsRequest TGS_REQ ISSUE: authtime 1557241755988,solr for HTTP/127.0.0.1@EXAMPLE.COM
> [junit4] 2> 857743 INFO (qtp722099044-4908) [n:127.0.0.1:36456_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf1&name=testkerberoscollection&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
> [junit4] 2> 857795 INFO (OverseerThreadFactory-1875-thread-1-processing-n:127.0.0.1:36456_solr) [n:127.0.0.1:36456_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection testkerberoscollection
> [junit4] 1> Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt false ticketCache is null isInitiator true KeyTab is /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/keytabs refreshKrb5Config is true principal is solr tryFirstPass is false useFirstPass is false storePass is false clearPass is false
> [junit4] 1> Refreshing Kerberos configuration
> [junit4] 2> 858026 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.KdcRequest The preauth data is empty.
> [junit4] 2> 858026 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.KdcHandler KRB error occurred while processing request:Additional pre-authentication required
> [junit4] 2> 858269 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.AsRequest AS_REQ ISSUE: authtime 1557241756590,solr@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM
> [junit4] 1> principal is solr@EXAMPLE.COM
> [junit4] 1> Will use keytab
> [junit4] 1> Commit Succeeded
> [junit4] 1>
> [junit4] 2> 858417 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.TgsRequest TGS_REQ ISSUE: authtime 1557241756846,solr for HTTP/127.0.0.1@EXAMPLE.COM
> [junit4] 2> 858711 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
> [junit4] 2> 858741 INFO (OverseerStateUpdate-74651453398122501-127.0.0.1:36456_solr-n_0000000000) [n:127.0.0.1:36456_solr ] o.a.s.c.o.SliceMutator createReplica() {
> [junit4] 2> "operation":"ADDREPLICA",
> [junit4] 2> "collection":"testkerberoscollection",
> [junit4] 2> "shard":"shard1",
> [junit4] 2> "core":"testkerberoscollection_shard1_replica_n1",
> [junit4] 2> "state":"down",
> [junit4] 2> "base_url":"http://127.0.0.1:36456/solr",
> [junit4] 2> "type":"NRT",
> [junit4] 2> "waitForFinalState":"false"}
> [junit4] 1> Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt false ticketCache is null isInitiator true KeyTab is /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/keytabs refreshKrb5Config is true principal is solr tryFirstPass is false useFirstPass is false storePass is false clearPass is false
> [junit4] 1> Refreshing Kerberos configuration
> [junit4] 2> 858977 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.KdcRequest The preauth data is empty.
> [junit4] 2> 858978 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.KdcHandler KRB error occurred while processing request:Additional pre-authentication required
> [junit4] 2> 859018 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.AsRequest AS_REQ ISSUE: authtime 1557241757448,solr@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM
> [junit4] 1> principal is solr@EXAMPLE.COM
> [junit4] 1> Will use keytab
> [junit4] 1> Commit Succeeded
> [junit4] 1>
> [junit4] 2> 859087 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.TgsRequest TGS_REQ ISSUE: authtime 1557241757517,solr for HTTP/127.0.0.1@EXAMPLE.COM
> [junit4] 2> 859160 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf1&newCollection=true&name=testkerberoscollection_shard1_replica_n1&action=CREATE&numShards=1&collection=testkerberoscollection&shard=shard1&wt=javabin&version=2&replicaType=NRT
> [junit4] 2> 859160 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
> [junit4] 2> 860214 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.1.0
> [junit4] 2> 860251 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.s.IndexSchema [testkerberoscollection_shard1_replica_n1] Schema name=minimal
> [junit4] 2> 860262 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
> [junit4] 2> 860262 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'testkerberoscollection_shard1_replica_n1' using configuration from collection testkerberoscollection, trusted=true
> [junit4] 2> 860264 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36456.solr.core.testkerberoscollection.shard1.replica_n1' (registry 'solr.core.testkerberoscollection.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d3ec300
> [junit4] 2> 860264 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SolrCore [[testkerberoscollection_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-002/node1/testkerberoscollection_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-002/node1/./testkerberoscollection_shard1_replica_n1/data/]
> [junit4] 2> 860480 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
> [junit4] 2> 860480 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
> [junit4] 2> 860481 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
> [junit4] 2> 860481 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
> [junit4] 2> 860482 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3b478112[testkerberoscollection_shard1_replica_n1] main]
> [junit4] 2> 860509 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
> [junit4] 2> 860509 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
> [junit4] 2> 860509 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
> [junit4] 2> 860510 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1632886334622269440
> [junit4] 2> 860531 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testkerberoscollection/terms/shard1 to Terms{values={core_node2=0}, version=0}
> [junit4] 2> 860531 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testkerberoscollection/leaders/shard1
> [junit4] 2> 860537 INFO (searcherExecutor-1880-thread-1-processing-n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1 c:testkerberoscollection s:shard1 r:core_node2) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SolrCore [testkerberoscollection_shard1_replica_n1] Registered new searcher Searcher@3b478112[testkerberoscollection_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
> [junit4] 2> 860568 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
> [junit4] 2> 860568 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
> [junit4] 2> 860568 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:36456/solr/testkerberoscollection_shard1_replica_n1/
> [junit4] 2> 860568 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
> [junit4] 2> 860568 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:36456/solr/testkerberoscollection_shard1_replica_n1/ has no replicas
> [junit4] 2> 860568 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/testkerberoscollection/leaders/shard1/leader after winning as /collections/testkerberoscollection/leader_elect/shard1/election/74651453398122501-core_node2-n_0000000000
> [junit4] 2> 860582 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:36456/solr/testkerberoscollection_shard1_replica_n1/ shard1
> [junit4] 2> 860743 INFO (zkCallback-1491-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
> [junit4] 2> 860744 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
> [junit4] 2> 860746 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf1&newCollection=true&name=testkerberoscollection_shard1_replica_n1&action=CREATE&numShards=1&collection=testkerberoscollection&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1586
> [junit4] 2> 860791 INFO (zkCallback-1491-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
> [junit4] 2> 860858 INFO (qtp722099044-4908) [n:127.0.0.1:36456_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> 860966 INFO (zkCallback-1491-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
> [junit4] 2> 860966 INFO (zkCallback-1491-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
> [junit4] 2> 860967 INFO (qtp722099044-4908) [n:127.0.0.1:36456_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf1&name=testkerberoscollection&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=3223
> [junit4] 2> 860974 INFO (zkCallback-1491-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
> [junit4] 1> Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt false ticketCache is null isInitiator true KeyTab is /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/keytabs refreshKrb5Config is true principal is solr tryFirstPass is false useFirstPass is false storePass is false clearPass is false
> [junit4] 1> Refreshing Kerberos configuration
> [junit4] 2> 861121 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.KdcRequest The preauth data is empty.
> [junit4] 2> 861122 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.KdcHandler KRB error occurred while processing request:Additional pre-authentication required
> [junit4] 1> principal is solr@EXAMPLE.COM
> [junit4] 1> Will use keytab
> [junit4] 1> Commit Succeeded
> [junit4] 1>
> [junit4] 2> 861158 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.AsRequest AS_REQ ISSUE: authtime 1557241759587,solr@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM
> [junit4] 2> 861223 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.TgsRequest TGS_REQ ISSUE: authtime 1557241759653,solr for HTTP/127.0.0.1@EXAMPLE.COM
> [junit4] 2> 861541 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testkerberoscollection/terms/shard1 to Terms{values={core_node2=1}, version=1}
> [junit4] 2> 861541 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [testkerberoscollection_shard1_replica_n1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1 (1632886335510413312)]} 0 183
> [junit4] 1> Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt false ticketCache is null isInitiator true KeyTab is /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/keytabs refreshKrb5Config is true principal is solr tryFirstPass is false useFirstPass is false storePass is false clearPass is false
> [junit4] 1> Refreshing Kerberos configuration
> [junit4] 2> 861612 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.KdcRequest The preauth data is empty.
> [junit4] 2> 861612 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.KdcHandler KRB error occurred while processing request:Additional pre-authentication required
> [junit4] 2> 861721 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.AsRequest AS_REQ ISSUE: authtime 1557241760151,solr@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM
> [junit4] 1> principal is solr@EXAMPLE.COM
> [junit4] 1> Will use keytab
> [junit4] 1> Commit Succeeded
> [junit4] 1>
> [junit4] 2> 861795 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.TgsRequest TGS_REQ ISSUE: authtime 1557241760224,solr for HTTP/127.0.0.1@EXAMPLE.COM
> [junit4] 2> 861974 INFO (OverseerCollectionConfigSetProcessor-74651453398122501-127.0.0.1:36456_solr-n_0000000000) [n:127.0.0.1:36456_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
> [junit4] 2> 862052 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1632886336239173632,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
> [junit4] 2> 862052 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@4afe318f commitCommandVersion:1632886336239173632
> [junit4] 2> 862054 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@28f166d[testkerberoscollection_shard1_replica_n1] main]
> [junit4] 2> 862064 INFO (searcherExecutor-1880-thread-1-processing-n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1 c:testkerberoscollection s:shard1 r:core_node2) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SolrCore [testkerberoscollection_shard1_replica_n1] Registered new searcher Searcher@28f166d[testkerberoscollection_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.1.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.1.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1557241760483}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
> [junit4] 2> 862065 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
> [junit4] 2> 862065 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [testkerberoscollection_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=testkerberoscollection:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 50
> [junit4] 2> 862293 INFO (qtp722099044-4909) [n:127.0.0.1:36456_solr c:testkerberoscollection s:shard1 r:core_node2 x:testkerberoscollection_shard1_replica_n1] o.a.s.c.S.Request [testkerberoscollection_shard1_replica_n1] webapp=/solr path=/select params={q=*:*&_stateVer_=testkerberoscollection:4&wt=javabin&version=2} hits=1 status=0 QTime=0
> [junit4] 2> 862307 INFO (qtp722099044-4908) [n:127.0.0.1:36456_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=testkerberoscollection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
> [junit4] 2> 862412 INFO (OverseerThreadFactory-1875-thread-2-processing-n:127.0.0.1:36456_solr) [n:127.0.0.1:36456_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler Executing Collection Cmd=action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true&deleteMetricsHistory=true, asyncId=null
> [junit4] 1> Debug is true storeKey true useTicketCache false useKeyTab true doNotPrompt false ticketCache is null isInitiator true KeyTab is /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001/tempDir-001/minikdc/keytabs refreshKrb5Config is true principal is solr tryFirstPass is false useFirstPass is false storePass is false clearPass is false
> [junit4] 1> Refreshing Kerberos configuration
> [junit4] 2> 862430 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.r.KdcRequest The preauth data is empty.
> [junit4] 2> 862431 INFO (pool-20-thread-2) [ ] o.a.k.k.k.s.KdcHandler KRB error occurred while processing request:Additional pre-authentication required
> [junit4] 2> 862528 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.AsRequest AS_REQ ISSUE: authtime 1557241760957,solr@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM
> [junit4] 1> principal is solr@EXAMPLE.COM
> [junit4] 1> Will use keytab
> [junit4] 1> Commit Succeeded
> [junit4] 1>
> [junit4] 2> 862622 INFO (pool-20-thread-1) [ ] o.a.k.k.k.s.r.TgsRequest TGS_REQ ISSUE: authtime 1557241761051,solr for HTTP/127.0.0.1@EXAMPLE.COM
> [junit4] 2> 862724 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.testkerberoscollection.shard1.replica_n1, tag=null
> [junit4] 2> 862740 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@19afa9f2: rootName = solr_36456, domain = solr.core.testkerberoscollection.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.testkerberoscollection.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@1d910d7
> [junit4] 2> 862852 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.c.SolrCore [testkerberoscollection_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@3b20424a
> [junit4] 2> 862852 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.testkerberoscollection.shard1.replica_n1, tag=3b20424a
> [junit4] 2> 862852 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.testkerberoscollection.shard1.leader, tag=3b20424a
> [junit4] 2> 862908 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testkerberoscollection/terms/shard1 to Terms{values={}, version=2}
> [junit4] 2> 862940 INFO (qtp722099044-4905) [n:127.0.0.1:36456_solr x:testkerberoscollection_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&deleteMetricsHistory=true&core=testkerberoscollection_shard1_replica_n1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=217
> [junit4] 2> 863012 INFO (zkCallback-1491-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
> [junit4] 2> 863012 INFO (zkCallback-1491-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
> [junit4] 2> 863015 INFO (zkCallback-1491-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
> [junit4] 2> 863138 INFO (zkCallback-1491-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
> [junit4] 2> 863138 INFO (zkCallback-1491-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
> [junit4] 2> 863138 INFO (zkCallback-1491-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/testkerberoscollection/state.json] for collection [testkerberoscollection] has occurred - updating... (live nodes size: [1])
> [junit4] 2> 863182 INFO (qtp722099044-4908) [n:127.0.0.1:36456_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=testkerberoscollection&action=DELETE&wt=javabin&version=2} status=0 QTime=874
> [junit4] 2> 863198 INFO (TEST-TestSolrCloudWithHadoopAuthPlugin.testBasics-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for collection to disappear - collection: testkerberoscollection failOnTimeout:true timeout (sec):330
> [junit4] 2> 863206 INFO (TEST-TestSolrCloudWithHadoopAuthPlugin.testBasics-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.AbstractDistribZkTestBase Collection has disappeared - collection: testkerberoscollection
> [junit4] 2> 863206 INFO (TEST-TestSolrCloudWithHadoopAuthPlugin.testBasics-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.SolrCloudAuthTestCase First metrics count assert failed, pausing 2s before re-attempt
> [junit4] 2> 864413 INFO (OverseerCollectionConfigSetProcessor-74651453398122501-127.0.0.1:36456_solr-n_0000000000) [n:127.0.0.1:36456_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper
> [junit4] 2> 865220 INFO (TEST-TestSolrCloudWithHadoopAuthPlugin.testBasics-seed#[D251F4D3C6FA0825]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testBasics
> [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestSolrCloudWithHadoopAuthPlugin -Dtests.method=testBasics -Dtests.seed=D251F4D3C6FA0825 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=ru-RU -Dtests.timezone=Asia/Qyzylorda -Dtests.asserts=true -Dtests.file.encoding=UTF-8
> [junit4] FAILURE 8.79s J1 | TestSolrCloudWithHadoopAuthPlugin.testBasics <<<
> [junit4] > Throwable #1: java.lang.AssertionError: Expected metric minimums for prefix SECURITY./authentication.: {failMissingCredentials=0, authenticated=8, passThrough=0, failWrongCredentials=8, requests=16, errors=0}, but got: {failMissingCredentials=0, authenticated=8, passThrough=0, totalTime=579767495, failWrongCredentials=6, requestTimes=1521, requests=14, errors=0}
> [junit4] > at __randomizedtesting.SeedInfo.seed([D251F4D3C6FA0825:EF895AFFFE145655]:0)
> [junit4] > at org.apache.solr.cloud.SolrCloudAuthTestCase.assertAuthMetricsMinimums(SolrCloudAuthTestCase.java:129)
> [junit4] > at org.apache.solr.cloud.SolrCloudAuthTestCase.assertAuthMetricsMinimums(SolrCloudAuthTestCase.java:83)
> [junit4] > at org.apache.solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin.testCollectionCreateSearchDelete(TestSolrCloudWithHadoopAuthPlugin.java:139)
> [junit4] > at org.apache.solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin.testBasics(TestSolrCloudWithHadoopAuthPlugin.java:108)
> [junit4] > at java.lang.Thread.run(Thread.java:748)
> [junit4] 2> 865223 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.k.k.k.s.i.DefaultInternalKdcServerImpl Default Internal kdc server stopped.
> [junit4] 2> 866257 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=721276841
> [junit4] 2> 866257 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:36456_solr
> [junit4] 2> 866272 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.c.ZkController Publish this node as DOWN...
> [junit4] 2> 866273 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:36456_solr as DOWN
> [junit4] 2> 866402 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
> [junit4] 2> 866402 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@14ced5e5: rootName = solr_36456, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@5bd478de
> [junit4] 2> 866405 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
> [junit4] 2> 866405 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1185f71c: rootName = solr_36456, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@375c45ab
> [junit4] 2> 866440 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
> [junit4] 2> 866440 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@69436321: rootName = solr_36456, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@7158613a
> [junit4] 2> 866440 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
> [junit4] 2> 866459 INFO (closeThreadPool-1511-thread-2) [ ] o.a.s.c.Overseer Overseer (id=74651453398122501-127.0.0.1:36456_solr-n_0000000000) closing
> [junit4] 2> 866511 INFO (OverseerStateUpdate-74651453398122501-127.0.0.1:36456_solr-n_0000000000) [n:127.0.0.1:36456_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:36456_solr
> [junit4] 2> 866527 INFO (OverseerAutoScalingTriggerThread-74651453398122501-127.0.0.1:36456_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
> [junit4] 2> 866533 INFO (closeThreadPool-1511-thread-1) [ ] o.a.s.c.Overseer Overseer (id=74651453398122501-127.0.0.1:36456_solr-n_0000000000) closing
> [junit4] 2> 866537 INFO (jetty-closer-1507-thread-1) [ ] o.a.s.c.Overseer Overseer (id=74651453398122501-127.0.0.1:36456_solr-n_0000000000) closing
> [junit4] 2> 866545 INFO (jetty-closer-1507-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@21797c98{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0}
> [junit4] 2> 866545 INFO (jetty-closer-1507-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2373f6d2{/solr,null,UNAVAILABLE}
> [junit4] 2> 866545 INFO (jetty-closer-1507-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
> [junit4] 2> 866546 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
> [junit4] 2> 866547 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> 4 /solr/collections/testkerberoscollection/terms/shard1
> [junit4] 2> 3 /solr/aliases.json
> [junit4] 2> 3 /solr/collections/testkerberoscollection/state.json
> [junit4] 2> 3 /solr/clusterprops.json
> [junit4] 2>
> [junit4] 2> Maximum concurrent data watches above limit:
> [junit4] 2>
> [junit4] 2> 8 /solr/collections/testkerberoscollection/state.json
> [junit4] 2> 3 /solr/clusterstate.json
> [junit4] 2> 3 /solr/clusterprops.json
> [junit4] 2>
> [junit4] 2> Maximum concurrent children watches above limit:
> [junit4] 2>
> [junit4] 2> 3 /solr/live_nodes
> [junit4] 2> 3 /solr/collections
> [junit4] 2>
> [junit4] 2> 866549 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:39325
> [junit4] 2> 866549 INFO (SUITE-TestSolrCloudWithHadoopAuthPlugin-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 39325
> [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J1/temp/solr.security.hadoop.TestSolrCloudWithHadoopAuthPlugin_D251F4D3C6FA0825-001
> [junit4] 2> NOTE: test params are: codec=Asserting(Lucene80): {_version_=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), _root_=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), id=PostingsFormat(name=Asserting)}, docValues:{}, maxPointsInLeafNode=877, maxMBSortInHeap=6.778557654438232, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@11ff40e4), locale=ru-RU, timezone=Asia/Qyzylorda
> [junit4] 2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation 1.8.0_191 (64-bit)/cpus=4,threads=1,free=206373112,total=476053504
> [junit4] 2> NOTE: All tests run in this JVM: [ChaosMonkeyNothingIsSafeWithPullReplicasTest, StatsComponentTest, MetricsConfigTest, TestHdfsBackupRestoreCore, TestComplexPhraseQParserPlugin, AssignTest, TestSimLargeCluster, CdcrWithNodesRestartsTest, SpatialRPTFieldTypeTest, TestSimPolicyCloud, TestReplicaProperties, SplitShardTest, TestCoreContainer, TestHighlightDedupGrouping, ResponseHeaderTest, TestPushWriter, TestRemoteStreaming, JavabinLoaderTest, ExitableDirectoryReaderTest, AnalysisErrorHandlingTest, TestIndexingPerformance, TestCollectionAPIs, LargeFieldTest, TestSearcherReuse, DistributedFacetPivotWhiteBoxTest, TestReplicationHandlerDiskOverFlow, TestNestedDocsSort, MoreLikeThisHandlerTest, ZkNodePropsTest, TestLeaderElectionWithEmptyReplica, LeaderElectionIntegrationTest, TestConfigSetImmutable, ReplicaListTransformerTest, ManagedSchemaRoundRobinCloudTest, TestGraphMLResponseWriter, AtomicUpdateRemovalJavabinTest, TestDistributedStatsComponentCardinality, HdfsRestartWhileUpdatingTest, InfixSuggestersTest, TestCSVResponseWriter, TestNumericTokenStream, FullHLLTest, TestSolrDeletionPolicy2, TestCSVLoader, TestEmbeddedSolrServerConstructors, TestSolrCloudWithHadoopAuthPlugin]
> [junit4] Completed [105/855 (1!)] on J1 in 15.31s, 1 test, 1 failure <<< FAILURES!
>
> [...truncated 817 lines...]
> [junit4] Suite: org.apache.solr.security.JWTAuthPluginIntegrationTest
> [junit4] 2> 2113737 INFO (SUITE-JWTAuthPluginIntegrationTest-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
> [junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J2/temp/solr.security.JWTAuthPluginIntegrationTest_D251F4D3C6FA0825-001/init-core-data-001
> [junit4] 2> 2113737 WARN (SUITE-JWTAuthPluginIntegrationTest-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=42 numCloses=42
> [junit4] 2> 2113738 INFO (SUITE-JWTAuthPluginIntegrationTest-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
> [junit4] 2> 2113739 INFO (SUITE-JWTAuthPluginIntegrationTest-seed#[D251F4D3C6FA0825]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None)
> [junit4] 2> 2113741 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.SolrTestCaseJ4 ###Starting infoRequestWithoutToken
> [junit4] 2> 2113742 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J2/temp/solr.security.JWTAuthPluginIntegrationTest_D251F4D3C6FA0825-001/tempDir-001
> [junit4] 2> 2113742 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
> [junit4] 2> 2113754 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
> [junit4] 2> 2113754 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
> [junit4] 2> 2113854 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.ZkTestServer start zk server on port:44837
> [junit4] 2> 2113854 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:44837
> [junit4] 2> 2113854 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 44837
> [junit4] 2> 2113906 INFO (zkConnectionManagerCallback-8971-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 2113950 INFO (zkConnectionManagerCallback-8973-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 2113967 INFO (zkConnectionManagerCallback-8975-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 2113971 WARN (jetty-launcher-8976-thread-1) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
> [junit4] 2> 2113971 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
> [junit4] 2> 2113971 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
> [junit4] 2> 2113971 INFO (jetty-launcher-8976-thread-1) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
> [junit4] 2> 2113972 WARN (jetty-launcher-8976-thread-2) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
> [junit4] 2> 2113972 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
> [junit4] 2> 2113972 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
> [junit4] 2> 2113972 INFO (jetty-launcher-8976-thread-2) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
> [junit4] 2> 2113972 INFO (jetty-launcher-8976-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
> [junit4] 2> 2113972 INFO (jetty-launcher-8976-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
> [junit4] 2> 2113972 INFO (jetty-launcher-8976-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
> [junit4] 2> 2113973 INFO (jetty-launcher-8976-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5209da3b{/solr,null,AVAILABLE}
> [junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2a17b75a{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:44538}
> [junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.e.j.s.Server Started @2114306ms
> [junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44538}
> [junit4] 2> 2113978 ERROR (jetty-launcher-8976-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
> [junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
> [junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.1.0
> [junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
> [junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
> [junit4] 2> 2113978 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-05-07T15:30:12.395Z
> [junit4] 2> 2113979 INFO (jetty-launcher-8976-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
> [junit4] 2> 2113979 INFO (jetty-launcher-8976-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
> [junit4] 2> 2113979 INFO (jetty-launcher-8976-thread-2) [ ] o.e.j.s.session node0 Scavenging every 660000ms
> [junit4] 2> 2113979 INFO (jetty-launcher-8976-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1521d4c5{/solr,null,AVAILABLE}
> [junit4] 2> 2113980 INFO (zkConnectionManagerCallback-8978-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@58ab8dd5{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:41707}
> [junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.e.j.s.Server Started @2114308ms
> [junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
> [junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41707}
> [junit4] 2> 2113980 ERROR (jetty-launcher-8976-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
> [junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
> [junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.1.0
> [junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
> [junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
> [junit4] 2> 2113980 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-05-07T15:30:12.397Z
> [junit4] 2> 2113983 INFO (zkConnectionManagerCallback-8980-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 2113983 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
> [junit4] 2> 2114066 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
> [junit4] 2> 2114067 WARN (jetty-launcher-8976-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@518ea535[provider=null,keyStore=null,trustStore=null]
> [junit4] 2> 2114070 WARN (jetty-launcher-8976-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@7ceb2edc[provider=null,keyStore=null,trustStore=null]
> [junit4] 2> 2114071 INFO (jetty-launcher-8976-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44837/solr
> [junit4] 2> 2114072 INFO (zkConnectionManagerCallback-8988-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 2114074 INFO (zkConnectionManagerCallback-8990-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 2114127 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:41707_solr
> [junit4] 2> 2114127 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.c.Overseer Overseer (id=74651535992160262-127.0.0.1:41707_solr-n_0000000000) starting
> [junit4] 2> 2114165 INFO (zkConnectionManagerCallback-8997-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 2114167 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44837/solr ready
> [junit4] 2> 2114167 INFO (OverseerStateUpdate-74651535992160262-127.0.0.1:41707_solr-n_0000000000) [n:127.0.0.1:41707_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:41707_solr
> [junit4] 2> 2114183 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
> [junit4] 2> 2114197 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41707_solr
> [junit4] 2> 2114203 WARN (jetty-launcher-8976-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@399b3730[provider=null,keyStore=null,trustStore=null]
> [junit4] 2> 2114205 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.JWTAuthPlugin
> [junit4] 2> 2114210 INFO (zkCallback-8996-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
> [junit4] 2> 2114215 INFO (zkCallback-8989-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
> [junit4] 2> 2114224 WARN (jetty-launcher-8976-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@7e36f9c3[provider=null,keyStore=null,trustStore=null]
> [junit4] 2> 2114225 INFO (jetty-launcher-8976-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44837/solr
> [junit4] 2> 2114270 WARN (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.s.JWTAuthPlugin Warning: No adminUiScope provided, fallback to 'solr' as required scope. If this is not correct, the Admin UI login may not work
> [junit4] 2> 2114290 INFO (zkConnectionManagerCallback-9003-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 2114310 INFO (zkConnectionManagerCallback-9005-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 2114313 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
> [junit4] 2> 2114317 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:44538_solr as DOWN
> [junit4] 2> 2114317 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
> [junit4] 2> 2114317 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44538_solr
> [junit4] 2> 2114318 INFO (zkCallback-8996-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
> [junit4] 2> 2114319 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.JWTAuthPlugin
> [junit4] 2> 2114319 WARN (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.s.JWTAuthPlugin Warning: No adminUiScope provided, fallback to 'solr' as required scope. If this is not correct, the Admin UI login may not work
> [junit4] 2> 2114341 INFO (zkCallback-9004-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
> [junit4] 2> 2114366 INFO (zkCallback-8989-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
> [junit4] 2> 2114377 INFO (zkConnectionManagerCallback-9013-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 2114379 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
> [junit4] 2> 2114380 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44837/solr ready
> [junit4] 2> 2114386 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
> [junit4] 2> 2114406 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
> [junit4] 2> 2114421 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41707.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@b7a6ec4
> [junit4] 2> 2114431 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44538.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@b7a6ec4
> [junit4] 2> 2114481 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41707.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@b7a6ec4
> [junit4] 2> 2114482 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41707.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@b7a6ec4
> [junit4] 2> 2114483 INFO (jetty-launcher-8976-thread-2) [n:127.0.0.1:41707_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J2/temp/solr.security.JWTAuthPluginIntegrationTest_D251F4D3C6FA0825-001/tempDir-001/node2/.
> [junit4] 2> 2114483 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44538.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@b7a6ec4
> [junit4] 2> 2114483 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44538.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@b7a6ec4
> [junit4] 2> 2114484 INFO (jetty-launcher-8976-thread-1) [n:127.0.0.1:44538_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/build/solr-core/test/J2/temp/solr.security.JWTAuthPluginIntegrationTest_D251F4D3C6FA0825-001/tempDir-001/node1/.
> [junit4] 2> 2114633 INFO (zkConnectionManagerCallback-9019-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
> [junit4] 2> 2114634 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
> [junit4] 2> 2114635 INFO (TEST-JWTAuthPluginIntegrationTest.infoRequestWithoutToken-seed#[D251F4D3C6FA0825]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44837/solr ready
> [junit4] 2> 2114951 INFO (qtp1313089676-22886) [ ] o.a.s.s.JWTAuthPlugin JWT Authentication attempt failed: Require authentication
> [junit4] 2> 2114974 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1499472627
> [junit4] 2> 2114974 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:44538_solr
> [junit4] 2> 2114974 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.c.ZkController Publish this node as DOWN...
> [junit4] 2> 2114974 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:44538_solr as DOWN
> [junit4] 2> 2114980 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=873691572
> [junit4] 2> 2114980 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:41707_solr
> [junit4] 2> 2114982 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.c.ZkController Publish this node as DOWN...
> [junit4] 2> 2114982 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:41707_solr as DOWN
> [junit4] 2> 2115022 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
> [junit4] 2> 2115022 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@cd5c633: rootName = solr_44538, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@20925144
> [junit4] 2> 2115025 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
> [junit4] 2> 2115025 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2a1ebc2c: rootName = solr_44538, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@97060e0
> [junit4] 2> 2115027 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
> [junit4] 2> 2115027 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@173cfa92: rootName = solr_44538, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@4b760b3f
> [junit4] 2> 2115027 INFO (jetty-closer-9020-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
> [junit4] 2> 2115030 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
> [junit4] 2> 2115046 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
> [junit4] 2> 2115046 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@415b98d2: rootName = solr_41707, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@3611a520
> [junit4] 2> 2115050 INFO (zkCallback-8996-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
> [junit4] 2> 2115051 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
> [junit4] 2> 2115051 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@67a2f75: rootName = solr_41707, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@97060e0
> [junit4] 2> 2115051 INFO (zkCallback-8989-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
> [junit4] 2> 2115053 INFO (jetty-closer-9020-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
> [junit4] 2> 2115053 INFO (jetty-closer-9020-threa
>
> [...truncated too long message...]
>
> s :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
>
> resolve:
>
> ivy-availability-check:
> [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
>
> -ivy-fail-disallowed-ivy-version:
>
> ivy-fail:
>
> ivy-fail:
>
> ivy-configure:
> [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
>
> resolve:
>
> ivy-availability-check:
> [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
>
> -ivy-fail-disallowed-ivy-version:
>
> ivy-fail:
>
> ivy-configure:
> [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
>
> resolve:
>
> ivy-availability-check:
> [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
>
> -ivy-fail-disallowed-ivy-version:
>
> ivy-fail:
>
> ivy-fail:
>
> ivy-configure:
> [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
>
> resolve:
>
> ivy-availability-check:
> [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
>
> -ivy-fail-disallowed-ivy-version:
>
> ivy-fail:
>
> ivy-configure:
> [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
>
> resolve:
>
> ivy-availability-check:
> [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
>
> -ivy-fail-disallowed-ivy-version:
>
> ivy-fail:
>
> ivy-fail:
>
> ivy-configure:
> [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
>
> resolve:
>
> ivy-availability-check:
> [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
>
> -ivy-fail-disallowed-ivy-version:
>
> ivy-fail:
>
> ivy-fail:
>
> ivy-configure:
> [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
>
> resolve:
>
> ivy-availability-check:
> [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
>
> -ivy-fail-disallowed-ivy-version:
>
> ivy-fail:
>
> ivy-fail:
>
> ivy-configure:
> [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
>
> resolve:
>
> ivy-availability-check:
> [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
>
> -ivy-fail-disallowed-ivy-version:
>
> ivy-fail:
>
> ivy-fail:
>
> ivy-configure:
> [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
>
> resolve:
>
> ivy-availability-check:
> [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
>
> -ivy-fail-disallowed-ivy-version:
>
> ivy-fail:
>
> ivy-fail:
>
> ivy-configure:
> [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
>
> resolve:
>
> ivy-availability-check:
> [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
>
> -ivy-fail-disallowed-ivy-version:
>
> ivy-fail:
>
> ivy-fail:
>
> ivy-configure:
> [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
>
> resolve:
>
> ivy-availability-check:
> [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
>
> -ivy-fail-disallowed-ivy-version:
>
> ivy-fail:
>
> ivy-fail:
>
> ivy-configure:
> [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
>
> resolve:
>
> ivy-availability-check:
> [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
>
> -ivy-fail-disallowed-ivy-version:
>
> ivy-fail:
>
> ivy-fail:
>
> ivy-configure:
> [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
>
> resolve:
>
> ivy-availability-check:
> [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
>
> -ivy-fail-disallowed-ivy-version:
>
> ivy-fail:
>
> ivy-fail:
>
> ivy-configure:
> [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
>
> resolve:
>
> ivy-availability-check:
> [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
>
> -ivy-fail-disallowed-ivy-version:
>
> ivy-fail:
>
> ivy-fail:
>
> ivy-configure:
> [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/lucene/top-level-ivy-settings.xml
>
> resolve:
>
> jar-checksums:
> [mkdir] Created dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/null2046754742
> [copy] Copying 239 files to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/null2046754742
> [delete] Deleting directory /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.1/solr/null2046754742
>
> check-working-copy:
> [ivy:cachepath] :: resolving dependencies :: #;working@lucene2-us-west.apache.org
> [ivy:cachepath] confs: [default]
> [ivy:cachepath] found org.eclipse.jgit#org.eclipse.jgit;5.3.0.201903130848-r in public
> [ivy:cachepath] found com.jcraft#jsch;0.1.54 in public
> [ivy:cachepath] found com.jcraft#jzlib;1.1.1 in public
> [ivy:cachepath] found com.googlecode.javaewah#JavaEWAH;1.1.6 in public
> [ivy:cachepath] found org.slf4j#slf4j-api;1.7.2 in public
> [ivy:cachepath] found org.bouncycastle#bcpg-jdk15on;1.60 in public
> [ivy:cachepath] found org.bouncycastle#bcprov-jdk15on;1.60 in public
> [ivy:cachepath] found org.bouncycastle#bcpkix-jdk15on;1.60 in public
> [ivy:cachepath] found org.slf4j#slf4j-nop;1.7.2 in public
> [ivy:cachepath] :: resolution report :: resolve 64ms :: artifacts dl 20ms
> ---------------------------------------------------------------------
> | | modules || artifacts |
> | conf | number| search|dwnlded|evicted|| number|dwnlded|
> ---------------------------------------------------------------------
> | default | 9 | 0 | 0 | 0 || 9 | 0 |
> ---------------------------------------------------------------------
> [wc-checker] Initializing working copy...
> [wc-checker] Checking working copy status...
>
> -jenkins-base:
>
> BUILD SUCCESSFUL
> Total time: 221 minutes 45 seconds
> Archiving artifacts
> java.lang.InterruptedException: no matches found within 10000
> at hudson.FilePath$ValidateAntFileMask.hasMatch(FilePath.java:2847)
> at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2726)
> at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2707)
> at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3086)
> Also: hudson.remoting.Channel$CallSiteStackTrace: Remote call to lucene2
> at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
> at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
> at hudson.remoting.Channel.call(Channel.java:955)
> at hudson.FilePath.act(FilePath.java:1072)
> at hudson.FilePath.act(FilePath.java:1061)
> at hudson.FilePath.validateAntFileMask(FilePath.java:2705)
> at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
> at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
> at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
> at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
> at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
> at hudson.model.Build$BuildExecution.post2(Build.java:186)
> at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
> at hudson.model.Run.execute(Run.java:1835)
> at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
> at hudson.model.ResourceController.execute(ResourceController.java:97)
> at hudson.model.Executor.run(Executor.java:429)
> Caused: hudson.FilePath$TunneledInterruptedException
> at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3088)
> at hudson.remoting.UserRequest.perform(UserRequest.java:212)
> at hudson.remoting.UserRequest.perform(UserRequest.java:54)
> at hudson.remoting.Request$2.run(Request.java:369)
> at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:748)
> Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000
> at hudson.FilePath.act(FilePath.java:1074)
> at hudson.FilePath.act(FilePath.java:1061)
> at hudson.FilePath.validateAntFileMask(FilePath.java:2705)
> at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
> at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
> at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
> at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
> at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
> at hudson.model.Build$BuildExecution.post2(Build.java:186)
> at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
> at hudson.model.Run.execute(Run.java:1835)
> at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
> at hudson.model.ResourceController.execute(ResourceController.java:97)
> at hudson.model.Executor.run(Executor.java:429)
> No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
> Recording test results
> Build step 'Publish JUnit test result report' changed build result to UNSTABLE
> Email was triggered for: Unstable (Test Failures)
> Sending email for trigger: Unstable (Test Failures)
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org