You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2019/04/05 12:22:57 UTC
[JENKINS] Lucene-Solr-master-Windows (64bit/jdk-12) - Build # 7875
- Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/7875/
Java: 64bit/jdk-12 -XX:+UseCompressedOops -XX:+UseSerialGC
2 tests failed.
FAILED: org.apache.solr.security.AuditLoggerIntegrationTest.testAsyncQueueDrain
Error Message:
Expecting <2 callbacks in buffer, was 2
Stack Trace:
java.lang.AssertionError: Expecting <2 callbacks in buffer, was 2
at __randomizedtesting.SeedInfo.seed([1A22FA94FBCDBD88:AB3D05B04B0E2E57]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.solr.security.AuditLoggerIntegrationTest.testAsyncQueueDrain(AuditLoggerIntegrationTest.java:128)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:567)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:835)
FAILED: org.apache.solr.security.AuditLoggerIntegrationTest.testAsyncQueueDrain
Error Message:
Failed waiting for 3 callbacks after 5 seconds
Stack Trace:
java.lang.AssertionError: Failed waiting for 3 callbacks after 5 seconds
at __randomizedtesting.SeedInfo.seed([1A22FA94FBCDBD88:AB3D05B04B0E2E57]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.apache.solr.security.AuditLoggerIntegrationTest.waitForAuditEventCallbacks(AuditLoggerIntegrationTest.java:229)
at org.apache.solr.security.AuditLoggerIntegrationTest.waitForAuditEventCallbacks(AuditLoggerIntegrationTest.java:221)
at org.apache.solr.security.AuditLoggerIntegrationTest.assertThreeAdminEvents(AuditLoggerIntegrationTest.java:252)
at org.apache.solr.security.AuditLoggerIntegrationTest.testAsyncQueueDrain(AuditLoggerIntegrationTest.java:132)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:567)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:835)
Build Log:
[...truncated 15318 lines...]
[junit4] Suite: org.apache.solr.security.AuditLoggerIntegrationTest
[junit4] 2> 3998053 INFO (SUITE-AuditLoggerIntegrationTest-seed#[1A22FA94FBCDBD88]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.security.AuditLoggerIntegrationTest_1A22FA94FBCDBD88-001\init-core-data-001
[junit4] 2> 3998054 WARN (SUITE-AuditLoggerIntegrationTest-seed#[1A22FA94FBCDBD88]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=27 numCloses=27
[junit4] 2> 3998054 INFO (SUITE-AuditLoggerIntegrationTest-seed#[1A22FA94FBCDBD88]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 3998056 INFO (SUITE-AuditLoggerIntegrationTest-seed#[1A22FA94FBCDBD88]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl="None")
[junit4] 2> 3998058 INFO (TEST-AuditLoggerIntegrationTest.testSynchronous-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSynchronous
[junit4] 2> 3998061 INFO (auditTestCallback-18524-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Listening for audit callbacks on on port 56585
[junit4] 2> 3998061 INFO (TEST-AuditLoggerIntegrationTest.testSynchronous-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.security.AuditLoggerIntegrationTest_1A22FA94FBCDBD88-001\tempDir-001
[junit4] 2> 3998062 INFO (TEST-AuditLoggerIntegrationTest.testSynchronous-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 3998062 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 3998062 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 3998163 INFO (TEST-AuditLoggerIntegrationTest.testSynchronous-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer start zk server on port:56588
[junit4] 2> 3998163 INFO (TEST-AuditLoggerIntegrationTest.testSynchronous-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:56588
[junit4] 2> 3998163 INFO (TEST-AuditLoggerIntegrationTest.testSynchronous-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 56588
[junit4] 2> 3998169 INFO (zkConnectionManagerCallback-23484-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3998231 INFO (zkConnectionManagerCallback-23486-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3998236 INFO (zkConnectionManagerCallback-23488-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3998241 WARN (jetty-launcher-23489-thread-1) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
[junit4] 2> 3998241 INFO (jetty-launcher-23489-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
[junit4] 2> 3998241 INFO (jetty-launcher-23489-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 3998241 INFO (jetty-launcher-23489-thread-1) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 12+33
[junit4] 2> 3998242 INFO (jetty-launcher-23489-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 3998242 INFO (jetty-launcher-23489-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 3998242 INFO (jetty-launcher-23489-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 3998242 INFO (jetty-launcher-23489-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4aad439b{/solr,null,AVAILABLE}
[junit4] 2> 3998243 INFO (jetty-launcher-23489-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7ccb7afc{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:56599}
[junit4] 2> 3998243 INFO (jetty-launcher-23489-thread-1) [ ] o.e.j.s.Server Started @3998287ms
[junit4] 2> 3998243 INFO (jetty-launcher-23489-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=56599}
[junit4] 2> 3998243 ERROR (jetty-launcher-23489-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 3998243 INFO (jetty-launcher-23489-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 3998243 INFO (jetty-launcher-23489-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 3998243 INFO (jetty-launcher-23489-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 3998243 INFO (jetty-launcher-23489-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 3998243 INFO (jetty-launcher-23489-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-04-05T11:48:11.579621700Z
[junit4] 2> 3998281 INFO (zkConnectionManagerCallback-23491-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3998371 INFO (jetty-launcher-23489-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 3998635 INFO (jetty-launcher-23489-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 3998638 WARN (jetty-launcher-23489-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@4a6fcc86[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 3998642 WARN (jetty-launcher-23489-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@67e96719[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 3998643 INFO (jetty-launcher-23489-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:56588/solr
[junit4] 2> 3998646 INFO (zkConnectionManagerCallback-23498-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3998647 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1007540f4670004, likely client has closed socket
[junit4] 2> 3998650 INFO (zkConnectionManagerCallback-23500-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3998751 INFO (jetty-launcher-23489-thread-1) [n:127.0.0.1:56599_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:56599_solr
[junit4] 2> 3998751 INFO (jetty-launcher-23489-thread-1) [n:127.0.0.1:56599_solr ] o.a.s.c.Overseer Overseer (id=72186515876675589-127.0.0.1:56599_solr-n_0000000000) starting
[junit4] 2> 3998759 INFO (zkConnectionManagerCallback-23507-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3998761 INFO (jetty-launcher-23489-thread-1) [n:127.0.0.1:56599_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:56588/solr ready
[junit4] 2> 3998762 INFO (jetty-launcher-23489-thread-1) [n:127.0.0.1:56599_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56599_solr
[junit4] 2> 3998762 INFO (OverseerStateUpdate-72186515876675589-127.0.0.1:56599_solr-n_0000000000) [n:127.0.0.1:56599_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:56599_solr
[junit4] 2> 3998763 INFO (OverseerStateUpdate-72186515876675589-127.0.0.1:56599_solr-n_0000000000) [n:127.0.0.1:56599_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3998763 INFO (jetty-launcher-23489-thread-1) [n:127.0.0.1:56599_solr ] o.a.s.c.CoreContainer Initializing auditlogger plugin: solr.CallbackAuditLoggerPlugin
[junit4] 2> 3998773 INFO (zkCallback-23506-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3998855 INFO (jetty-launcher-23489-thread-1) [n:127.0.0.1:56599_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 3998914 INFO (jetty-launcher-23489-thread-1) [n:127.0.0.1:56599_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56599.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42392c26
[junit4] 2> 3998924 INFO (jetty-launcher-23489-thread-1) [n:127.0.0.1:56599_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56599.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42392c26
[junit4] 2> 3998924 INFO (jetty-launcher-23489-thread-1) [n:127.0.0.1:56599_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56599.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42392c26
[junit4] 2> 3998926 INFO (jetty-launcher-23489-thread-1) [n:127.0.0.1:56599_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.security.AuditLoggerIntegrationTest_1A22FA94FBCDBD88-001\tempDir-001\node1\.
[junit4] 2> 3998968 INFO (zkConnectionManagerCallback-23513-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3998996 INFO (TEST-AuditLoggerIntegrationTest.testSynchronous-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3999046 INFO (TEST-AuditLoggerIntegrationTest.testSynchronous-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:56588/solr ready
[junit4] 2> 3999054 INFO (qtp943676030-60024) [n:127.0.0.1:56599_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 3999056 INFO (qtp943676030-60024) [n:127.0.0.1:56599_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 3999079 INFO (qtp943676030-60024) [n:127.0.0.1:56599_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sent audit callback {"requestUrl":"http://127.0.0.1:56599/solr/admin/collections","nodeName":"n:127.0.0.1:56599_solr","message":"Completed","level":"INFO","date":1554464892392,"clientIp":"127.0.0.1","collections":[],"headers":{"User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:56599"},"solrParams":{"action":["LIST"],"wt":["javabin"],"version":["2"]},"solrHost":"127.0.0.1","solrPort":56599,"solrIp":"127.0.0.1","resource":"/admin/collections","httpMethod":"GET","httpQueryString":"action=LIST&wt=javabin&version=2","eventType":"COMPLETED","requestType":"ADMIN","status":200,"qtime":0.0} to localhost:56585
[junit4] 2> 3999079 INFO (qtp943676030-60024) [n:127.0.0.1:56599_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :clusterstatus with params action=CLUSTERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 3999083 INFO (qtp943676030-60024) [n:127.0.0.1:56599_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=CLUSTERSTATUS&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 3999103 INFO (qtp943676030-60024) [n:127.0.0.1:56599_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sent audit callback {"requestUrl":"http://127.0.0.1:56599/solr/admin/collections","nodeName":"n:127.0.0.1:56599_solr","message":"Completed","level":"INFO","date":1554464892419,"clientIp":"127.0.0.1","collections":[],"headers":{"User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:56599"},"solrParams":{"action":["CLUSTERSTATUS"],"wt":["javabin"],"version":["2"]},"solrHost":"127.0.0.1","solrPort":56599,"solrIp":"127.0.0.1","resource":"/admin/collections","httpMethod":"GET","httpQueryString":"action=CLUSTERSTATUS&wt=javabin&version=2","eventType":"COMPLETED","requestType":"ADMIN","status":200,"qtime":2.0} to localhost:56585
[junit4] 2> 3999104 INFO (qtp943676030-60026) [n:127.0.0.1:56599_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 3999138 INFO (auditTestCallback-18524-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Received audit event for path /admin/collections
[junit4] 2> 3999147 INFO (auditTestCallback-18524-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Received audit event for path /admin/collections
[junit4] 2> 3999162 INFO (qtp943676030-60026) [n:127.0.0.1:56599_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=58
[junit4] 2> 3999175 INFO (qtp943676030-60026) [n:127.0.0.1:56599_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sent audit callback {"requestUrl":"http://127.0.0.1:56599/solr/admin/collections","nodeName":"n:127.0.0.1:56599_solr","message":"Completed","level":"INFO","date":1554464892498,"clientIp":"127.0.0.1","collections":[],"headers":{"User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:56599"},"solrParams":{"action":["OVERSEERSTATUS"],"wt":["javabin"],"version":["2"]},"solrHost":"127.0.0.1","solrPort":56599,"solrIp":"127.0.0.1","resource":"/admin/collections","httpMethod":"GET","httpQueryString":"action=OVERSEERSTATUS&wt=javabin&version=2","eventType":"COMPLETED","requestType":"ADMIN","status":200,"qtime":59.0} to localhost:56585
[junit4] 2> 3999183 INFO (auditTestCallback-18524-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Received audit event for path /admin/collections
[junit4] 2> 3999293 INFO (jetty-closer-23514-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1042642234
[junit4] 2> 3999293 INFO (jetty-closer-23514-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:56599_solr
[junit4] 2> 3999293 INFO (jetty-closer-23514-thread-1) [ ] o.a.s.c.CoreContainer Publish this node as DOWN...
[junit4] 2> 3999293 INFO (jetty-closer-23514-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:56599_solr as DOWN
[junit4] 2> 3999294 INFO (jetty-closer-23514-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 3999294 INFO (jetty-closer-23514-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 3999294 INFO (jetty-closer-23514-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4331094c: rootName = solr_56599, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@10830362
[junit4] 2> 3999299 INFO (jetty-closer-23514-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 3999300 INFO (jetty-closer-23514-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@44b46ef1: rootName = solr_56599, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@638fad63
[junit4] 2> 3999303 INFO (jetty-closer-23514-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 3999303 INFO (jetty-closer-23514-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@47e5a3b1: rootName = solr_56599, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@42868445
[junit4] 2> 3999303 INFO (jetty-closer-23514-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 3999303 INFO (jetty-closer-23514-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72186515876675589-127.0.0.1:56599_solr-n_0000000000) closing
[junit4] 2> 3999303 INFO (OverseerStateUpdate-72186515876675589-127.0.0.1:56599_solr-n_0000000000) [n:127.0.0.1:56599_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:56599_solr
[junit4] 2> 3999309 INFO (zkCallback-23506-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 3999309 INFO (OverseerAutoScalingTriggerThread-72186515876675589-127.0.0.1:56599_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 3999311 INFO (closeThreadPool-23517-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72186515876675589-127.0.0.1:56599_solr-n_0000000000) closing
[junit4] 2> 3999312 INFO (closeThreadPool-23517-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72186515876675589-127.0.0.1:56599_solr-n_0000000000) closing
[junit4] 2> 3999313 INFO (jetty-closer-23514-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@7ccb7afc{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0}
[junit4] 2> 3999314 INFO (jetty-closer-23514-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4aad439b{/solr,null,UNAVAILABLE}
[junit4] 2> 3999314 INFO (jetty-closer-23514-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 3999317 INFO (TEST-AuditLoggerIntegrationTest.testSynchronous-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 3999318 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/collections
[junit4] 2>
[junit4] 2> 3999320 INFO (TEST-AuditLoggerIntegrationTest.testSynchronous-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:56588
[junit4] 2> 3999320 INFO (TEST-AuditLoggerIntegrationTest.testSynchronous-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 56588
[junit4] 2> 4000351 INFO (TEST-AuditLoggerIntegrationTest.testSynchronous-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSynchronous
[junit4] 2> 4000355 INFO (TEST-AuditLoggerIntegrationTest.testAsyncQueueDrain-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testAsyncQueueDrain
[junit4] 2> 4000360 INFO (TEST-AuditLoggerIntegrationTest.testAsyncQueueDrain-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.security.AuditLoggerIntegrationTest_1A22FA94FBCDBD88-001\tempDir-002
[junit4] 2> 4000360 INFO (TEST-AuditLoggerIntegrationTest.testAsyncQueueDrain-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 4000365 INFO (auditTestCallback-18539-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Listening for audit callbacks on on port 56625
[junit4] 2> 4000365 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 4000365 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 4000460 INFO (TEST-AuditLoggerIntegrationTest.testAsyncQueueDrain-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer start zk server on port:56628
[junit4] 2> 4000460 INFO (TEST-AuditLoggerIntegrationTest.testAsyncQueueDrain-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:56628
[junit4] 2> 4000460 INFO (TEST-AuditLoggerIntegrationTest.testAsyncQueueDrain-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 56628
[junit4] 2> 4000480 INFO (zkConnectionManagerCallback-23519-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4000487 INFO (zkConnectionManagerCallback-23521-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4000495 INFO (zkConnectionManagerCallback-23523-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4000498 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1007540fd660002, likely client has closed socket
[junit4] 2> 4000500 WARN (jetty-launcher-23524-thread-1) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
[junit4] 2> 4000500 INFO (jetty-launcher-23524-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
[junit4] 2> 4000500 INFO (jetty-launcher-23524-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 4000500 INFO (jetty-launcher-23524-thread-1) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 12+33
[junit4] 2> 4000502 INFO (jetty-launcher-23524-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 4000502 INFO (jetty-launcher-23524-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 4000502 INFO (jetty-launcher-23524-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 4000503 INFO (jetty-launcher-23524-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@19636afc{/solr,null,AVAILABLE}
[junit4] 2> 4000505 INFO (jetty-launcher-23524-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7f04a117{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:56639}
[junit4] 2> 4000505 INFO (jetty-launcher-23524-thread-1) [ ] o.e.j.s.Server Started @4000547ms
[junit4] 2> 4000505 INFO (jetty-launcher-23524-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=56639}
[junit4] 2> 4000505 ERROR (jetty-launcher-23524-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 4000505 INFO (jetty-launcher-23524-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 4000505 INFO (jetty-launcher-23524-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 4000505 INFO (jetty-launcher-23524-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 4000505 INFO (jetty-launcher-23524-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 4000505 INFO (jetty-launcher-23524-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-04-05T11:48:13.841474900Z
[junit4] 2> 4000514 INFO (zkConnectionManagerCallback-23526-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4000517 INFO (jetty-launcher-23524-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 4000686 INFO (jetty-launcher-23524-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 4000688 WARN (jetty-launcher-23524-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@4e0c2bf5[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 4000693 WARN (jetty-launcher-23524-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@6ce0b4b9[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 4000694 INFO (jetty-launcher-23524-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:56628/solr
[junit4] 2> 4000697 INFO (zkConnectionManagerCallback-23533-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4000702 INFO (zkConnectionManagerCallback-23535-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4000801 INFO (jetty-launcher-23524-thread-1) [n:127.0.0.1:56639_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:56639_solr
[junit4] 2> 4000802 INFO (jetty-launcher-23524-thread-1) [n:127.0.0.1:56639_solr ] o.a.s.c.Overseer Overseer (id=72186516027604997-127.0.0.1:56639_solr-n_0000000000) starting
[junit4] 2> 4000811 INFO (zkConnectionManagerCallback-23542-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4000814 INFO (jetty-launcher-23524-thread-1) [n:127.0.0.1:56639_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:56628/solr ready
[junit4] 2> 4000815 INFO (jetty-launcher-23524-thread-1) [n:127.0.0.1:56639_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56639_solr
[junit4] 2> 4000815 INFO (OverseerStateUpdate-72186516027604997-127.0.0.1:56639_solr-n_0000000000) [n:127.0.0.1:56639_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:56639_solr
[junit4] 2> 4000817 INFO (OverseerStateUpdate-72186516027604997-127.0.0.1:56639_solr-n_0000000000) [n:127.0.0.1:56639_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 4000817 INFO (jetty-launcher-23524-thread-1) [n:127.0.0.1:56639_solr ] o.a.s.c.CoreContainer Initializing auditlogger plugin: solr.CallbackAuditLoggerPlugin
[junit4] 2> 4000825 INFO (zkCallback-23541-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 4000855 INFO (jetty-launcher-23524-thread-1) [n:127.0.0.1:56639_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 4000889 INFO (jetty-launcher-23524-thread-1) [n:127.0.0.1:56639_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56639.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42392c26
[junit4] 2> 4000901 INFO (jetty-launcher-23524-thread-1) [n:127.0.0.1:56639_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56639.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42392c26
[junit4] 2> 4000901 INFO (jetty-launcher-23524-thread-1) [n:127.0.0.1:56639_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56639.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42392c26
[junit4] 2> 4000903 INFO (jetty-launcher-23524-thread-1) [n:127.0.0.1:56639_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.security.AuditLoggerIntegrationTest_1A22FA94FBCDBD88-001\tempDir-002\node1\.
[junit4] 2> 4000951 INFO (zkConnectionManagerCallback-23549-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4000953 INFO (TEST-AuditLoggerIntegrationTest.testAsyncQueueDrain-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 4000956 INFO (TEST-AuditLoggerIntegrationTest.testAsyncQueueDrain-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:56628/solr ready
[junit4] 2> 4000961 INFO (qtp1613828963-60102) [n:127.0.0.1:56639_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 4000961 INFO (qtp1613828963-60102) [n:127.0.0.1:56639_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 4000962 INFO (qtp1613828963-60102) [n:127.0.0.1:56639_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :clusterstatus with params action=CLUSTERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 4000962 INFO (audit-23543-thread-1-processing-n:127.0.0.1:56639_solr) [n:127.0.0.1:56639_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sleeping for 100ms before sending callback
[junit4] 2> 4000963 INFO (qtp1613828963-60102) [n:127.0.0.1:56639_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=CLUSTERSTATUS&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 4000963 INFO (qtp1613828963-60102) [n:127.0.0.1:56639_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 4001245 INFO (audit-23543-thread-1-processing-n:127.0.0.1:56639_solr) [n:127.0.0.1:56639_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sent audit callback {"requestUrl":"http://127.0.0.1:56639/solr/admin/collections","nodeName":"n:127.0.0.1:56639_solr","message":"Completed","level":"INFO","date":1554464894297,"clientIp":"127.0.0.1","collections":[],"headers":{"User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:56639"},"solrParams":{"action":["LIST"],"wt":["javabin"],"version":["2"]},"solrHost":"127.0.0.1","solrPort":56639,"solrIp":"127.0.0.1","resource":"/admin/collections","httpMethod":"GET","httpQueryString":"action=LIST&wt=javabin&version=2","eventType":"COMPLETED","requestType":"ADMIN","status":200,"qtime":0.0} to localhost:56625
[junit4] 2> 4001245 INFO (audit-23543-thread-1-processing-n:127.0.0.1:56639_solr) [n:127.0.0.1:56639_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sleeping for 100ms before sending callback
[junit4] 2> 4001247 INFO (auditTestCallback-18539-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Received audit event for path /admin/collections
[junit4] 2> 4001256 INFO (qtp1613828963-60102) [n:127.0.0.1:56639_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=291
[junit4] 2> 4001256 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1007540fd660007, likely client has closed socket
[junit4] 2> 4001263 INFO (jetty-closer-23550-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=620603812
[junit4] 2> 4001263 INFO (jetty-closer-23550-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:56639_solr
[junit4] 2> 4001266 INFO (jetty-closer-23550-thread-1) [ ] o.a.s.c.CoreContainer Publish this node as DOWN...
[junit4] 2> 4001266 INFO (jetty-closer-23550-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:56639_solr as DOWN
[junit4] 2> 4001433 INFO (jetty-closer-23550-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 4001433 INFO (jetty-closer-23550-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 4001435 INFO (jetty-closer-23550-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@562633ee: rootName = solr_56639, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@13c0bfcc
[junit4] 2> 4001449 INFO (jetty-closer-23550-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 4001449 INFO (jetty-closer-23550-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@50e2ee64: rootName = solr_56639, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@638fad63
[junit4] 2> 4001454 INFO (jetty-closer-23550-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 4001454 INFO (jetty-closer-23550-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@e87dc4: rootName = solr_56639, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@42868445
[junit4] 2> 4001456 INFO (jetty-closer-23550-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 4001460 INFO (zkCallback-23541-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 4001461 INFO (jetty-closer-23550-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72186516027604997-127.0.0.1:56639_solr-n_0000000000) closing
[junit4] 2> 4001475 INFO (OverseerAutoScalingTriggerThread-72186516027604997-127.0.0.1:56639_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 4001483 INFO (OverseerStateUpdate-72186516027604997-127.0.0.1:56639_solr-n_0000000000) [n:127.0.0.1:56639_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:56639_solr
[junit4] 2> 4001507 INFO (audit-23543-thread-1-processing-n:127.0.0.1:56639_solr) [n:127.0.0.1:56639_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sent audit callback {"requestUrl":"http://127.0.0.1:56639/solr/admin/collections","nodeName":"n:127.0.0.1:56639_solr","message":"Completed","level":"INFO","date":1554464894299,"clientIp":"127.0.0.1","collections":[],"headers":{"User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:56639"},"solrParams":{"action":["CLUSTERSTATUS"],"wt":["javabin"],"version":["2"]},"solrHost":"127.0.0.1","solrPort":56639,"solrIp":"127.0.0.1","resource":"/admin/collections","httpMethod":"GET","httpQueryString":"action=CLUSTERSTATUS&wt=javabin&version=2","eventType":"COMPLETED","requestType":"ADMIN","status":200,"qtime":1.0} to localhost:56625
[junit4] 2> 4001507 INFO (audit-23543-thread-1-processing-n:127.0.0.1:56639_solr) [n:127.0.0.1:56639_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sleeping for 100ms before sending callback
[junit4] 2> 4001511 INFO (closeThreadPool-23553-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72186516027604997-127.0.0.1:56639_solr-n_0000000000) closing
[junit4] 2> 4001512 INFO (closeThreadPool-23553-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72186516027604997-127.0.0.1:56639_solr-n_0000000000) closing
[junit4] 2> 4001516 INFO (jetty-closer-23550-thread-1) [ ] o.a.s.s.AuditLoggerPlugin Shutting down async Auditlogger background thread(s)
[junit4] 2> 4001516 INFO (auditTestCallback-18539-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Received audit event for path /admin/collections
[junit4] 2> 4001531 INFO (audit-23543-thread-1-processing-n:127.0.0.1:56639_solr) [n:127.0.0.1:56639_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sent audit callback {"requestUrl":"http://127.0.0.1:56639/solr/admin/collections","nodeName":"n:127.0.0.1:56639_solr","message":"Completed","level":"INFO","date":1554464894592,"clientIp":"127.0.0.1","collections":[],"headers":{"User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:56639"},"solrParams":{"action":["OVERSEERSTATUS"],"wt":["javabin"],"version":["2"]},"solrHost":"127.0.0.1","solrPort":56639,"solrIp":"127.0.0.1","resource":"/admin/collections","httpMethod":"GET","httpQueryString":"action=OVERSEERSTATUS&wt=javabin&version=2","eventType":"COMPLETED","requestType":"ADMIN","status":200,"qtime":291.0} to localhost:56625
[junit4] 2> 4001533 INFO (jetty-closer-23550-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@7f04a117{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0}
[junit4] 2> 4001533 INFO (jetty-closer-23550-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@19636afc{/solr,null,UNAVAILABLE}
[junit4] 2> 4001536 INFO (jetty-closer-23550-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 4001543 INFO (TEST-AuditLoggerIntegrationTest.testAsyncQueueDrain-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 4001543 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxnFactory Ignoring unexpected runtime exception
[junit4] 2> => java.nio.channels.CancelledKeyException
[junit4] 2> at java.base/sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:71)
[junit4] 2> java.nio.channels.CancelledKeyException: null
[junit4] 2> at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:71) ~[?:?]
[junit4] 2> at sun.nio.ch.SelectionKeyImpl.readyOps(SelectionKeyImpl.java:130) ~[?:?]
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:212) ~[zookeeper-3.4.14.jar:3.4.14-4c25d480e66aadd371de8bd2fd8da255ac140bcf]
[junit4] 2> at java.lang.Thread.run(Thread.java:835) [?:?]
[junit4] 2> 4001543 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/collections
[junit4] 2>
[junit4] 2> 4001548 INFO (TEST-AuditLoggerIntegrationTest.testAsyncQueueDrain-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:56628
[junit4] 2> 4001548 INFO (TEST-AuditLoggerIntegrationTest.testAsyncQueueDrain-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 56628
[junit4] 2> 4008063 INFO (TEST-AuditLoggerIntegrationTest.testAsyncQueueDrain-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 4008063 INFO (TEST-AuditLoggerIntegrationTest.testAsyncQueueDrain-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:56628
[junit4] 2> 4008063 INFO (TEST-AuditLoggerIntegrationTest.testAsyncQueueDrain-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 56628
[junit4] 2> 4009070 INFO (TEST-AuditLoggerIntegrationTest.testAsyncQueueDrain-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testAsyncQueueDrain
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=AuditLoggerIntegrationTest -Dtests.method=testAsyncQueueDrain -Dtests.seed=1A22FA94FBCDBD88 -Dtests.slow=true -Dtests.locale=kkj-CM -Dtests.timezone=Pacific/Pitcairn -Dtests.asserts=true -Dtests.file.encoding=Cp1252
[junit4] FAILURE 8.72s J0 | AuditLoggerIntegrationTest.testAsyncQueueDrain <<<
[junit4] > Throwable #1: java.lang.AssertionError: Failed waiting for 3 callbacks after 5 seconds
[junit4] > at __randomizedtesting.SeedInfo.seed([1A22FA94FBCDBD88:AB3D05B04B0E2E57]:0)
[junit4] > at org.apache.solr.security.AuditLoggerIntegrationTest.waitForAuditEventCallbacks(AuditLoggerIntegrationTest.java:229)
[junit4] > at org.apache.solr.security.AuditLoggerIntegrationTest.waitForAuditEventCallbacks(AuditLoggerIntegrationTest.java:221)
[junit4] > at org.apache.solr.security.AuditLoggerIntegrationTest.assertThreeAdminEvents(AuditLoggerIntegrationTest.java:252)
[junit4] > at org.apache.solr.security.AuditLoggerIntegrationTest.testAsyncQueueDrain(AuditLoggerIntegrationTest.java:132)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:567)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:835)
[junit4] 2> 4009075 INFO (TEST-AuditLoggerIntegrationTest.auth-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.SolrTestCaseJ4 ###Starting auth
[junit4] 2> 4009077 INFO (TEST-AuditLoggerIntegrationTest.auth-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.security.AuditLoggerIntegrationTest_1A22FA94FBCDBD88-001\tempDir-003
[junit4] 2> 4009077 INFO (TEST-AuditLoggerIntegrationTest.auth-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 4009079 INFO (auditTestCallback-18554-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Listening for audit callbacks on on port 56702
[junit4] 2> 4009080 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 4009080 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 4009179 INFO (TEST-AuditLoggerIntegrationTest.auth-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer start zk server on port:56705
[junit4] 2> 4009179 INFO (TEST-AuditLoggerIntegrationTest.auth-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:56705
[junit4] 2> 4009179 INFO (TEST-AuditLoggerIntegrationTest.auth-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 56705
[junit4] 2> 4009188 INFO (zkConnectionManagerCallback-23556-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4009200 INFO (zkConnectionManagerCallback-23558-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4009207 INFO (zkConnectionManagerCallback-23560-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4009210 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x10075411f700002, likely client has closed socket
[junit4] 2> 4009211 WARN (jetty-launcher-23561-thread-1) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
[junit4] 2> 4009211 INFO (jetty-launcher-23561-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
[junit4] 2> 4009211 INFO (jetty-launcher-23561-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 4009211 INFO (jetty-launcher-23561-thread-1) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 12+33
[junit4] 2> 4009211 INFO (jetty-launcher-23561-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 4009212 INFO (jetty-launcher-23561-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 4009212 INFO (jetty-launcher-23561-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 4009212 INFO (jetty-launcher-23561-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6799fea9{/solr,null,AVAILABLE}
[junit4] 2> 4009213 INFO (jetty-launcher-23561-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@67e18b82{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:56716}
[junit4] 2> 4009213 INFO (jetty-launcher-23561-thread-1) [ ] o.e.j.s.Server Started @4009256ms
[junit4] 2> 4009213 INFO (jetty-launcher-23561-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=56716}
[junit4] 2> 4009214 ERROR (jetty-launcher-23561-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 4009214 INFO (jetty-launcher-23561-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 4009214 INFO (jetty-launcher-23561-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 4009214 INFO (jetty-launcher-23561-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 4009214 INFO (jetty-launcher-23561-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 4009214 INFO (jetty-launcher-23561-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-04-05T11:48:22.550489900Z
[junit4] 2> 4009218 INFO (zkConnectionManagerCallback-23563-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4009219 INFO (jetty-launcher-23561-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 4009224 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x10075411f700003, likely client has closed socket
[junit4] 2> 4009496 INFO (jetty-launcher-23561-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 4009497 WARN (jetty-launcher-23561-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@655ae65f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 4009502 WARN (jetty-launcher-23561-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@226e9c10[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 4009502 INFO (jetty-launcher-23561-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:56705/solr
[junit4] 2> 4009506 INFO (zkConnectionManagerCallback-23570-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4009510 INFO (zkConnectionManagerCallback-23572-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4009667 INFO (jetty-launcher-23561-thread-1) [n:127.0.0.1:56716_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:56716_solr
[junit4] 2> 4009667 INFO (jetty-launcher-23561-thread-1) [n:127.0.0.1:56716_solr ] o.a.s.c.Overseer Overseer (id=72186516598685701-127.0.0.1:56716_solr-n_0000000000) starting
[junit4] 2> 4009675 INFO (zkConnectionManagerCallback-23579-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4009679 INFO (jetty-launcher-23561-thread-1) [n:127.0.0.1:56716_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:56705/solr ready
[junit4] 2> 4009680 INFO (OverseerStateUpdate-72186516598685701-127.0.0.1:56716_solr-n_0000000000) [n:127.0.0.1:56716_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:56716_solr
[junit4] 2> 4009680 INFO (jetty-launcher-23561-thread-1) [n:127.0.0.1:56716_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56716_solr
[junit4] 2> 4009682 INFO (OverseerStateUpdate-72186516598685701-127.0.0.1:56716_solr-n_0000000000) [n:127.0.0.1:56716_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 4009683 INFO (jetty-launcher-23561-thread-1) [n:127.0.0.1:56716_solr ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin
[junit4] 2> 4009683 INFO (jetty-launcher-23561-thread-1) [n:127.0.0.1:56716_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin
[junit4] 2> 4009683 INFO (jetty-launcher-23561-thread-1) [n:127.0.0.1:56716_solr ] o.a.s.c.CoreContainer Initializing auditlogger plugin: solr.CallbackAuditLoggerPlugin
[junit4] 2> 4009712 INFO (jetty-launcher-23561-thread-1) [n:127.0.0.1:56716_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 4009736 INFO (jetty-launcher-23561-thread-1) [n:127.0.0.1:56716_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56716.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42392c26
[junit4] 2> 4009743 INFO (jetty-launcher-23561-thread-1) [n:127.0.0.1:56716_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56716.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42392c26
[junit4] 2> 4009743 INFO (jetty-launcher-23561-thread-1) [n:127.0.0.1:56716_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56716.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42392c26
[junit4] 2> 4009746 INFO (jetty-launcher-23561-thread-1) [n:127.0.0.1:56716_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.security.AuditLoggerIntegrationTest_1A22FA94FBCDBD88-001\tempDir-003\node1\.
[junit4] 2> 4009772 INFO (zkCallback-23578-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 4009776 INFO (zkConnectionManagerCallback-23585-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4009777 INFO (TEST-AuditLoggerIntegrationTest.auth-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 4009779 INFO (TEST-AuditLoggerIntegrationTest.auth-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:56705/solr ready
[junit4] 2> 4009783 INFO (qtp374720357-60177) [n:127.0.0.1:56716_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 4009783 INFO (qtp374720357-60177) [n:127.0.0.1:56716_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 4009802 INFO (auditTestCallback-18554-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Received audit event for path /admin/collections
[junit4] 2> 4009846 INFO (qtp374720357-60177) [n:127.0.0.1:56716_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sent audit callback {"requestUrl":"http://127.0.0.1:56716/solr/admin/collections","nodeName":"n:127.0.0.1:56716_solr","message":"Completed","level":"INFO","date":1554464903119,"clientIp":"127.0.0.1","collections":[],"headers":{"User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:56716"},"solrParams":{"action":["LIST"],"wt":["javabin"],"version":["2"]},"solrHost":"127.0.0.1","solrPort":56716,"solrIp":"127.0.0.1","resource":"/admin/collections","httpMethod":"GET","httpQueryString":"action=LIST&wt=javabin&version=2","eventType":"COMPLETED","requestType":"ADMIN","status":200,"qtime":0.0} to localhost:56702
[junit4] 2> 4009847 INFO (qtp374720357-60177) [n:127.0.0.1:56716_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 4009847 INFO (qtp374720357-60177) [n:127.0.0.1:56716_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 4009869 INFO (auditTestCallback-18554-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Received audit event for path /admin/collections
[junit4] 2> 4009881 INFO (qtp374720357-60177) [n:127.0.0.1:56716_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sent audit callback {"requestUrl":"http://127.0.0.1:56716/solr/admin/collections","nodeName":"n:127.0.0.1:56716_solr","message":"Completed","level":"INFO","date":1554464903183,"username":"solr","clientIp":"127.0.0.1","collections":[],"headers":{"Authorization":"Basic c29scjpTb2xyUm9ja3M=","User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:56716"},"solrParams":{"action":["LIST"],"wt":["javabin"],"version":["2"]},"solrHost":"127.0.0.1","solrPort":56716,"solrIp":"127.0.0.1","resource":"/admin/collections","httpMethod":"GET","httpQueryString":"action=LIST&wt=javabin&version=2","eventType":"COMPLETED","requestType":"ADMIN","status":200,"qtime":0.0} to localhost:56702
[junit4] 2> 4009881 INFO (qtp374720357-60177) [n:127.0.0.1:56716_solr ] o.a.s.s.RuleBasedAuthorizationPlugin request has come without principal. failed permission {
[junit4] 2> "name":"collection-admin-edit",
[junit4] 2> "role":"admin"}
[junit4] 2> 4009898 INFO (auditTestCallback-18554-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Received audit event for path /admin/collections
[junit4] 2> 4009898 INFO (qtp374720357-60177) [n:127.0.0.1:56716_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sent audit callback {"requestUrl":"http://127.0.0.1:56716/solr/admin/collections","nodeName":"n:127.0.0.1:56716_solr","message":"Rejected","level":"WARN","date":1554464903217,"clientIp":"127.0.0.1","collections":["test"],"headers":{"User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:56716"},"solrParams":{"pullReplicas":["0"],"name":["test"],"nrtReplicas":["1"],"action":["CREATE"],"numShards":["1"],"tlogReplicas":["0"],"wt":["javabin"],"version":["2"]},"solrHost":"127.0.0.1","solrPort":56716,"solrIp":"127.0.0.1","resource":"/admin/collections","httpMethod":"GET","httpQueryString":"action=CREATE&name=test&numShards=1&nrtReplicas=1&pullReplicas=0&tlogReplicas=0&wt=javabin&version=2","eventType":"REJECTED","requestType":"ADMIN","status":401,"qtime":-1.0} to localhost:56702
[junit4] 2> 4009898 INFO (qtp374720357-60177) [n:127.0.0.1:56716_solr ] o.a.s.s.HttpSolrCall USER_REQUIRED auth header null context : userPrincipal: [null] type: [ADMIN], collections: [test,], Path: [/admin/collections] path : /admin/collections params :pullReplicas=0&name=test&nrtReplicas=1&action=CREATE&numShards=1&tlogReplicas=0&wt=javabin&version=2
[junit4] 1> {"requestUrl":"http://127.0.0.1:56716/solr/admin/collections","nodeName":"n:127.0.0.1:56716_solr","message":"Completed","level":"INFO","date":1554464903183,"username":"solr","clientIp":"127.0.0.1","collections":[],"headers":{"Authorization":"Basic c29scjpTb2xyUm9ja3M=","User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:56716"},"solrParams":{"action":["LIST"],"wt":["javabin"],"version":["2"]},"solrHost":"127.0.0.1","solrPort":56716,"solrIp":"127.0.0.1","resource":"/admin/collections","httpMethod":"GET","httpQueryString":"action=LIST&wt=javabin&version=2","eventType":"COMPLETED","requestType":"ADMIN","status":200,"qtime":0.0}
[junit4] 2> 4009918 INFO (auditTestCallback-18554-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Received audit event for path /admin/collections
[junit4] 2> 4009920 INFO (qtp374720357-60177) [n:127.0.0.1:56716_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sent audit callback {"requestUrl":"http://127.0.0.1:56716/solr/admin/collections","nodeName":"n:127.0.0.1:56716_solr","message":"Unauthorized","level":"WARN","date":1554464903244,"clientIp":"127.0.0.1","collections":["test"],"headers":{"User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:56716"},"solrParams":{"pullReplicas":["0"],"name":["test"],"nrtReplicas":["1"],"action":["CREATE"],"numShards":["1"],"tlogReplicas":["0"],"wt":["javabin"],"version":["2"]},"solrHost":"127.0.0.1","solrPort":56716,"solrIp":"127.0.0.1","resource":"/admin/collections","httpMethod":"GET","httpQueryString":"action=CREATE&name=test&numShards=1&nrtReplicas=1&pullReplicas=0&tlogReplicas=0&wt=javabin&version=2","eventType":"UNAUTHORIZED","requestType":"ADMIN","status":403,"qtime":-1.0} to localhost:56702
[junit4] 2> 4009931 INFO (auditTestCallback-18554-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Received audit event for path /solr
[junit4] 2> 4009931 INFO (qtp374720357-60177) [n:127.0.0.1:56716_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sent audit callback {"requestUrl":"http://127.0.0.1:56716/solr/admin/collections","nodeName":"n:127.0.0.1:56716_solr","message":"Rejected","level":"WARN","date":1554464903258,"clientIp":"127.0.0.1","headers":{"Authorization":"Basic c29scjp3cm9uZ1BX","User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:56716"},"solrParams":{},"solrHost":"127.0.0.1","solrPort":56716,"solrIp":"127.0.0.1","resource":"/solr","httpMethod":"GET","httpQueryString":"action=CREATE&name=test&numShards=1&nrtReplicas=1&pullReplicas=0&tlogReplicas=0&wt=javabin&version=2","eventType":"REJECTED","requestType":"UNKNOWN","status":401,"qtime":-1.0} to localhost:56702
[junit4] 2> 4009936 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x10075411f700007, likely client has closed socket
[junit4] 2> 4009937 INFO (jetty-closer-23586-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1257678215
[junit4] 2> 4009937 INFO (jetty-closer-23586-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:56716_solr
[junit4] 2> 4009948 INFO (jetty-closer-23586-thread-1) [ ] o.a.s.c.CoreContainer Publish this node as DOWN...
[junit4] 2> 4009948 INFO (jetty-closer-23586-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:56716_solr as DOWN
[junit4] 2> 4009948 INFO (jetty-closer-23586-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 4009953 INFO (jetty-closer-23586-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 4009953 INFO (jetty-closer-23586-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4b735fa0: rootName = solr_56716, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@293763cc
[junit4] 2> 4009957 INFO (jetty-closer-23586-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 4009957 INFO (jetty-closer-23586-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4535d30d: rootName = solr_56716, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@638fad63
[junit4] 2> 4009959 INFO (jetty-closer-23586-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 4009959 INFO (jetty-closer-23586-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3597e8dc: rootName = solr_56716, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@42868445
[junit4] 2> 4009959 INFO (jetty-closer-23586-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 4009961 INFO (jetty-closer-23586-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72186516598685701-127.0.0.1:56716_solr-n_0000000000) closing
[junit4] 2> 4009964 INFO (OverseerAutoScalingTriggerThread-72186516598685701-127.0.0.1:56716_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 4009964 INFO (OverseerStateUpdate-72186516598685701-127.0.0.1:56716_solr-n_0000000000) [n:127.0.0.1:56716_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:56716_solr
[junit4] 2> 4009964 INFO (zkCallback-23578-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 4009965 INFO (closeThreadPool-23589-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72186516598685701-127.0.0.1:56716_solr-n_0000000000) closing
[junit4] 2> 4009965 INFO (closeThreadPool-23589-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72186516598685701-127.0.0.1:56716_solr-n_0000000000) closing
[junit4] 2> 4009968 INFO (jetty-closer-23586-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@67e18b82{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0}
[junit4] 2> 4009968 INFO (jetty-closer-23586-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6799fea9{/solr,null,UNAVAILABLE}
[junit4] 2> 4009968 INFO (jetty-closer-23586-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 4009969 INFO (TEST-AuditLoggerIntegrationTest.auth-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 4009970 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x10075411f700000, likely client has closed socket
[junit4] 2> 4009970 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/collections
[junit4] 2>
[junit4] 2> 4009972 INFO (TEST-AuditLoggerIntegrationTest.auth-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:56705
[junit4] 2> 4009972 INFO (TEST-AuditLoggerIntegrationTest.auth-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 56705
[junit4] 2> 4010998 INFO (TEST-AuditLoggerIntegrationTest.auth-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.SolrTestCaseJ4 ###Ending auth
[junit4] 2> 4011002 INFO (TEST-AuditLoggerIntegrationTest.testAsync-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testAsync
[junit4] 2> 4011002 INFO (TEST-AuditLoggerIntegrationTest.testAsync-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.security.AuditLoggerIntegrationTest_1A22FA94FBCDBD88-001\tempDir-004
[junit4] 2> 4011006 INFO (TEST-AuditLoggerIntegrationTest.testAsync-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 4011008 INFO (auditTestCallback-18569-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Listening for audit callbacks on on port 56754
[junit4] 2> 4011008 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 4011008 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 4011107 INFO (TEST-AuditLoggerIntegrationTest.testAsync-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer start zk server on port:56757
[junit4] 2> 4011107 INFO (TEST-AuditLoggerIntegrationTest.testAsync-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:56757
[junit4] 2> 4011107 INFO (TEST-AuditLoggerIntegrationTest.testAsync-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 56757
[junit4] 2> 4011113 INFO (zkConnectionManagerCallback-23591-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4011118 INFO (zkConnectionManagerCallback-23593-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4011122 INFO (zkConnectionManagerCallback-23595-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4011128 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x100754126f90002, likely client has closed socket
[junit4] 2> 4011129 WARN (jetty-launcher-23596-thread-1) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
[junit4] 2> 4011129 INFO (jetty-launcher-23596-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
[junit4] 2> 4011129 INFO (jetty-launcher-23596-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 4011129 INFO (jetty-launcher-23596-thread-1) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 12+33
[junit4] 2> 4011129 INFO (jetty-launcher-23596-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 4011129 INFO (jetty-launcher-23596-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 4011129 INFO (jetty-launcher-23596-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 4011129 INFO (jetty-launcher-23596-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1934d2b7{/solr,null,AVAILABLE}
[junit4] 2> 4011133 INFO (jetty-launcher-23596-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@40ace4a4{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:56768}
[junit4] 2> 4011133 INFO (jetty-launcher-23596-thread-1) [ ] o.e.j.s.Server Started @4011176ms
[junit4] 2> 4011133 INFO (jetty-launcher-23596-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=56768}
[junit4] 2> 4011133 ERROR (jetty-launcher-23596-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 4011133 INFO (jetty-launcher-23596-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 4011134 INFO (jetty-launcher-23596-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 4011134 INFO (jetty-launcher-23596-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 4011134 INFO (jetty-launcher-23596-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 4011134 INFO (jetty-launcher-23596-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-04-05T11:48:24.470327500Z
[junit4] 2> 4011148 INFO (zkConnectionManagerCallback-23598-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4011148 INFO (jetty-launcher-23596-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 4011336 INFO (jetty-launcher-23596-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 4011337 WARN (jetty-launcher-23596-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@5c69ab81[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 4011344 WARN (jetty-launcher-23596-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@26844c3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 4011345 INFO (jetty-launcher-23596-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:56757/solr
[junit4] 2> 4011347 INFO (zkConnectionManagerCallback-23605-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4011350 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x100754126f90004, likely client has closed socket
[junit4] 2> 4011354 INFO (zkConnectionManagerCallback-23607-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4011475 INFO (jetty-launcher-23596-thread-1) [n:127.0.0.1:56768_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:56768_solr
[junit4] 2> 4011475 INFO (jetty-launcher-23596-thread-1) [n:127.0.0.1:56768_solr ] o.a.s.c.Overseer Overseer (id=72186516725104645-127.0.0.1:56768_solr-n_0000000000) starting
[junit4] 2> 4011491 INFO (zkConnectionManagerCallback-23614-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4011494 INFO (jetty-launcher-23596-thread-1) [n:127.0.0.1:56768_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:56757/solr ready
[junit4] 2> 4011495 INFO (jetty-launcher-23596-thread-1) [n:127.0.0.1:56768_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56768_solr
[junit4] 2> 4011497 INFO (OverseerStateUpdate-72186516725104645-127.0.0.1:56768_solr-n_0000000000) [n:127.0.0.1:56768_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:56768_solr
[junit4] 2> 4011498 INFO (jetty-launcher-23596-thread-1) [n:127.0.0.1:56768_solr ] o.a.s.c.CoreContainer Initializing auditlogger plugin: solr.CallbackAuditLoggerPlugin
[junit4] 2> 4011506 INFO (OverseerStateUpdate-72186516725104645-127.0.0.1:56768_solr-n_0000000000) [n:127.0.0.1:56768_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 4011511 INFO (zkCallback-23613-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 4011543 INFO (jetty-launcher-23596-thread-1) [n:127.0.0.1:56768_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 4011567 INFO (jetty-launcher-23596-thread-1) [n:127.0.0.1:56768_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56768.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42392c26
[junit4] 2> 4011577 INFO (jetty-launcher-23596-thread-1) [n:127.0.0.1:56768_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56768.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42392c26
[junit4] 2> 4011577 INFO (jetty-launcher-23596-thread-1) [n:127.0.0.1:56768_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56768.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42392c26
[junit4] 2> 4011578 INFO (jetty-launcher-23596-thread-1) [n:127.0.0.1:56768_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.security.AuditLoggerIntegrationTest_1A22FA94FBCDBD88-001\tempDir-004\node1\.
[junit4] 2> 4011604 INFO (zkConnectionManagerCallback-23621-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 4011606 INFO (TEST-AuditLoggerIntegrationTest.testAsync-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 4011607 INFO (TEST-AuditLoggerIntegrationTest.testAsync-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:56757/solr ready
[junit4] 2> 4011611 INFO (qtp2065141184-60253) [n:127.0.0.1:56768_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 4011611 INFO (qtp2065141184-60253) [n:127.0.0.1:56768_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 4011662 INFO (qtp2065141184-60252) [n:127.0.0.1:56768_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :clusterstatus with params action=CLUSTERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 4011664 INFO (qtp2065141184-60252) [n:127.0.0.1:56768_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=CLUSTERSTATUS&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 4011664 INFO (qtp2065141184-60252) [n:127.0.0.1:56768_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 4011689 INFO (auditTestCallback-18569-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Received audit event for path /admin/collections
[junit4] 2> 4011727 INFO (qtp2065141184-60252) [n:127.0.0.1:56768_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=65
[junit4] 2> 4011742 INFO (audit-23615-thread-1-processing-n:127.0.0.1:56768_solr) [n:127.0.0.1:56768_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sent audit callback {"requestUrl":"http://127.0.0.1:56768/solr/admin/collections","nodeName":"n:127.0.0.1:56768_solr","message":"Completed","level":"INFO","date":1554464904947,"clientIp":"127.0.0.1","collections":[],"headers":{"User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:56768"},"solrParams":{"action":["LIST"],"wt":["javabin"],"version":["2"]},"solrHost":"127.0.0.1","solrPort":56768,"solrIp":"127.0.0.1","resource":"/admin/collections","httpMethod":"GET","httpQueryString":"action=LIST&wt=javabin&version=2","eventType":"COMPLETED","requestType":"ADMIN","status":200,"qtime":0.0} to localhost:56754
[junit4] 2> 4011753 INFO (audit-23615-thread-1-processing-n:127.0.0.1:56768_solr) [n:127.0.0.1:56768_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sent audit callback {"requestUrl":"http://127.0.0.1:56768/solr/admin/collections","nodeName":"n:127.0.0.1:56768_solr","message":"Completed","level":"INFO","date":1554464905000,"clientIp":"127.0.0.1","collections":[],"headers":{"User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:56768"},"solrParams":{"action":["CLUSTERSTATUS"],"wt":["javabin"],"version":["2"]},"solrHost":"127.0.0.1","solrPort":56768,"solrIp":"127.0.0.1","resource":"/admin/collections","httpMethod":"GET","httpQueryString":"action=CLUSTERSTATUS&wt=javabin&version=2","eventType":"COMPLETED","requestType":"ADMIN","status":200,"qtime":1.0} to localhost:56754
[junit4] 2> 4011764 INFO (auditTestCallback-18569-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Received audit event for path /admin/collections
[junit4] 2> 4011772 INFO (auditTestCallback-18569-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Received audit event for path /admin/collections
[junit4] 2> 4011772 INFO (audit-23615-thread-1-processing-n:127.0.0.1:56768_solr) [n:127.0.0.1:56768_solr ] o.a.s.s.CallbackAuditLoggerPlugin Sent audit callback {"requestUrl":"http://127.0.0.1:56768/solr/admin/collections","nodeName":"n:127.0.0.1:56768_solr","message":"Completed","level":"INFO","date":1554464905063,"clientIp":"127.0.0.1","collections":[],"headers":{"User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:56768"},"solrParams":{"action":["OVERSEERSTATUS"],"wt":["javabin"],"version":["2"]},"solrHost":"127.0.0.1","solrPort":56768,"solrIp":"127.0.0.1","resource":"/admin/collections","httpMethod":"GET","httpQueryString":"action=OVERSEERSTATUS&wt=javabin&version=2","eventType":"COMPLETED","requestType":"ADMIN","status":200,"qtime":65.0} to localhost:56754
[junit4] 2> 4011831 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x100754126f90007, likely client has closed socket
[junit4] 2> 4011833 INFO (jetty-closer-23622-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1425962535
[junit4] 2> 4011833 INFO (jetty-closer-23622-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:56768_solr
[junit4] 2> 4011835 INFO (jetty-closer-23622-thread-1) [ ] o.a.s.c.CoreContainer Publish this node as DOWN...
[junit4] 2> 4011835 INFO (jetty-closer-23622-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:56768_solr as DOWN
[junit4] 2> 4011837 INFO (jetty-closer-23622-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 4011837 INFO (jetty-closer-23622-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 4011837 INFO (jetty-closer-23622-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3ece377: rootName = solr_56768, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@1901b060
[junit4] 2> 4011842 INFO (jetty-closer-23622-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 4011842 INFO (jetty-closer-23622-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4bfbf012: rootName = solr_56768, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@638fad63
[junit4] 2> 4011846 INFO (jetty-closer-23622-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 4011846 INFO (jetty-closer-23622-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@362a112f: rootName = solr_56768, domain = solr.jetty, service url = null, agent id = null] for registry solr.jett
[...truncated too long message...]
:"n:127.0.0.1:59215_solr","message":"Completed","level":"INFO","date":1554466847259,"clientIp":"127.0.0.1","collections":[],"headers":{"User-Agent":"Solr[org.apache.solr.client.solrj.impl.HttpSolrClient] 1.0","Connection":"keep-alive","Host":"127.0.0.1:59215"},"solrParams":{"action":["OVERSEERSTATUS"],"wt":["javabin"],"version":["2"]},"solrHost":"127.0.0.1","solrPort":59215,"solrIp":"127.0.0.1","resource":"/admin/collections","httpMethod":"GET","httpQueryString":"action=OVERSEERSTATUS&wt=javabin&version=2","eventType":"COMPLETED","requestType":"ADMIN","status":200,"qtime":26.0} to localhost:59201
[junit4] 2> 53159 INFO (auditTestCallback-97-thread-1) [ ] o.a.s.s.AuditLoggerIntegrationTest Received audit event for path /admin/collections
[junit4] 2> 53160 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x100755ec5f40007, likely client has closed socket
[junit4] 2> 53163 INFO (jetty-closer-247-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=128645057
[junit4] 2> 53163 INFO (jetty-closer-247-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:59215_solr
[junit4] 2> 53164 INFO (jetty-closer-247-thread-1) [ ] o.a.s.c.CoreContainer Publish this node as DOWN...
[junit4] 2> 53164 INFO (jetty-closer-247-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:59215_solr as DOWN
[junit4] 2> 53168 INFO (jetty-closer-247-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 53173 INFO (jetty-closer-247-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 53173 INFO (jetty-closer-247-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3b75a422: rootName = solr_59215, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@682718d7
[junit4] 2> 53180 INFO (jetty-closer-247-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 53180 INFO (jetty-closer-247-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@56330934: rootName = solr_59215, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@1a59e2a6
[junit4] 2> 53184 INFO (jetty-closer-247-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 53184 INFO (jetty-closer-247-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@672d3a2b: rootName = solr_59215, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@516776de
[junit4] 2> 53184 INFO (jetty-closer-247-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 53188 INFO (closeThreadPool-250-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72186643946405893-127.0.0.1:59215_solr-n_0000000000) closing
[junit4] 2> 53188 INFO (OverseerStateUpdate-72186643946405893-127.0.0.1:59215_solr-n_0000000000) [n:127.0.0.1:59215_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:59215_solr
[junit4] 2> 53188 INFO (OverseerAutoScalingTriggerThread-72186643946405893-127.0.0.1:59215_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 53189 INFO (zkCallback-239-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 53197 INFO (closeThreadPool-250-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72186643946405893-127.0.0.1:59215_solr-n_0000000000) closing
[junit4] 2> 53197 INFO (jetty-closer-247-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72186643946405893-127.0.0.1:59215_solr-n_0000000000) closing
[junit4] 2> 53199 INFO (jetty-closer-247-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1d876c28{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0}
[junit4] 2> 53199 INFO (jetty-closer-247-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@71e37f11{/solr,null,UNAVAILABLE}
[junit4] 2> 53199 INFO (jetty-closer-247-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 53203 INFO (TEST-AuditLoggerIntegrationTest.testMuteAdminListCollections-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 53204 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/collections
[junit4] 2>
[junit4] 2> 53209 INFO (TEST-AuditLoggerIntegrationTest.testMuteAdminListCollections-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:59204
[junit4] 2> 53209 INFO (TEST-AuditLoggerIntegrationTest.testMuteAdminListCollections-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 59204
[junit4] 2> 54357 INFO (TEST-AuditLoggerIntegrationTest.testMuteAdminListCollections-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 54357 INFO (TEST-AuditLoggerIntegrationTest.testMuteAdminListCollections-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:59204
[junit4] 2> 54357 INFO (TEST-AuditLoggerIntegrationTest.testMuteAdminListCollections-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 59204
[junit4] 2> 55471 INFO (TEST-AuditLoggerIntegrationTest.testMuteAdminListCollections-seed#[1A22FA94FBCDBD88]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMuteAdminListCollections
[junit4] OK 4.26s J1 | AuditLoggerIntegrationTest.testMuteAdminListCollections
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.security.AuditLoggerIntegrationTest_1A22FA94FBCDBD88-001
[junit4] 2> NOTE: test params are: codec=Lucene80, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@42cb6825), locale=kkj-CM, timezone=Pacific/Pitcairn
[junit4] 2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 12 (64-bit)/cpus=3,threads=2,free=9077880,total=97517568
[junit4] 2> NOTE: All tests run in this JVM: [AuditLoggerIntegrationTest]
[junit4] Completed [1/5 (1!)] on J1 in 53.45s, 7 tests, 1 failure <<< FAILURES!
[...truncated 50 lines...]
BUILD FAILED
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\common-build.xml:1573: The following error occurred while executing this line:
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\common-build.xml:1100: There were test failures: 5 suites, 35 tests, 1 failure [seed: 1A22FA94FBCDBD88]
Total time: 1 minute 49 seconds
[repro] Setting last failure code to 1
[repro] Failures:
[repro] 1/5 failed: org.apache.solr.security.AuditLoggerIntegrationTest
[repro] Exiting with code 1
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows>IF EXIST lucene\build move /y lucene\build lucene\build.repro
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows>IF EXIST solr\build move /y solr\build solr\build.repro
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows>IF EXIST lucene\build.orig move /y lucene\build.orig lucene\build
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows>IF EXIST solr\build.orig move /y solr\build.orig solr\build
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows>exit 0
Archiving artifacts
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
[WARNINGS] Parsing warnings in console log with parser Java Compiler (javac)
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
No credentials specified
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
<Git Blamer> Using GitBlamer to create author and commit information for all warnings.
<Git Blamer> GIT_COMMIT=aadc94a6e3887955ed08439d32e29fe31b622a45, workspace=C:\Users\jenkins\workspace\Lucene-Solr-master-Windows
[WARNINGS] Computing warning deltas based on reference build #7874
Recording test results
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
[JENKINS] Lucene-Solr-master-Windows (64bit/jdk-11) - Build # 7876
- Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/7876/
Java: 64bit/jdk-11 -XX:+UseCompressedOops -XX:+UseParallelGC
2 tests failed.
FAILED: org.apache.solr.cloud.DocValuesNotIndexedTest.testGroupingSorting
Error Message:
Should have exactly 4 documents returned expected:<4> but was:<3>
Stack Trace:
java.lang.AssertionError: Should have exactly 4 documents returned expected:<4> but was:<3>
at __randomizedtesting.SeedInfo.seed([5D9D0D1BEA5AAE8D:43A5051396F1140D]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.failNotEquals(Assert.java:834)
at org.junit.Assert.assertEquals(Assert.java:645)
at org.apache.solr.cloud.DocValuesNotIndexedTest.checkSortOrder(DocValuesNotIndexedTest.java:262)
at org.apache.solr.cloud.DocValuesNotIndexedTest.testGroupingSorting(DocValuesNotIndexedTest.java:247)
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:566)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:834)
FAILED: junit.framework.TestSuite.org.apache.solr.client.solrj.impl.CloudHttp2SolrClientTest
Error Message:
ObjectTracker found 4 object(s) that were not released!!! [MockDirectoryWrapper, SolrCore, MockDirectoryWrapper, MockDirectoryWrapper] org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) at org.apache.solr.core.SolrCore.initSnapshotMetaDataManager(SolrCore.java:517) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:968) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:883) at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1245) at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1155) at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:92) at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360) at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396) at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188) at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.core.SolrCore at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1063) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:883) at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1245) at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1155) at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:92) at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360) at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396) at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188) at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:509) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:351) at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:422) at org.apache.solr.handler.ReplicationHandler.lambda$setupPolling$13(ReplicationHandler.java:1191) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) at org.apache.solr.update.SolrIndexWriter.create(SolrIndexWriter.java:99) at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:779) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:976) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:883) at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1245) at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1155) at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:92) at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360) at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396) at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188) at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834) expected null, but was:<ObjectTracker found 4 object(s) that were not released!!! [MockDirectoryWrapper, SolrCore, MockDirectoryWrapper, MockDirectoryWrapper] org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) at org.apache.solr.core.SolrCore.initSnapshotMetaDataManager(SolrCore.java:517) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:968) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:883) at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1245) at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1155) at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:92) at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360) at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396) at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188) at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.core.SolrCore at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1063) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:883) at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1245) at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1155) at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:92) at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360) at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396) at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188) at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:509) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:351) at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:422) at org.apache.solr.handler.ReplicationHandler.lambda$setupPolling$13(ReplicationHandler.java:1191) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) at org.apache.solr.update.SolrIndexWriter.create(SolrIndexWriter.java:99) at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:779) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:976) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:883) at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1245) at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1155) at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:92) at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360) at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396) at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188) at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834) >
Stack Trace:
java.lang.AssertionError: ObjectTracker found 4 object(s) that were not released!!! [MockDirectoryWrapper, SolrCore, MockDirectoryWrapper, MockDirectoryWrapper]
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348)
at org.apache.solr.core.SolrCore.initSnapshotMetaDataManager(SolrCore.java:517)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:968)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:883)
at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1245)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1155)
at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:92)
at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360)
at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396)
at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188)
at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.core.SolrCore
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1063)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:883)
at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1245)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1155)
at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:92)
at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360)
at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396)
at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188)
at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348)
at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:509)
at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:351)
at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:422)
at org.apache.solr.handler.ReplicationHandler.lambda$setupPolling$13(ReplicationHandler.java:1191)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348)
at org.apache.solr.update.SolrIndexWriter.create(SolrIndexWriter.java:99)
at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:779)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:976)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:883)
at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1245)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1155)
at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:92)
at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360)
at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396)
at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188)
at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
expected null, but was:<ObjectTracker found 4 object(s) that were not released!!! [MockDirectoryWrapper, SolrCore, MockDirectoryWrapper, MockDirectoryWrapper]
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348)
at org.apache.solr.core.SolrCore.initSnapshotMetaDataManager(SolrCore.java:517)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:968)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:883)
at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1245)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1155)
at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:92)
at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360)
at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396)
at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188)
at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.core.SolrCore
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1063)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:883)
at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1245)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1155)
at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:92)
at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360)
at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396)
at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188)
at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348)
at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:509)
at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:351)
at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:422)
at org.apache.solr.handler.ReplicationHandler.lambda$setupPolling$13(ReplicationHandler.java:1191)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348)
at org.apache.solr.update.SolrIndexWriter.create(SolrIndexWriter.java:99)
at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:779)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:976)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:883)
at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1245)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1155)
at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:92)
at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360)
at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396)
at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188)
at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
>
at __randomizedtesting.SeedInfo.seed([6A6133522733A8B9]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.failNotNull(Assert.java:755)
at org.junit.Assert.assertNull(Assert.java:737)
at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:325)
at jdk.internal.reflect.GeneratedMethodAccessor41.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:901)
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:834)
Build Log:
[...truncated 14215 lines...]
[junit4] Suite: org.apache.solr.cloud.DocValuesNotIndexedTest
[junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.DocValuesNotIndexedTest_5D9D0D1BEA5AAE8D-001\init-core-data-001
[junit4] 2> 2277857 WARN (SUITE-DocValuesNotIndexedTest-seed#[5D9D0D1BEA5AAE8D]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=105 numCloses=105
[junit4] 2> 2277858 INFO (SUITE-DocValuesNotIndexedTest-seed#[5D9D0D1BEA5AAE8D]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 2277858 INFO (SUITE-DocValuesNotIndexedTest-seed#[5D9D0D1BEA5AAE8D]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 2277858 INFO (SUITE-DocValuesNotIndexedTest-seed#[5D9D0D1BEA5AAE8D]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 2277878 INFO (TEST-DocValuesNotIndexedTest.testDistribFaceting-seed#[5D9D0D1BEA5AAE8D]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDistribFaceting
[junit4] 2> 2277878 INFO (TEST-DocValuesNotIndexedTest.testDistribFaceting-seed#[5D9D0D1BEA5AAE8D]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.DocValuesNotIndexedTest_5D9D0D1BEA5AAE8D-001\tempDir-001
[junit4] 2> 2277882 INFO (TEST-DocValuesNotIndexedTest.testDistribFaceting-seed#[5D9D0D1BEA5AAE8D]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2277898 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2277898 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2277983 INFO (TEST-DocValuesNotIndexedTest.testDistribFaceting-seed#[5D9D0D1BEA5AAE8D]) [ ] o.a.s.c.ZkTestServer start zk server on port:55455
[junit4] 2> 2277983 INFO (TEST-DocValuesNotIndexedTest.testDistribFaceting-seed#[5D9D0D1BEA5AAE8D]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:55455
[junit4] 2> 2277983 INFO (TEST-DocValuesNotIndexedTest.testDistribFaceting-seed#[5D9D0D1BEA5AAE8D]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 55455
[junit4] 2> 2277993 INFO (zkConnectionManagerCallback-13371-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2278007 INFO (zkConnectionManagerCallback-13373-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2278016 INFO (zkConnectionManagerCallback-13375-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2278019 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x10086d1d1490002, likely client has closed socket
[junit4] 2> 2278023 WARN (jetty-launcher-13376-thread-1) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
[junit4] 2> 2278023 INFO (jetty-launcher-13376-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
[junit4] 2> 2278023 INFO (jetty-launcher-13376-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 2278023 INFO (jetty-launcher-13376-thread-1) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 11+28
[junit4] 2> 2278025 INFO (jetty-launcher-13376-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2278027 WARN (jetty-launcher-13376-thread-2) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
[junit4] 2> 2278027 INFO (jetty-launcher-13376-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
[junit4] 2> 2278027 INFO (jetty-launcher-13376-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 2278027 INFO (jetty-launcher-13376-thread-2) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 11+28
[junit4] 2> 2278027 INFO (jetty-launcher-13376-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2278027 INFO (jetty-launcher-13376-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2278027 INFO (jetty-launcher-13376-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 2278027 INFO (jetty-launcher-13376-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@179993ae{/solr,null,AVAILABLE}
[junit4] 2> 2278029 INFO (jetty-launcher-13376-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2278029 INFO (jetty-launcher-13376-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 2278029 INFO (jetty-launcher-13376-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@322ca0d1{/solr,null,AVAILABLE}
[junit4] 2> 2278038 INFO (jetty-launcher-13376-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@191eada9{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:55469}
[junit4] 2> 2278038 INFO (jetty-launcher-13376-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@32a7abfe{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:55466}
[junit4] 2> 2278038 INFO (jetty-launcher-13376-thread-2) [ ] o.e.j.s.Server Started @2278089ms
[junit4] 2> 2278038 INFO (jetty-launcher-13376-thread-1) [ ] o.e.j.s.Server Started @2278089ms
[junit4] 2> 2278038 INFO (jetty-launcher-13376-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=55466}
[junit4] 2> 2278038 INFO (jetty-launcher-13376-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=55469}
[junit4] 2> 2278038 ERROR (jetty-launcher-13376-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2278038 INFO (jetty-launcher-13376-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2278038 ERROR (jetty-launcher-13376-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2278038 INFO (jetty-launcher-13376-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2278038 INFO (jetty-launcher-13376-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 2278038 INFO (jetty-launcher-13376-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2278038 INFO (jetty-launcher-13376-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2278038 INFO (jetty-launcher-13376-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-04-08T21:39:56.218133900Z
[junit4] 2> 2278039 INFO (jetty-launcher-13376-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 2278039 INFO (jetty-launcher-13376-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2278039 INFO (jetty-launcher-13376-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2278039 INFO (jetty-launcher-13376-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-04-08T21:39:56.219063700Z
[junit4] 2> 2278044 INFO (zkConnectionManagerCallback-13378-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2278044 INFO (jetty-launcher-13376-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2278047 INFO (zkConnectionManagerCallback-13380-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2278049 INFO (jetty-launcher-13376-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2278235 INFO (jetty-launcher-13376-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 2278239 WARN (jetty-launcher-13376-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@53f09753[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2278243 WARN (jetty-launcher-13376-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@62e570b5[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2278245 INFO (jetty-launcher-13376-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:55455/solr
[junit4] 2> 2278253 INFO (zkConnectionManagerCallback-13388-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2278259 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x10086d1d1490005, likely client has closed socket
[junit4] 2> 2278263 INFO (zkConnectionManagerCallback-13390-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2278361 INFO (jetty-launcher-13376-thread-1) [n:127.0.0.1:55469_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:55469_solr
[junit4] 2> 2278362 INFO (jetty-launcher-13376-thread-1) [n:127.0.0.1:55469_solr ] o.a.s.c.Overseer Overseer (id=72205829755437062-127.0.0.1:55469_solr-n_0000000000) starting
[junit4] 2> 2278376 INFO (zkConnectionManagerCallback-13397-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2278379 INFO (jetty-launcher-13376-thread-1) [n:127.0.0.1:55469_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:55455/solr ready
[junit4] 2> 2278380 INFO (jetty-launcher-13376-thread-1) [n:127.0.0.1:55469_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55469_solr
[junit4] 2> 2278388 INFO (zkCallback-13389-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2278388 INFO (zkCallback-13396-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2278392 INFO (OverseerStateUpdate-72205829755437062-127.0.0.1:55469_solr-n_0000000000) [n:127.0.0.1:55469_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:55469_solr
[junit4] 2> 2278418 INFO (jetty-launcher-13376-thread-1) [n:127.0.0.1:55469_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2278448 INFO (jetty-launcher-13376-thread-1) [n:127.0.0.1:55469_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55469.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@41ce22d2
[junit4] 2> 2278456 INFO (jetty-launcher-13376-thread-1) [n:127.0.0.1:55469_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55469.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@41ce22d2
[junit4] 2> 2278457 INFO (jetty-launcher-13376-thread-1) [n:127.0.0.1:55469_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55469.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@41ce22d2
[junit4] 2> 2278458 INFO (jetty-launcher-13376-thread-1) [n:127.0.0.1:55469_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.DocValuesNotIndexedTest_5D9D0D1BEA5AAE8D-001\tempDir-001\node1\.
[junit4] 2> 2278579 INFO (jetty-launcher-13376-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 2278582 WARN (jetty-launcher-13376-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@3da8c96d[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2278588 WARN (jetty-launcher-13376-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@150fe59b[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2278588 INFO (jetty-launcher-13376-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:55455/solr
[junit4] 2> 2278592 INFO (zkConnectionManagerCallback-13404-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2278599 INFO (zkConnectionManagerCallback-13406-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2278607 INFO (jetty-launcher-13376-thread-2) [n:127.0.0.1:55466_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2278617 INFO (jetty-launcher-13376-thread-2) [n:127.0.0.1:55466_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:55466_solr as DOWN
[junit4] 2> 2278627 INFO (jetty-launcher-13376-thread-2) [n:127.0.0.1:55466_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2278628 INFO (jetty-launcher-13376-thread-2) [n:127.0.0.1:55466_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55466_solr
[junit4] 2> 2278629 INFO (zkCallback-13396-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2278629 INFO (zkCallback-13389-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2278629 INFO (zkCallback-13405-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2278667 INFO (zkConnectionManagerCallback-13413-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2278671 INFO (jetty-launcher-13376-thread-2) [n:127.0.0.1:55466_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2278679 INFO (jetty-launcher-13376-thread-2) [n:127.0.0.1:55466_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:55455/solr ready
[junit4] 2> 2278679 INFO (jetty-launcher-13376-thread-2) [n:127.0.0.1:55466_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2278704 INFO (jetty-launcher-13376-thread-2) [n:127.0.0.1:55466_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55466.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@41ce22d2
[junit4] 2> 2278716 INFO (jetty-launcher-13376-thread-2) [n:127.0.0.1:55466_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55466.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@41ce22d2
[junit4] 2> 2278716 INFO (jetty-launcher-13376-thread-2) [n:127.0.0.1:55466_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55466.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@41ce22d2
[junit4] 2> 2278717 INFO (jetty-launcher-13376-thread-2) [n:127.0.0.1:55466_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.DocValuesNotIndexedTest_5D9D0D1BEA5AAE8D-001\tempDir-001\node2\.
[junit4] 2> 2278769 INFO (zkConnectionManagerCallback-13419-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2278774 INFO (TEST-DocValuesNotIndexedTest.testDistribFaceting-seed#[5D9D0D1BEA5AAE8D]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2278776 INFO (TEST-DocValuesNotIndexedTest.testDistribFaceting-seed#[5D9D0D1BEA5AAE8D]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:55455/solr ready
[junit4] 2> 2278785 INFO (qtp909188690-35589) [n:127.0.0.1:55466_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf1&maxShardsPerNode=2&name=dv_coll&nrtReplicas=1&action=CREATE&numShards=4&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2278792 INFO (OverseerThreadFactory-10913-thread-1-processing-n:127.0.0.1:55469_solr) [n:127.0.0.1:55469_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection dv_coll
[junit4] 2> 2278907 INFO (OverseerStateUpdate-72205829755437062-127.0.0.1:55469_solr-n_0000000000) [n:127.0.0.1:55469_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"dv_coll",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"dv_coll_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:55469/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2278910 INFO (OverseerStateUpdate-72205829755437062-127.0.0.1:55469_solr-n_0000000000) [n:127.0.0.1:55469_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"dv_coll",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"dv_coll_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:55466/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2278914 INFO (OverseerStateUpdate-72205829755437062-127.0.0.1:55469_solr-n_0000000000) [n:127.0.0.1:55469_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"dv_coll",
[junit4] 2> "shard":"shard3",
[junit4] 2> "core":"dv_coll_shard3_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:55469/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2278918 INFO (OverseerStateUpdate-72205829755437062-127.0.0.1:55469_solr-n_0000000000) [n:127.0.0.1:55469_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"dv_coll",
[junit4] 2> "shard":"shard4",
[junit4] 2> "core":"dv_coll_shard4_replica_n6",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:55466/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2279130 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr x:dv_coll_shard2_replica_n2] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf1&newCollection=true&name=dv_coll_shard2_replica_n2&action=CREATE&numShards=4&collection=dv_coll&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2279132 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr x:dv_coll_shard4_replica_n6] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf1&newCollection=true&name=dv_coll_shard4_replica_n6&action=CREATE&numShards=4&collection=dv_coll&shard=shard4&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2279132 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr x:dv_coll_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf1&newCollection=true&name=dv_coll_shard1_replica_n1&action=CREATE&numShards=4&collection=dv_coll&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2279133 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr x:dv_coll_shard1_replica_n1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2279134 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr x:dv_coll_shard3_replica_n4] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf1&newCollection=true&name=dv_coll_shard3_replica_n4&action=CREATE&numShards=4&collection=dv_coll&shard=shard3&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2280179 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 2280188 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.IndexSchema [dv_coll_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2280190 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2280190 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard1_replica_n1' using configuration from collection dv_coll, trusted=true
[junit4] 2> 2280196 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55469.solr.core.dv_coll.shard1.replica_n1' (registry 'solr.core.dv_coll.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@41ce22d2
[junit4] 2> 2280197 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SolrCore [[dv_coll_shard1_replica_n1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.DocValuesNotIndexedTest_5D9D0D1BEA5AAE8D-001\tempDir-001\node1\dv_coll_shard1_replica_n1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.DocValuesNotIndexedTest_5D9D0D1BEA5AAE8D-001\tempDir-001\node1\.\dv_coll_shard1_replica_n1\data\]
[junit4] 2> 2280197 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 2280203 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 2280211 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.s.IndexSchema [dv_coll_shard3_replica_n4] Schema name=minimal
[junit4] 2> 2280211 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.IndexSchema [dv_coll_shard2_replica_n2] Schema name=minimal
[junit4] 2> 2280213 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2280213 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard3_replica_n4' using configuration from collection dv_coll, trusted=true
[junit4] 2> 2280213 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 2280214 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55469.solr.core.dv_coll.shard3.replica_n4' (registry 'solr.core.dv_coll.shard3.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@41ce22d2
[junit4] 2> 2280214 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.SolrCore [[dv_coll_shard3_replica_n4] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.DocValuesNotIndexedTest_5D9D0D1BEA5AAE8D-001\tempDir-001\node1\dv_coll_shard3_replica_n4], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.DocValuesNotIndexedTest_5D9D0D1BEA5AAE8D-001\tempDir-001\node1\.\dv_coll_shard3_replica_n4\data\]
[junit4] 2> 2280223 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2280223 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard2_replica_n2' using configuration from collection dv_coll, trusted=true
[junit4] 2> 2280227 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55466.solr.core.dv_coll.shard2.replica_n2' (registry 'solr.core.dv_coll.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@41ce22d2
[junit4] 2> 2280227 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SolrCore [[dv_coll_shard2_replica_n2] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.DocValuesNotIndexedTest_5D9D0D1BEA5AAE8D-001\tempDir-001\node2\dv_coll_shard2_replica_n2], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.DocValuesNotIndexedTest_5D9D0D1BEA5AAE8D-001\tempDir-001\node2\.\dv_coll_shard2_replica_n2\data\]
[junit4] 2> 2280235 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.s.IndexSchema [dv_coll_shard4_replica_n6] Schema name=minimal
[junit4] 2> 2280237 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2280237 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard4_replica_n6' using configuration from collection dv_coll, trusted=true
[junit4] 2> 2280237 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55466.solr.core.dv_coll.shard4.replica_n6' (registry 'solr.core.dv_coll.shard4.replica_n6') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@41ce22d2
[junit4] 2> 2280238 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.SolrCore [[dv_coll_shard4_replica_n6] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.DocValuesNotIndexedTest_5D9D0D1BEA5AAE8D-001\tempDir-001\node2\dv_coll_shard4_replica_n6], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.DocValuesNotIndexedTest_5D9D0D1BEA5AAE8D-001\tempDir-001\node2\.\dv_coll_shard4_replica_n6\data\]
[junit4] 2> 2280354 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2280354 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2280358 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2280358 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2280378 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2280378 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2280383 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2280383 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2280393 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2280393 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2280399 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2280399 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2280403 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@404cd51a[dv_coll_shard1_replica_n1] main]
[junit4] 2> 2280403 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2280403 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2280403 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2280403 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 2280403 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2280403 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1630283600843767808
[junit4] 2> 2280410 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@729c54ea[dv_coll_shard2_replica_n2] main]
[junit4] 2> 2280413 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/dv_coll/terms/shard1 to Terms{values={core_node3=0}, version=0}
[junit4] 2> 2280413 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/dv_coll/leaders/shard1
[junit4] 2> 2280418 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2280418 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2280418 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:55469/solr/dv_coll_shard1_replica_n1/
[junit4] 2> 2280418 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2280418 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:55469/solr/dv_coll_shard1_replica_n1/ has no replicas
[junit4] 2> 2280418 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/dv_coll/leaders/shard1/leader after winning as /collections/dv_coll/leader_elect/shard1/election/72205829755437062-core_node3-n_0000000000
[junit4] 2> 2280418 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2280422 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2280422 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2280423 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 2280423 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:55469/solr/dv_coll_shard1_replica_n1/ shard1
[junit4] 2> 2280423 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2280423 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1630283600864739328
[junit4] 2> 2280427 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@92e6fe7[dv_coll_shard4_replica_n6] main]
[junit4] 2> 2280430 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.ZkShardTerms Successful update of terms at /collections/dv_coll/terms/shard2 to Terms{values={core_node5=0}, version=0}
[junit4] 2> 2280430 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/dv_coll/leaders/shard2
[junit4] 2> 2280435 INFO (searcherExecutor-10925-thread-1-processing-n:127.0.0.1:55469_solr x:dv_coll_shard1_replica_n1 c:dv_coll s:shard1 r:core_node3) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SolrCore [dv_coll_shard1_replica_n1] Registered new searcher Searcher@404cd51a[dv_coll_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2280435 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2280436 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2280436 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2280436 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2280436 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2280436 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:55466/solr/dv_coll_shard2_replica_n2/
[junit4] 2> 2280437 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2280437 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 2280437 INFO (searcherExecutor-10927-thread-1-processing-n:127.0.0.1:55466_solr x:dv_coll_shard2_replica_n2 c:dv_coll s:shard2 r:core_node5) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SolrCore [dv_coll_shard2_replica_n2] Registered new searcher Searcher@729c54ea[dv_coll_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2280437 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SyncStrategy http://127.0.0.1:55466/solr/dv_coll_shard2_replica_n2/ has no replicas
[junit4] 2> 2280437 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/dv_coll/leaders/shard2/leader after winning as /collections/dv_coll/leader_elect/shard2/election/72205829755437065-core_node5-n_0000000000
[junit4] 2> 2280437 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2280439 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1630283600881516544
[junit4] 2> 2280439 INFO (searcherExecutor-10928-thread-1-processing-n:127.0.0.1:55466_solr x:dv_coll_shard4_replica_n6 c:dv_coll s:shard4 r:core_node8) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.SolrCore [dv_coll_shard4_replica_n6] Registered new searcher Searcher@92e6fe7[dv_coll_shard4_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2280442 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:55466/solr/dv_coll_shard2_replica_n2/ shard2
[junit4] 2> 2280444 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.ZkShardTerms Successful update of terms at /collections/dv_coll/terms/shard4 to Terms{values={core_node8=0}, version=0}
[junit4] 2> 2280444 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/dv_coll/leaders/shard4
[junit4] 2> 2280450 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2280450 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2280450 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:55466/solr/dv_coll_shard4_replica_n6/
[junit4] 2> 2280450 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2280450 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.SyncStrategy http://127.0.0.1:55466/solr/dv_coll_shard4_replica_n6/ has no replicas
[junit4] 2> 2280450 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/dv_coll/leaders/shard4/leader after winning as /collections/dv_coll/leader_elect/shard4/election/72205829755437065-core_node8-n_0000000000
[junit4] 2> 2280452 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:55466/solr/dv_coll_shard4_replica_n6/ shard4
[junit4] 2> 2280555 INFO (zkCallback-13405-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280555 INFO (zkCallback-13389-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280555 INFO (zkCallback-13389-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280557 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2280557 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2280558 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2280562 INFO (qtp1459593956-35595) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf1&newCollection=true&name=dv_coll_shard1_replica_n1&action=CREATE&numShards=4&collection=dv_coll&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1429
[junit4] 2> 2280563 INFO (qtp909188690-35588) [n:127.0.0.1:55466_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf1&newCollection=true&name=dv_coll_shard2_replica_n2&action=CREATE&numShards=4&collection=dv_coll&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1434
[junit4] 2> 2280566 INFO (qtp909188690-35586) [n:127.0.0.1:55466_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf1&newCollection=true&name=dv_coll_shard4_replica_n6&action=CREATE&numShards=4&collection=dv_coll&shard=shard4&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1434
[junit4] 2> 2280572 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2280572 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2280577 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2280577 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2280587 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.s.SolrIndexSearcher Opening [Searcher@1d7c8237[dv_coll_shard3_replica_n4] main]
[junit4] 2> 2280588 INFO (zkCallback-13405-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280590 INFO (zkCallback-13405-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280591 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2280591 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2280592 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2280592 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 2280593 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2280593 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1630283601042997248
[junit4] 2> 2280595 INFO (searcherExecutor-10926-thread-1-processing-n:127.0.0.1:55469_solr x:dv_coll_shard3_replica_n4 c:dv_coll s:shard3 r:core_node7) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.SolrCore [dv_coll_shard3_replica_n4] Registered new searcher Searcher@1d7c8237[dv_coll_shard3_replica_n4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2280608 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.ZkShardTerms Successful update of terms at /collections/dv_coll/terms/shard3 to Terms{values={core_node7=0}, version=0}
[junit4] 2> 2280608 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/dv_coll/leaders/shard3
[junit4] 2> 2280617 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2280617 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2280617 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:55469/solr/dv_coll_shard3_replica_n4/
[junit4] 2> 2280617 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2280617 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.SyncStrategy http://127.0.0.1:55469/solr/dv_coll_shard3_replica_n4/ has no replicas
[junit4] 2> 2280617 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/dv_coll/leaders/shard3/leader after winning as /collections/dv_coll/leader_elect/shard3/election/72205829755437062-core_node7-n_0000000000
[junit4] 2> 2280623 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:55469/solr/dv_coll_shard3_replica_n4/ shard3
[junit4] 2> 2280728 INFO (zkCallback-13405-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280728 INFO (zkCallback-13405-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280729 INFO (zkCallback-13405-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280729 INFO (zkCallback-13389-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280729 INFO (zkCallback-13389-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280729 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2280729 INFO (zkCallback-13405-thread-4) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280729 INFO (zkCallback-13389-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280732 INFO (qtp1459593956-35584) [n:127.0.0.1:55469_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf1&newCollection=true&name=dv_coll_shard3_replica_n4&action=CREATE&numShards=4&collection=dv_coll&shard=shard3&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1597
[junit4] 2> 2280737 INFO (qtp909188690-35589) [n:127.0.0.1:55466_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 45 seconds. Check all shard replicas
[junit4] 2> 2280797 INFO (OverseerCollectionConfigSetProcessor-72205829755437062-127.0.0.1:55469_solr-n_0000000000) [n:127.0.0.1:55469_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 2280835 INFO (zkCallback-13389-thread-4) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280835 INFO (zkCallback-13389-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280835 INFO (zkCallback-13389-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280835 INFO (zkCallback-13405-thread-4) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280835 INFO (zkCallback-13405-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280835 INFO (zkCallback-13405-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280835 INFO (zkCallback-13405-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2280838 INFO (qtp909188690-35589) [n:127.0.0.1:55466_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf1&maxShardsPerNode=2&name=dv_coll&nrtReplicas=1&action=CREATE&numShards=4&wt=javabin&version=2} status=0 QTime=2051
[junit4] 2> 2280852 INFO (qtp1459593956-35582) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.SchemaManager managed schema loaded . version : 0
[junit4] 2> 2280852 INFO (qtp1459593956-35582) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.IndexSchema [dv_coll_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2280857 INFO (qtp1459593956-35582) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2280873 INFO (qtp1459593956-35582) [n:127.0.0.1:55469_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.ZkController Persisted config data to node /configs/conf1/managed-schema
[junit4] 2> 2280873 INFO (zkCallback-13389-thread-2) [ ] o.a.s.s.ZkIndexSchemaReader A schema change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/configs/conf1/managed-schema, has occurred - updating schema from ZooKeeper ...
[junit4] 2> 2280873 INFO (zkCallback-13389-thread-3) [ ] o.a.s.s.ZkIndexSchemaReader A schema change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/configs/conf1/managed-schema, has occurred - updating schema from ZooKeeper ...
[junit4] 2> 2280879 INFO (zkCallback-13389-thread-2) [ ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 1 from ZooKeeper
[junit4] 2> 2280879 INFO (zkCallback-13405-thread-1) [ ] o.a.s.s.ZkIndexSchemaReader A schema change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/configs/conf1/managed-schema, has occurred - updating schema from ZooKeeper ...
[junit4] 2> 2280879 INFO (zkCallback-13405-thread-2) [ ] o.a.s.s.ZkIndexSchemaReader A schema change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/configs/conf1/managed-schema, has occurred - updating schema from ZooKeeper ...
[junit4] 2> 2280881 INFO (zkCallback-13389-thread-2) [ ] o.a.s.s.IndexSchema [dv_coll_shard3_replica_n4] Schema name=minimal
[junit4] 2> 2280881 INFO (zkCallback-13405-thr
[...truncated too long message...]
tatic$0(CoreAdminOperation.java:92)
[junit4] > at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360)
[junit4] > at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396)
[junit4] > at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188)
[junit4] > at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
[junit4] > at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[junit4] > at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[junit4] > at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] > expected null, but was:<ObjectTracker found 4 object(s) that were not released!!! [MockDirectoryWrapper, SolrCore, MockDirectoryWrapper, MockDirectoryWrapper]
[junit4] > org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper
[junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
[junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348)
[junit4] > at org.apache.solr.core.SolrCore.initSnapshotMetaDataManager(SolrCore.java:517)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:968)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:883)
[junit4] > at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1245)
[junit4] > at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1155)
[junit4] > at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:92)
[junit4] > at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360)
[junit4] > at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396)
[junit4] > at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188)
[junit4] > at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
[junit4] > at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[junit4] > at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[junit4] > at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] > org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.core.SolrCore
[junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1063)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:883)
[junit4] > at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1245)
[junit4] > at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1155)
[junit4] > at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:92)
[junit4] > at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360)
[junit4] > at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396)
[junit4] > at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188)
[junit4] > at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
[junit4] > at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[junit4] > at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[junit4] > at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] > org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper
[junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
[junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348)
[junit4] > at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:509)
[junit4] > at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:351)
[junit4] > at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:422)
[junit4] > at org.apache.solr.handler.ReplicationHandler.lambda$setupPolling$13(ReplicationHandler.java:1191)
[junit4] > at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
[junit4] > at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
[junit4] > at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
[junit4] > at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[junit4] > at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] > org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper
[junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
[junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348)
[junit4] > at org.apache.solr.update.SolrIndexWriter.create(SolrIndexWriter.java:99)
[junit4] > at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:779)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:976)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:883)
[junit4] > at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1245)
[junit4] > at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1155)
[junit4] > at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:92)
[junit4] > at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:360)
[junit4] > at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:396)
[junit4] > at org.apache.solr.handler.admin.CoreAdminHandler.lambda$handleRequestBody$0(CoreAdminHandler.java:188)
[junit4] > at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
[junit4] > at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[junit4] > at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[junit4] > at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] > >
[junit4] > at __randomizedtesting.SeedInfo.seed([6A6133522733A8B9]:0)
[junit4] > at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:325)
[junit4] > at jdk.internal.reflect.GeneratedMethodAccessor41.invoke(Unknown Source)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] Completed [131/193 (1!)] on J0 in 157.08s, 16 tests, 1 failure <<< FAILURES!
[...truncated 41734 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/7876/consoleText
[repro] Revision: 6bc360ee67582e42c0211ac1767a9c0ed8bfaad3
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC"
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr\core
[repro] DocValuesNotIndexedTest
[repro] solr\solrj
[repro] CloudHttp2SolrClientTest
[repro] ant compile-test
[...truncated 3591 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.DocValuesNotIndexedTest" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=5D9D0D1BEA5AAE8D -Dtests.slow=true -Dtests.locale=cgg-UG -Dtests.timezone=Africa/Dakar -Dtests.asserts=true -Dtests.file.encoding=Cp1252
[...truncated 88 lines...]
[repro] ant compile-test
[...truncated 454 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.CloudHttp2SolrClientTest" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=6A6133522733A8B9 -Dtests.slow=true -Dtests.locale=sr-Latn-XK -Dtests.timezone=Asia/Qyzylorda -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[...truncated 148 lines...]
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.client.solrj.impl.CloudHttp2SolrClientTest
[repro] 0/5 failed: org.apache.solr.cloud.DocValuesNotIndexedTest
[repro] Exiting with code 0
[...truncated 78 lines...]