Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.6-Windows/31/ Java: 64bit/jdk-9-ea+181 -XX:-UseCompressedOops -XX:+UseSerialGC --illegal-access=deny
1 tests failed. FAILED: org.apache.solr.security.BasicAuthIntegrationTest.testBasicAuth Error Message: Error from server at https://127.0.0.1:49579/solr/authCollection: No registered leader was found after waiting for 4000ms , collection: authCollection slice: shard2 Stack Trace: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:49579/solr/authCollection: No registered leader was found after waiting for 4000ms , collection: authCollection slice: shard2 at __randomizedtesting.SeedInfo.seed([DBE9C69975F83041:6787B08BD1ABB33B]:0) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:612) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:279) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:268) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:447) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:388) at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1383) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1134) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:1073) at org.apache.solr.security.BasicAuthIntegrationTest.testBasicAuth(BasicAuthIntegrationTest.java:194) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.base/java.lang.Thread.run(Thread.java:844) Build Log: [...truncated 11854 lines...] [junit4] Suite: org.apache.solr.security.BasicAuthIntegrationTest [junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\init-core-data-001 [junit4] 2> 959729 INFO (SUITE-BasicAuthIntegrationTest-seed#[DBE9C69975F83041]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields [junit4] 2> 959734 INFO (SUITE-BasicAuthIntegrationTest-seed#[DBE9C69975F83041]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0) [junit4] 2> 959736 INFO (SUITE-BasicAuthIntegrationTest-seed#[DBE9C69975F83041]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 3 servers in C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001 [junit4] 2> 959736 INFO (SUITE-BasicAuthIntegrationTest-seed#[DBE9C69975F83041]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 959736 INFO (Thread-2432) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 959736 INFO (Thread-2432) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 959742 ERROR (Thread-2432) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes [junit4] 2> 959837 INFO (SUITE-BasicAuthIntegrationTest-seed#[DBE9C69975F83041]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:49574 [junit4] 2> 959849 INFO (jetty-launcher-1810-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 959849 INFO (jetty-launcher-1810-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 959849 INFO (jetty-launcher-1810-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 959850 INFO (jetty-launcher-1810-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7b56a071{/solr,null,AVAILABLE} [junit4] 2> 959850 INFO (jetty-launcher-1810-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@411a7e42{/solr,null,AVAILABLE} [junit4] 2> 959852 INFO (jetty-launcher-1810-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6d42a54a{SSL,[ssl, http/1.1]}{127.0.0.1:49578} [junit4] 2> 959852 INFO (jetty-launcher-1810-thread-1) [ ] o.e.j.s.Server Started @961912ms [junit4] 2> 959852 INFO (jetty-launcher-1810-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=49578} [junit4] 2> 959852 ERROR (jetty-launcher-1810-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 959852 INFO (jetty-launcher-1810-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1 [junit4] 2> 959852 INFO (jetty-launcher-1810-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 959852 INFO (jetty-launcher-1810-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 959852 INFO (jetty-launcher-1810-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-24T07:08:30.781336700Z [junit4] 2> 959854 INFO (jetty-launcher-1810-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4578e624{SSL,[ssl, http/1.1]}{127.0.0.1:49579} [junit4] 2> 959854 INFO (jetty-launcher-1810-thread-2) [ ] o.e.j.s.Server Started @961914ms [junit4] 2> 959854 INFO (jetty-launcher-1810-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=49579} [junit4] 2> 959854 INFO (jetty-launcher-1810-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@65192d3a{/solr,null,AVAILABLE} [junit4] 2> 959854 ERROR (jetty-launcher-1810-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 959854 INFO (jetty-launcher-1810-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1 [junit4] 2> 959854 INFO (jetty-launcher-1810-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 959854 INFO (jetty-launcher-1810-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 959854 INFO (jetty-launcher-1810-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-24T07:08:30.783395200Z [junit4] 2> 959855 INFO (jetty-launcher-1810-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4e1baa77{SSL,[ssl, http/1.1]}{127.0.0.1:49586} [junit4] 2> 959859 INFO (jetty-launcher-1810-thread-3) [ ] o.e.j.s.Server Started @961919ms [junit4] 2> 959859 INFO (jetty-launcher-1810-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=49586} [junit4] 2> 959859 ERROR (jetty-launcher-1810-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 959861 INFO (jetty-launcher-1810-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1 [junit4] 2> 959871 INFO (jetty-launcher-1810-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 959871 INFO (jetty-launcher-1810-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 959871 INFO (jetty-launcher-1810-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-24T07:08:30.800429700Z [junit4] 2> 959872 INFO (jetty-launcher-1810-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 959872 INFO (jetty-launcher-1810-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 959878 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15e1312284e0002, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 959878 INFO (jetty-launcher-1810-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 959879 INFO (jetty-launcher-1810-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 959880 INFO (jetty-launcher-1810-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:49574/solr [junit4] 2> 959880 INFO (jetty-launcher-1810-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 959881 INFO (jetty-launcher-1810-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:49574/solr [junit4] 2> 959885 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15e1312284e0003, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 959886 INFO (jetty-launcher-1810-thread-3) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 959888 INFO (jetty-launcher-1810-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:49574/solr [junit4] 2> 959891 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15e1312284e0008, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 959907 INFO (jetty-launcher-1810-thread-3) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 959907 INFO (jetty-launcher-1810-thread-2) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 959907 INFO (jetty-launcher-1810-thread-1) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 959909 INFO (jetty-launcher-1810-thread-3) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:49586_solr [junit4] 2> 959909 INFO (jetty-launcher-1810-thread-2) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49579_solr [junit4] 2> 959909 INFO (jetty-launcher-1810-thread-3) [ ] o.a.s.c.Overseer Overseer (id=98537210555269129-127.0.0.1:49586_solr-n_0000000000) starting [junit4] 2> 959909 INFO (jetty-launcher-1810-thread-1) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49578_solr [junit4] 2> 959911 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 959911 INFO (zkCallback-1827-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 959911 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 959913 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 959913 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 959913 INFO (zkCallback-1827-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 959917 INFO (jetty-launcher-1810-thread-3) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49586_solr [junit4] 2> 959944 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 959945 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 959945 INFO (zkCallback-1827-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 959961 INFO (jetty-launcher-1810-thread-3) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node3\. [junit4] 2> 959989 INFO (jetty-launcher-1810-thread-1) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node1\. [junit4] 2> 959998 INFO (jetty-launcher-1810-thread-2) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node2\. [junit4] 2> 960012 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15e1312284e000a, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 960016 INFO (SUITE-BasicAuthIntegrationTest-seed#[DBE9C69975F83041]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3) [junit4] 2> 960017 INFO (SUITE-BasicAuthIntegrationTest-seed#[DBE9C69975F83041]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:49574/solr ready [junit4] 2> 960047 INFO (qtp445964847-10383) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=authCollection&action=CREATE&numShards=3&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 960050 INFO (OverseerThreadFactory-5033-thread-1) [ ] o.a.s.c.CreateCollectionCmd Create collection authCollection [junit4] 2> 960163 INFO (qtp445964847-10414) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=authCollection_shard2_replica1&action=CREATE&numShards=3&collection=authCollection&shard=shard2&wt=javabin&version=2 [junit4] 2> 960163 INFO (qtp445964847-10414) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 960178 INFO (qtp1969321744-10390) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=authCollection_shard1_replica1&action=CREATE&numShards=3&collection=authCollection&shard=shard1&wt=javabin&version=2 [junit4] 2> 960178 INFO (qtp1969321744-10390) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 960183 INFO (qtp754365257-10378) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=authCollection_shard3_replica1&action=CREATE&numShards=3&collection=authCollection&shard=shard3&wt=javabin&version=2 [junit4] 2> 960183 INFO (qtp754365257-10378) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 960287 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 960287 INFO (zkCallback-1827-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 960289 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 961177 INFO (qtp445964847-10414) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1 [junit4] 2> 961185 INFO (qtp445964847-10414) [ ] o.a.s.s.IndexSchema [authCollection_shard2_replica1] Schema name=minimal [junit4] 2> 961187 INFO (qtp445964847-10414) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 961187 INFO (qtp445964847-10414) [ ] o.a.s.c.CoreContainer Creating SolrCore 'authCollection_shard2_replica1' using configuration from collection authCollection, trusted=true [junit4] 2> 961188 INFO (qtp445964847-10414) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 961188 INFO (qtp445964847-10414) [ ] o.a.s.c.SolrCore [[authCollection_shard2_replica1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node3\authCollection_shard2_replica1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node3\.\authCollection_shard2_replica1\data\] [junit4] 2> 961193 INFO (qtp754365257-10378) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1 [junit4] 2> 961193 INFO (qtp1969321744-10390) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1 [junit4] 2> 961209 INFO (qtp754365257-10378) [ ] o.a.s.s.IndexSchema [authCollection_shard3_replica1] Schema name=minimal [junit4] 2> 961210 INFO (qtp754365257-10378) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 961210 INFO (qtp1969321744-10390) [ ] o.a.s.s.IndexSchema [authCollection_shard1_replica1] Schema name=minimal [junit4] 2> 961210 INFO (qtp754365257-10378) [ ] o.a.s.c.CoreContainer Creating SolrCore 'authCollection_shard3_replica1' using configuration from collection authCollection, trusted=true [junit4] 2> 961212 INFO (qtp754365257-10378) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 961212 INFO (qtp754365257-10378) [ ] o.a.s.c.SolrCore [[authCollection_shard3_replica1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node1\authCollection_shard3_replica1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node1\.\authCollection_shard3_replica1\data\] [junit4] 2> 961213 INFO (qtp1969321744-10390) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 961213 INFO (qtp1969321744-10390) [ ] o.a.s.c.CoreContainer Creating SolrCore 'authCollection_shard1_replica1' using configuration from collection authCollection, trusted=true [junit4] 2> 961214 INFO (qtp1969321744-10390) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 961214 INFO (qtp1969321744-10390) [ ] o.a.s.c.SolrCore [[authCollection_shard1_replica1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node2\authCollection_shard1_replica1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node2\.\authCollection_shard1_replica1\data\] [junit4] 2> 961286 INFO (qtp445964847-10414) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 961286 INFO (qtp445964847-10414) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 961289 INFO (qtp445964847-10414) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 961289 INFO (qtp445964847-10414) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 961289 INFO (qtp445964847-10414) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@32100de5[authCollection_shard2_replica1] main] [junit4] 2> 961290 INFO (qtp754365257-10378) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 961290 INFO (qtp754365257-10378) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 961291 INFO (qtp445964847-10414) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 961291 INFO (qtp754365257-10378) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 961291 INFO (qtp754365257-10378) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 961291 INFO (qtp445964847-10414) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 961291 INFO (qtp445964847-10414) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 961291 INFO (qtp445964847-10414) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1576595370509598720 [junit4] 2> 961292 INFO (qtp754365257-10378) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5a749bdb[authCollection_shard3_replica1] main] [junit4] 2> 961292 INFO (searcherExecutor-5039-thread-1) [ ] o.a.s.c.SolrCore [authCollection_shard2_replica1] Registered new searcher Searcher@32100de5[authCollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 961293 INFO (qtp754365257-10378) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 961293 INFO (qtp754365257-10378) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 961293 INFO (qtp754365257-10378) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 961294 INFO (searcherExecutor-5040-thread-1) [ ] o.a.s.c.SolrCore [authCollection_shard3_replica1] Registered new searcher Searcher@5a749bdb[authCollection_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 961294 INFO (qtp754365257-10378) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1576595370512744448 [junit4] 2> 961295 INFO (qtp1969321744-10390) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 961295 INFO (qtp1969321744-10390) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 961296 INFO (qtp1969321744-10390) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 961296 INFO (qtp1969321744-10390) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 961299 INFO (qtp754365257-10378) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 961300 INFO (qtp754365257-10378) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 961300 INFO (qtp754365257-10378) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:49578/solr/authCollection_shard3_replica1/ [junit4] 2> 961300 INFO (qtp754365257-10378) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 961300 INFO (qtp754365257-10378) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:49578/solr/authCollection_shard3_replica1/ has no replicas [junit4] 2> 961300 INFO (qtp754365257-10378) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 961301 INFO (qtp445964847-10414) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 961301 INFO (qtp445964847-10414) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 961301 INFO (qtp445964847-10414) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:49586/solr/authCollection_shard2_replica1/ [junit4] 2> 961302 INFO (qtp445964847-10414) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 961302 INFO (qtp445964847-10414) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:49586/solr/authCollection_shard2_replica1/ has no replicas [junit4] 2> 961302 INFO (qtp445964847-10414) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 961302 INFO (qtp1969321744-10390) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@484c7215[authCollection_shard1_replica1] main] [junit4] 2> 961305 INFO (qtp754365257-10378) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:49578/solr/authCollection_shard3_replica1/ shard3 [junit4] 2> 961306 INFO (qtp445964847-10414) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:49586/solr/authCollection_shard2_replica1/ shard2 [junit4] 2> 961306 INFO (qtp1969321744-10390) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 961306 INFO (qtp1969321744-10390) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 961307 INFO (qtp1969321744-10390) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 961307 INFO (qtp1969321744-10390) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1576595370526375936 [junit4] 2> 961307 INFO (searcherExecutor-5041-thread-1) [ ] o.a.s.c.SolrCore [authCollection_shard1_replica1] Registered new searcher Searcher@484c7215[authCollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 961313 INFO (qtp1969321744-10390) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 961313 INFO (qtp1969321744-10390) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 961313 INFO (qtp1969321744-10390) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:49579/solr/authCollection_shard1_replica1/ [junit4] 2> 961313 INFO (qtp1969321744-10390) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 961313 INFO (qtp1969321744-10390) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:49579/solr/authCollection_shard1_replica1/ has no replicas [junit4] 2> 961313 INFO (qtp1969321744-10390) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 961318 INFO (qtp1969321744-10390) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:49579/solr/authCollection_shard1_replica1/ shard1 [junit4] 2> 961421 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 961421 INFO (zkCallback-1827-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 961421 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 961458 INFO (qtp754365257-10378) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 961459 INFO (qtp445964847-10414) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 961460 INFO (qtp754365257-10378) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=authCollection_shard3_replica1&action=CREATE&numShards=3&collection=authCollection&shard=shard3&wt=javabin&version=2} status=0 QTime=1277 [junit4] 2> 961460 INFO (qtp445964847-10414) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=authCollection_shard2_replica1&action=CREATE&numShards=3&collection=authCollection&shard=shard2&wt=javabin&version=2} status=0 QTime=1297 [junit4] 2> 961470 INFO (qtp1969321744-10390) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 961472 INFO (qtp1969321744-10390) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=authCollection_shard1_replica1&action=CREATE&numShards=3&collection=authCollection&shard=shard1&wt=javabin&version=2} status=0 QTime=1294 [junit4] 2> 961475 INFO (qtp445964847-10383) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas [junit4] 2> 961576 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 961576 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 961576 INFO (zkCallback-1827-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 962053 INFO (OverseerCollectionConfigSetProcessor-98537210555269129-127.0.0.1:49586_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 962476 INFO (qtp445964847-10383) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=authCollection&action=CREATE&numShards=3&wt=javabin&version=2} status=0 QTime=2428 [junit4] 2> 962498 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBasicAuth [junit4] 2> 962503 INFO (qtp445964847-10386) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authentication params={} status=0 QTime=0 [junit4] 2> 962506 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 962506 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 962508 INFO (qtp445964847-10387) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authentication params={} status=0 QTime=0 [junit4] 2> 962509 INFO (zkCallback-1827-thread-2) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 962510 INFO (zkCallback-1827-thread-2) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 962514 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 962514 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 962520 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 962523 INFO (zkCallback-1827-thread-2) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 962527 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 962531 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer PKIAuthenticationPlugin is managing internode requests [junit4] 2> 962531 INFO (zkCallback-1822-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Reconfiguring the default client with: org.apache.solr.security.PKIAuthenticationPlugin$HttpHeaderClientConfigurer@6e7dec01 [junit4] 2> 962531 INFO (zkCallback-1822-thread-1) [ ] o.a.s.u.UpdateShardHandler Reconfiguring the default client with: org.apache.solr.security.PKIAuthenticationPlugin$HttpHeaderClientConfigurer@6e7dec01 [junit4] 2> 962537 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer PKIAuthenticationPlugin is managing internode requests [junit4] 2> 962537 INFO (zkCallback-1823-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Reconfiguring the default client with: org.apache.solr.security.PKIAuthenticationPlugin$HttpHeaderClientConfigurer@2744396e [junit4] 2> 962537 INFO (zkCallback-1823-thread-1) [ ] o.a.s.u.UpdateShardHandler Reconfiguring the default client with: org.apache.solr.security.PKIAuthenticationPlugin$HttpHeaderClientConfigurer@2744396e [junit4] 2> 962541 INFO (zkCallback-1827-thread-2) [ ] o.a.s.c.CoreContainer PKIAuthenticationPlugin is managing internode requests [junit4] 2> 962542 INFO (zkCallback-1827-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Reconfiguring the default client with: org.apache.solr.security.PKIAuthenticationPlugin$HttpHeaderClientConfigurer@2763e6d1 [junit4] 2> 962542 INFO (zkCallback-1827-thread-2) [ ] o.a.s.u.UpdateShardHandler Reconfiguring the default client with: org.apache.solr.security.PKIAuthenticationPlugin$HttpHeaderClientConfigurer@2763e6d1 [junit4] 2> 962565 INFO (qtp445964847-10414) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authentication params={} status=0 QTime=1 [junit4] 2> 962567 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@4e1baa77{SSL,[ssl, http/1.1]}{127.0.0.1:0} [junit4] 2> 962567 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=105800240 [junit4] 2> 962568 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 962568 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm [junit4] 2> 962568 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty [junit4] 2> 962570 INFO (coreCloseExecutor-5054-thread-1) [ ] o.a.s.c.SolrCore [authCollection_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@5354f5e6 [junit4] 2> 962572 INFO (coreCloseExecutor-5054-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.authCollection.shard2.replica1 [junit4] 2> 962573 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.c.Overseer Overseer (id=98537210555269129-127.0.0.1:49586_solr-n_0000000000) closing [junit4] 2> 962573 INFO (OverseerStateUpdate-98537210555269129-127.0.0.1:49586_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:49586_solr [junit4] 2> 962576 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15e1312284e0009, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 962576 WARN (zkCallback-1827-thread-2) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 962577 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@65192d3a{/solr,null,UNAVAILABLE} [junit4] 2> 962577 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 962577 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 962577 INFO (zkCallback-1834-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 962578 INFO (zkCallback-1823-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:49579_solr [junit4] 2> 962580 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 962580 INFO (zkCallback-1823-thread-2) [ ] o.a.s.c.Overseer Overseer (id=98537210555269127-127.0.0.1:49579_solr-n_0000000001) starting [junit4] 2> 962581 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5d99b24e{/solr,null,AVAILABLE} [junit4] 2> 962583 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@36832308{SSL,[ssl, http/1.1]}{127.0.0.1:49654} [junit4] 2> 962583 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.e.j.s.Server Started @964643ms [junit4] 2> 962585 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=49654} [junit4] 2> 962586 ERROR (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 962586 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1 [junit4] 2> 962586 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 962586 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 962586 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-24T07:08:33.515453900Z [junit4] 2> 962591 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 962596 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [2]) [junit4] 2> 962596 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15e1312284e000c, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 962596 INFO (zkCallback-1823-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [2]) [junit4] 2> 962599 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 962600 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:49574/solr [junit4] 2> 962604 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15e1312284e000d, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 962613 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 962616 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 962618 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49654_solr [junit4] 2> 962665 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 962665 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 962665 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.c.CoreContainer PKIAuthenticationPlugin is managing internode requests [junit4] 2> 962665 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.h.c.HttpShardHandlerFactory Reconfiguring the default client with: org.apache.solr.security.PKIAuthenticationPlugin$HttpHeaderClientConfigurer@20a46d8f [junit4] 2> 962665 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.u.UpdateShardHandler Reconfiguring the default client with: org.apache.solr.security.PKIAuthenticationPlugin$HttpHeaderClientConfigurer@20a46d8f [junit4] 2> 962670 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 962671 INFO (zkCallback-1834-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 962671 INFO (zkCallback-1823-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 962671 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 962719 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node3\. [junit4] 2> 962720 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [authCollection_shard2_replica1] [junit4] 2> 962728 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 962835 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 962835 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 962835 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 963740 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1 [junit4] 2> 963745 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.s.IndexSchema [authCollection_shard2_replica1] Schema name=minimal [junit4] 2> 963746 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 963747 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'authCollection_shard2_replica1' using configuration from collection authCollection, trusted=true [junit4] 2> 963747 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 963747 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.c.SolrCore [[authCollection_shard2_replica1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node3\authCollection_shard2_replica1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node3\.\authCollection_shard2_replica1\data\] [junit4] 2> 963787 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 963787 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 963787 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 963787 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 963787 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@19d9ae1c[authCollection_shard2_replica1] main] [junit4] 2> 963796 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 963797 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 963797 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 963797 INFO (searcherExecutor-5064-thread-1) [ ] o.a.s.c.SolrCore [authCollection_shard2_replica1] Registered new searcher Searcher@19d9ae1c[authCollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 963797 INFO (coreLoadExecutor-5063-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1576595373137330176 [junit4] 2> 963801 INFO (coreZkRegister-5057-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms [junit4] 2> 963905 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 963905 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 963905 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 964248 INFO (qtp959443097-10483) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authentication params={} status=0 QTime=0 [junit4] 2> 964253 INFO (qtp1969321744-10412) [ ] o.a.s.s.RuleBasedAuthorizationPlugin request has come without principal. failed permission { [junit4] 2> "name":"security-edit", [junit4] 2> "role":"admin"} [junit4] 2> 964253 INFO (qtp1969321744-10412) [ ] o.a.s.s.HttpSolrCall USER_REQUIRED auth header null context : userPrincipal: [null] type: [ADMIN], collections: [], Path: [/____v2/cluster/security/authentication] path : /____v2/cluster/security/authentication params :wt=javabin&version=2 [junit4] 2> 964259 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.s.BasicAuthIntegrationTest Added Basic Auth security Header c29scjpTb2xyUm9ja3M= [junit4] 2> 964263 INFO (qtp959443097-10492) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authentication params={} status=0 QTime=0 [junit4] 2> 964270 INFO (qtp959443097-10483) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authentication params={} status=0 QTime=2 [junit4] 2> 964271 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 964271 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 964271 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 964271 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 964271 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 964271 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 964273 INFO (qtp1969321744-10394) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authentication params={} status=0 QTime=0 [junit4] 2> 964274 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.s.BasicAuthIntegrationTest Added Basic Auth security Header c29scjpTb2xyUm9ja3M= [junit4] 2> 964278 INFO (qtp1969321744-10382) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authorization params={} status=0 QTime=1 [junit4] 2> 964279 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 964280 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 964280 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 964280 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 964280 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 964280 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 964280 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 964280 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 964280 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 964282 INFO (qtp959443097-10489) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authorization params={} status=0 QTime=0 [junit4] 2> 964282 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.s.BasicAuthIntegrationTest Added Basic Auth security Header aGFycnk6SGFycnlJc1ViZXJDb29s [junit4] 2> 964287 INFO (qtp959443097-10484) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authorization params={} status=0 QTime=2 [junit4] 2> 964288 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 964289 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 964289 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 964289 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 964289 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 964289 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 964289 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 964290 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 964290 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 964291 INFO (qtp959443097-10489) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authorization params={} status=0 QTime=0 [junit4] 2> 964292 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.s.BasicAuthIntegrationTest Added Basic Auth security Header aGFycnk6SGFycnlJc1ViZXJDb29s [junit4] 2> 964296 INFO (qtp959443097-10493) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authorization params={} status=0 QTime=1 [junit4] 2> 964297 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 964297 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 964298 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 964298 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 964298 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 964298 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 964298 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 964298 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 964298 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 964301 INFO (qtp959443097-10483) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authorization params={} status=0 QTime=0 [junit4] 2> 964305 INFO (qtp959443097-10493) [ ] o.a.s.s.RuleBasedAuthorizationPlugin request has come without principal. failed permission { [junit4] 2> "name":"collection-admin-edit", [junit4] 2> "role":"admin", [junit4] 2> "index":3} [junit4] 2> 964306 INFO (qtp959443097-10493) [ ] o.a.s.s.HttpSolrCall USER_REQUIRED auth header null context : userPrincipal: [null] type: [ADMIN], collections: [authCollection,], Path: [/admin/collections] path : /admin/collections params :name=authCollection&action=RELOAD&wt=javabin&version=2 [junit4] 2> 964308 INFO (qtp959443097-10489) [ ] o.a.s.s.RuleBasedAuthorizationPlugin request has come without principal. failed permission { [junit4] 2> "name":"collection-admin-edit", [junit4] 2> "role":"admin", [junit4] 2> "index":3} [junit4] 2> 964308 INFO (qtp959443097-10489) [ ] o.a.s.s.HttpSolrCall USER_REQUIRED auth header null context : userPrincipal: [null] type: [ADMIN], collections: [], Path: [/admin/collections] path : /admin/collections params :name=authCollection&action=RELOAD&wt=javabin&version=2 [junit4] 2> 964310 INFO (qtp1969321744-10412) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :reload with params name=authCollection&action=RELOAD&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 964314 INFO (OverseerThreadFactory-5061-thread-1) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=RELOAD [junit4] 2> 964343 INFO (qtp1969321744-10390) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/key params={omitHeader=true&wt=json} status=0 QTime=0 [junit4] 2> 964344 INFO (qtp754365257-10408) [ ] o.a.s.s.PKIAuthenticationPlugin New Key obtained from node: 127.0.0.1:49579_solr / MIGfMA0GCSqGSIb3DQEBAQUAA4GNADCBiQKBgQC2btHrR3mL1wT3bZC8rePwUtV0yezJLNO36hulmRCdTpFeIr9D+dTNI05/VIxJzRfuNSlcHJ3VTaLLjIaWjG21WUKWG4HBLrFntDzt+XTilME/lxmjtbwGDMLbHuC2tUzVD8gnBUAeYP0XaZsir2pXV7akWoUdFpnnyPOXCfqs8QIDAQAB [junit4] 2> 964344 INFO (qtp1969321744-10413) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/key params={omitHeader=true&wt=json} status=0 QTime=0 [junit4] 2> 964344 INFO (qtp1969321744-10398) [ ] o.a.s.s.PKIAuthenticationPlugin New Key obtained from node: 127.0.0.1:49579_solr / MIGfMA0GCSqGSIb3DQEBAQUAA4GNADCBiQKBgQC2btHrR3mL1wT3bZC8rePwUtV0yezJLNO36hulmRCdTpFeIr9D+dTNI05/VIxJzRfuNSlcHJ3VTaLLjIaWjG21WUKWG4HBLrFntDzt+XTilME/lxmjtbwGDMLbHuC2tUzVD8gnBUAeYP0XaZsir2pXV7akWoUdFpnnyPOXCfqs8QIDAQAB [junit4] 2> 964354 INFO (qtp1969321744-10398) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1 [junit4] 2> 964354 INFO (qtp754365257-10408) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1 [junit4] 2> 964361 INFO (qtp754365257-10408) [ ] o.a.s.s.IndexSchema [authCollection_shard3_replica1] Schema name=minimal [junit4] 2> 964361 INFO (qtp1969321744-10398) [ ] o.a.s.s.IndexSchema [authCollection_shard1_replica1] Schema name=minimal [junit4] 2> 964364 INFO (qtp1969321744-10398) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 964364 INFO (qtp1969321744-10398) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'authCollection_shard1_replica1' using configuration from collection authCollection [junit4] 2> 964364 INFO (qtp754365257-10408) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 964364 INFO (qtp754365257-10408) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'authCollection_shard3_replica1' using configuration from collection authCollection [junit4] 2> 964365 INFO (qtp1969321744-10398) [ ] o.a.s.c.SolrCore [[authCollection_shard1_replica1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node2\authCollection_shard1_replica1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node2\.\authCollection_shard1_replica1\data\] [junit4] 2> 964365 INFO (qtp754365257-10408) [ ] o.a.s.c.SolrCore [[authCollection_shard3_replica1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node1\authCollection_shard3_replica1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001\tempDir-001\node1\.\authCollection_shard3_replica1\data\] [junit4] 2> 964454 INFO (qtp1969321744-10398) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 964454 INFO (qtp1969321744-10398) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 964455 INFO (qtp1969321744-10398) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4f06860c[authCollection_shard1_replica1] main] [junit4] 2> 964456 INFO (qtp1969321744-10398) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 964457 INFO (qtp1969321744-10398) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 964457 INFO (qtp1969321744-10398) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 964457 INFO (qtp1969321744-10398) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1576595373829390336 [junit4] 2> 964459 INFO (qtp1969321744-10398) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 964460 INFO (searcherExecutor-5070-thread-1) [ ] o.a.s.c.SolrCore [authCollection_shard1_replica1] Registered new searcher Searcher@4f06860c[authCollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 964460 INFO (qtp1969321744-10398) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5d530934[authCollection_shard1_replica1] main] [junit4] 2> 964461 INFO (qtp1969321744-10398) [ ] o.a.s.c.SolrCore [authCollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@3ff7b0fb [junit4] 2> 964461 INFO (qtp754365257-10408) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 964461 INFO (qtp754365257-10408) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 964461 INFO (qtp1969321744-10398) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.authCollection.shard1.replica1 [junit4] 2> 964461 INFO (qtp1969321744-10398) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=authCollection_shard1_replica1&qt=/admin/cores&action=RELOAD&wt=javabin&version=2} status=0 QTime=116 [junit4] 2> 964461 INFO (qtp754365257-10408) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5e1a6f79[authCollection_shard3_replica1] main] [junit4] 2> 964462 INFO (searcherExecutor-5070-thread-1) [ ] o.a.s.c.SolrCore [authCollection_shard1_replica1] Registered new searcher Searcher@5d530934[authCollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 964462 INFO (qtp754365257-10408) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 964462 INFO (qtp754365257-10408) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 964462 INFO (qtp754365257-10408) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 964462 INFO (searcherExecutor-5069-thread-1) [ ] o.a.s.c.SolrCore [authCollection_shard3_replica1] Registered new searcher Searcher@5e1a6f79[authCollection_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 964463 INFO (qtp754365257-10408) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1576595373835681792 [junit4] 2> 964464 INFO (qtp754365257-10408) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 964464 INFO (qtp754365257-10408) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@21ca2d4b[authCollection_shard3_replica1] main] [junit4] 2> 964465 INFO (qtp754365257-10408) [ ] o.a.s.c.SolrCore [authCollection_shard3_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@505de5cf [junit4] 2> 964465 INFO (searcherExecutor-5069-thread-1) [ ] o.a.s.c.SolrCore [authCollection_shard3_replica1] Registered new searcher Searcher@21ca2d4b[authCollection_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 964465 INFO (qtp754365257-10408) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.authCollection.shard3.replica1 [junit4] 2> 964465 INFO (qtp754365257-10408) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=authCollection_shard3_replica1&qt=/admin/cores&action=RELOAD&wt=javabin&version=2} status=0 QTime=121 [junit4] 2> 964467 INFO (qtp1969321744-10412) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=authCollection&action=RELOAD&wt=javabin&version=2} status=0 QTime=156 [junit4] 2> 964470 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.s.BasicAuthIntegrationTest Added Basic Auth security Header aGFycnk6SGFycnlJc1ViZXJDb29s [junit4] 2> 964475 INFO (qtp959443097-10482) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/security/authorization params={} status=0 QTime=1 [junit4] 2> 964476 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 964476 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 964477 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 964477 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 964478 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 964478 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 964478 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Security node changed, reloading security.json [junit4] 2> 964478 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin [junit4] 2> 964478 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin [junit4] 2> 966316 INFO (OverseerCollectionConfigSetProcessor-98537210555269127-127.0.0.1:49579_solr-n_0000000001) [ ] 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> 968522 INFO (qtp1969321744-10411) [ ] o.a.s.u.p.LogUpdateProcessorFactory [authCollection_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{} 0 4044 [junit4] 2> 968522 ERROR (qtp1969321744-10411) [ ] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: No registered leader was found after waiting for 4000ms , collection: authCollection slice: shard2 [junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:748) [junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:734) [junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.setupRequest(DistributedUpdateProcessor.java:400) [junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.setupRequest(DistributedUpdateProcessor.java:346) [junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.processAdd(DistributedUpdateProcessor.java:703) [junit4] 2> at org.apache.solr.update.processor.LogUpdateProcessorFactory$LogUpdateProcessor.processAdd(LogUpdateProcessorFactory.java:103) [junit4] 2> at org.apache.solr.handler.loader.JavabinLoader$1.update(JavabinLoader.java:98) [junit4] 2> at org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec$1.readOuterMostDocIterator(JavaBinUpdateRequestCodec.java:180) [junit4] 2> at org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec$1.readIterator(JavaBinUpdateRequestCodec.java:136) [junit4] 2> at org.apache.solr.common.util.JavaBinCodec.readObject(JavaBinCodec.java:306) [junit4] 2> at org.apache.solr.common.util.JavaBinCodec.readVal(JavaBinCodec.java:251) [junit4] 2> at org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec$1.readNamedList(JavaBinUpdateRequestCodec.java:122) [junit4] 2> at org.apache.solr.common.util.JavaBinCodec.readObject(JavaBinCodec.java:271) [junit4] 2> at org.apache.solr.common.util.JavaBinCodec.readVal(JavaBinCodec.java:251) [junit4] 2> at org.apache.solr.common.util.JavaBinCodec.unmarshal(JavaBinCodec.java:173) [junit4] 2> at org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec.unmarshal(JavaBinUpdateRequestCodec.java:187) [junit4] 2> at org.apache.solr.handler.loader.JavabinLoader.parseAndLoadDocs(JavabinLoader.java:108) [junit4] 2> at org.apache.solr.handler.loader.JavabinLoader.load(JavabinLoader.java:55) [junit4] 2> at org.apache.solr.handler.UpdateRequestHandler$1.load(UpdateRequestHandler.java:97) [junit4] 2> at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:68) [junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:173) [junit4] 2> at org.apache.solr.core.SolrCore.execute(SolrCore.java:2477) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.execute(HttpSolrCall.java:723) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:529) [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:361) [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:305) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699) [junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582) [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224) [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) [junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:395) [junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) [junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534) [junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320) [junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) [junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) [junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) [junit4] 2> at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:202) [junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) [junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) [junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) [junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) [junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> [junit4] 2> 968523 ERROR (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.c.s.i.CloudSolrClient Request to collection authCollection failed due to (503) org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:49579/solr/authCollection: No registered leader was found after waiting for 4000ms , collection: authCollection slice: shard2, retry? 0 [junit4] 2> 968524 INFO (TEST-BasicAuthIntegrationTest.testBasicAuth-seed#[DBE9C69975F83041]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testBasicAuth [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicAuthIntegrationTest -Dtests.method=testBasicAuth -Dtests.seed=DBE9C69975F83041 -Dtests.slow=true -Dtests.locale=ki -Dtests.timezone=Arctic/Longyearbyen -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1 [junit4] ERROR 6.05s J1 | BasicAuthIntegrationTest.testBasicAuth <<< [junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:49579/solr/authCollection: No registered leader was found after waiting for 4000ms , collection: authCollection slice: shard2 [junit4] > at __randomizedtesting.SeedInfo.seed([DBE9C69975F83041:6787B08BD1ABB33B]:0) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:612) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:279) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:268) [junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:447) [junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:388) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1383) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1134) [junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:1073) [junit4] > at org.apache.solr.security.BasicAuthIntegrationTest.testBasicAuth(BasicAuthIntegrationTest.java:194) [junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:564) [junit4] > at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 968527 INFO (jetty-closer-1811-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@36832308{SSL,[ssl, http/1.1]}{127.0.0.1:0} [junit4] 2> 968528 INFO (jetty-closer-1811-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=440209878 [junit4] 2> 968528 INFO (jetty-closer-1811-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 968528 INFO (jetty-closer-1811-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm [junit4] 2> 968528 INFO (jetty-closer-1811-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@6d42a54a{SSL,[ssl, http/1.1]}{127.0.0.1:0} [junit4] 2> 968528 INFO (jetty-closer-1811-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty [junit4] 2> 968528 INFO (jetty-closer-1811-thread-3) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@4578e624{SSL,[ssl, http/1.1]}{127.0.0.1:0} [junit4] 2> 968529 INFO (jetty-closer-1811-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=977412263 [junit4] 2> 968529 INFO (jetty-closer-1811-thread-3) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=760329505 [junit4] 2> 968529 INFO (jetty-closer-1811-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 968529 INFO (jetty-closer-1811-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm [junit4] 2> 968529 INFO (jetty-closer-1811-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 968529 INFO (jetty-closer-1811-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty [junit4] 2> 968529 INFO (jetty-closer-1811-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm [junit4] 2> 968529 INFO (jetty-closer-1811-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty [junit4] 2> 968532 INFO (coreCloseExecutor-5077-thread-1) [ ] o.a.s.c.SolrCore [authCollection_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@127aaca7 [junit4] 2> 968532 INFO (coreCloseExecutor-5078-thread-1) [ ] o.a.s.c.SolrCore [authCollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@596d20b6 [junit4] 2> 968532 INFO (coreCloseExecutor-5079-thread-1) [ ] o.a.s.c.SolrCore [authCollection_shard3_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@61f0e4ad [junit4] 2> 968532 INFO (coreCloseExecutor-5079-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.authCollection.shard3.replica1 [junit4] 2> 968534 INFO (coreCloseExecutor-5078-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.authCollection.shard1.replica1 [junit4] 2> 968534 INFO (coreCloseExecutor-5077-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.authCollection.shard2.replica1 [junit4] 2> 968534 INFO (zkCallback-1823-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 968535 INFO (zkCallback-1839-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 968535 INFO (zkCallback-1822-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/authCollection/state.json] for collection [authCollection] has occurred - updating... (live nodes size: [3]) [junit4] 2> 968538 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15e1312284e000e, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 968538 INFO (zkCallback-1823-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1) [junit4] 2> 968538 INFO (jetty-closer-1811-thread-3) [ ] o.a.s.c.Overseer Overseer (id=98537210555269127-127.0.0.1:49579_solr-n_0000000001) closing [junit4] 2> 968540 WARN (zkCallback-1839-thread-3) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 968540 INFO (OverseerStateUpdate-98537210555269127-127.0.0.1:49579_solr-n_0000000001) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:49579_solr [junit4] 2> 968542 WARN (zkCallback-1823-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 968542 INFO (jetty-closer-1811-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@411a7e42{/solr,null,UNAVAILABLE} [junit4] 2> 969807 ERROR (coreZkRegister-5057-thread-1) [ ] o.a.s.c.ZkController Error getting leader from zk [junit4] 2> org.apache.solr.common.SolrException: CoreContainer is closed [junit4] 2> at org.apache.solr.cloud.ZkController.getLeaderProps(ZkController.java:1040) [junit4] 2> at org.apache.solr.cloud.ZkController.getLeaderProps(ZkController.java:1007) [junit4] 2> at org.apache.solr.cloud.ZkController.getLeader(ZkController.java:963) [junit4] 2> at org.apache.solr.cloud.ZkController.register(ZkController.java:902) [junit4] 2> at org.apache.solr.cloud.ZkController.register(ZkController.java:846) [junit4] 2> at org.apache.solr.core.ZkContainer.lambda$registerInZk$0(ZkContainer.java:181) [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 969807 ERROR (coreZkRegister-5057-thread-1) [ ] o.a.s.c.ZkContainer :org.apache.solr.common.SolrException: Error getting leader from zk for shard shard2 [junit4] 2> at org.apache.solr.cloud.ZkController.getLeader(ZkController.java:996) [junit4] 2> at org.apache.solr.cloud.ZkController.register(ZkController.java:902) [junit4] 2> at org.apache.solr.cloud.ZkController.register(ZkController.java:846) [junit4] 2> at org.apache.solr.core.ZkContainer.lambda$registerInZk$0(ZkContainer.java:181) [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> Caused by: org.apache.solr.common.SolrException: CoreContainer is closed [junit4] 2> at org.apache.solr.cloud.ZkController.getLeaderProps(ZkController.java:1040) [junit4] 2> at org.apache.solr.cloud.ZkController.getLeaderProps(ZkController.java:1007) [junit4] 2> at org.apache.solr.cloud.ZkController.getLeader(ZkController.java:963) [junit4] 2> ... 7 more [junit4] 2> [junit4] 2> 969808 INFO (jetty-closer-1811-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5d99b24e{/solr,null,UNAVAILABLE} [junit4] 2> 970035 WARN (zkCallback-1822-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /collections/authCollection/state.json] [junit4] 2> 970035 INFO (jetty-closer-1811-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7b56a071{/solr,null,UNAVAILABLE} [junit4] 2> 970037 ERROR (SUITE-BasicAuthIntegrationTest-seed#[DBE9C69975F83041]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes [junit4] 2> 970037 INFO (SUITE-BasicAuthIntegrationTest-seed#[DBE9C69975F83041]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:49574 49574 [junit4] 2> 970038 INFO (Thread-2432) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:49574 49574 [junit4] 2> 970038 WARN (Thread-2432) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 5 /solr/aliases.json [junit4] 2> 4 /solr/security.json [junit4] 2> 4 /solr/configs/conf [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 5 /solr/clusterstate.json [junit4] 2> 5 /solr/clusterprops.json [junit4] 2> 4 /solr/collections/authCollection/state.json [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 5 /solr/collections [junit4] 2> 4 /solr/live_nodes [junit4] 2> 2 /solr/overseer/queue [junit4] 2> 2 /solr/overseer/collection-queue-work [junit4] 2> [junit4] 2> 970038 INFO (SUITE-BasicAuthIntegrationTest-seed#[DBE9C69975F83041]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-6.6-Windows\solr\build\solr-core\test\J1\temp\solr.security.BasicAuthIntegrationTest_DBE9C69975F83041-001 [junit4] 2> Aug 24, 2017 7:08:40 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks [junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s). [junit4] 2> NOTE: test params are: codec=Asserting(Lucene62), sim=RandomSimilarity(queryNorm=true,coord=yes): {}, locale=ki, timezone=Arctic/Longyearbyen [junit4] 2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 9 (64-bit)/cpus=3,threads=1,free=131775680,total=518979584 [junit4] 2> NOTE: All tests run in this JVM: [RegexBoostProcessorTest, DefaultValueUpdateProcessorTest, TestQuerySenderListener, IndexSchemaTest, MultiThreadedOCPTest, TestTrie, LukeRequestHandlerTest, TestClusterProperties, SolrInfoMBeanTest, CloneFieldUpdateProcessorFactoryTest, TestSchemaNameResource, RankQueryTest, DistributedIntervalFacetingTest, HighlighterConfigTest, AtomicUpdatesTest, TestShortCircuitedRequests, ShowFileRequestHandlerTest, TestFreeTextSuggestions, TestDynamicLoading, ExternalFileFieldSortTest, OpenCloseCoreStressTest, SolrMetricManagerTest, TestEmbeddedSolrServerSchemaAPI, TlogReplayBufferedWhileIndexingTest, SuggesterWFSTTest, HdfsWriteToMultipleCollectionsTest, TestDownShardTolerantSearch, TestMinMaxOnMultiValuedField, TestValueSourceCache, CollectionsAPIDistributedZkTest, TestCloudManagedSchema, TestBlendedInfixSuggestions, ZkStateWriterTest, TestSolr4Spatial, BufferStoreTest, TestPayloadScoreQParserPlugin, VMParamsZkACLAndCredentialsProvidersTest, QueryResultKeyTest, TestMiniSolrCloudCluster, ResourceLoaderTest, LeaderFailureAfterFreshStartTest, EchoParamsTest, TestRandomCollapseQParserPlugin, TestXmlQParser, TestRecovery, TestSerializedLuceneMatchVersion, PKIAuthenticationIntegrationTest, BinaryUpdateRequestHandlerTest, TestCodecSupport, TestSolrConfigHandler, TestWriterPerf, TestShardHandlerFactory, TestObjectReleaseTracker, IgnoreCommitOptimizeUpdateProcessorFactoryTest, DeleteNodeTest, TestImpersonationWithHadoopAuth, StatsReloadRaceTest, DataDrivenBlockJoinTest, HLLSerializationTest, SpatialRPTFieldTypeTest, TestSolrCLIRunExample, TestLeaderElectionZkExpiry, TestAddFieldRealTimeGet, BadIndexSchemaTest, TestExportWriter, TestRandomFlRTGCloud, TestSolrQueryParser, TestJoin, CoreMergeIndexesAdminHandlerTest, TestCloudNestedDocsSort, TestPushWriter, TestMacroExpander, TestStressInPlaceUpdates, MissingSegmentRecoveryTest, TestBlobHandler, TestCoreAdminApis, CollectionsAPISolrJTest, SolrMetricsIntegrationTest, TestTolerantUpdateProcessorCloud, TestPKIAuthenticationPlugin, CurrencyFieldOpenExchangeTest, HdfsChaosMonkeySafeLeaderTest, CdcrBootstrapTest, RuleEngineTest, CdcrVersionReplicationTest, BigEndianAscendingWordSerializerTest, OverseerTaskQueueTest, TestSubQueryTransformerCrossCore, SpellingQueryConverterTest, SmileWriterTest, TestSolrCoreProperties, TestDeleteCollectionOnDownNodes, SolrCmdDistributorTest, TestFoldingMultitermQuery, OutOfBoxZkACLAndCredentialsProvidersTest, TestManagedStopFilterFactory, ReplaceNodeTest, QueryParsingTest, SolrIndexConfigTest, TestBinaryResponseWriter, TestRawTransformer, DirectUpdateHandlerOptimizeTest, DistributedExpandComponentTest, SuggesterTest, CreateCollectionCleanupTest, ConfigSetsAPITest, TestFieldCollectionResource, TestFiltering, WordBreakSolrSpellCheckerTest, DocValuesMissingTest, SolrIndexSplitterTest, CollectionReloadTest, DistributedFacetPivotLargeTest, TestTrackingShardHandlerFactory, DistributedVersionInfoTest, FacetPivotSmallTest, SparseHLLTest, TestUtils, UUIDFieldTest, TestConfigOverlay, ExitableDirectoryReaderTest, TestStressUserVersions, TestDocSet, TestSimpleQParserPlugin, SharedFSAutoReplicaFailoverUtilsTest, ConvertedLegacyTest, CheckHdfsIndexTest, FieldMutatingUpdateProcessorTest, TestSuggestSpellingConverter, TestJsonFacetRefinement, TestOmitPositions, ExplicitHLLTest, BasicDistributedZk2Test, DistribJoinFromCollectionTest, SSLMigrationTest, HighlighterMaxOffsetTest, TestExactStatsCache, TestSolrXml, ShardRoutingCustomTest, MetricsHandlerTest, TestPathTrie, BasicAuthIntegrationTest] [junit4] Completed [273/713 (1!)] on J1 in 10.58s, 1 test, 1 error <<< FAILURES! [...truncated 37816 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
