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
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
