github-mirrors/elasticsearch
1
0
Fork 0
mirror of https://github.com/elastic/elasticsearch.git synced 2025-04-24 23:27:25 -04:00
Code Issues Projects Releases Packages Wiki Activity

Make MockLogAppender threadsafe (#108206)

Browse source 
Adding and removing appenders in Log4j is not threadsafe. Yet some tests
rely on capturing logging by adding an in memory appender,
MockLogAppender. This commit makes the mock logging threadsafe by
creating a new, singular appender for mock logging that delegates, in a
threadsafe way, to the existing appenders created. Confusingly
MockLogAppender is no longer really an appender, but I'm leaving
clarifying that for a followup so as to limit the scope of this PR.

closes #106425
This commit is contained in:
Ryan Ernst 2024-05-08 15:38:38 -07:00 • committed by GitHub
parent 90b238e9d8
commit 31abf3e00c
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
6 changed files with 100 additions and 27 deletions
Download patch file Download diff file Expand all files Collapse all files

1
qa/no-bootstrap-tests/src/test/java/org/elasticsearch/bootstrap/SpawnerNoBootstrapTests.java
View file

@ -64,6 +64,7 @@ public class SpawnerNoBootstrapTests extends LuceneTestCase {
static {
// normally done by ESTestCase, but need here because spawner depends on logging
LogConfigurator.loadLog4jPlugins();
MockLogAppender.init();
}
static class ExpectedStreamMessage implements MockLogAppender.LoggingExpectation {

1
server/src/test/java/org/elasticsearch/common/settings/SettingsFilterTests.java
View file

@ -119,7 +119,6 @@ public class SettingsFilterTests extends ESTestCase {
Logger testLogger = LogManager.getLogger("org.elasticsearch.test");
MockLogAppender appender = new MockLogAppender();
try (var ignored = appender.capturing("org.elasticsearch.test")) {
appender.start();
Arrays.stream(expectations).forEach(appender::addExpectation);
consumer.accept(testLogger);
appender.assertAllExpectationsMatched();

1
test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java
View file

@ -260,6 +260,7 @@ public abstract class ESTestCase extends LuceneTestCase {
// TODO: consolidate logging initialization for tests so it all occurs in logconfigurator
LogConfigurator.loadLog4jPlugins();
LogConfigurator.configureESLogging();
MockLogAppender.init();
final List<Appender> testAppenders = new ArrayList<>(3);
for (String leakLoggerName : Arrays.asList("io.netty.util.ResourceLeakDetector", LeakTracker.class.getName())) {

84
test/framework/src/main/java/org/elasticsearch/test/MockLogAppender.java
View file

@ -9,7 +9,6 @@ package org.elasticsearch.test;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.appender.AbstractAppender;
import org.apache.logging.log4j.core.config.Property;
@ -19,9 +18,10 @@ import org.elasticsearch.core.Releasable;
import java.util.Arrays;
import java.util.List;
import java.util.Map;
import java.util.Objects;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.CopyOnWriteArrayList;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.regex.Pattern;
import static org.hamcrest.CoreMatchers.equalTo;
@ -31,12 +31,38 @@ import static org.hamcrest.Matchers.is;
/**
* Test appender that can be used to verify that certain events were logged correctly
*/
public class MockLogAppender extends AbstractAppender {
public class MockLogAppender {
private static final Map<String, List<MockLogAppender>> mockAppenders = new ConcurrentHashMap<>();
private static final RealMockAppender parent = new RealMockAppender();
private final List<WrappedLoggingExpectation> expectations;
private volatile boolean isAlive = true;
private static class RealMockAppender extends AbstractAppender {
RealMockAppender() {
super("mock", null, null, false, Property.EMPTY_ARRAY);
}
@Override
public void append(LogEvent event) {
List<MockLogAppender> appenders = mockAppenders.get(event.getLoggerName());
if (appenders == null) {
// check if there is a root appender
appenders = mockAppenders.getOrDefault("", List.of());
}
for (MockLogAppender appender : appenders) {
if (appender.isAlive == false) {
continue;
}
for (LoggingExpectation expectation : appender.expectations) {
expectation.match(event);
}
}
}
}
public MockLogAppender() {
super("mock", null, null, false, Property.EMPTY_ARRAY);
/*
* We use a copy-on-write array list since log messages could be appended while we are setting up expectations. When that occurs,
* we would run into a concurrent modification exception from the iteration over the expectations in #append, concurrent with a
@ -45,15 +71,16 @@ public class MockLogAppender extends AbstractAppender {
expectations = new CopyOnWriteArrayList<>();
}
public void addExpectation(LoggingExpectation expectation) {
expectations.add(new WrappedLoggingExpectation(expectation));
/**
* Initialize the mock log appender with the log4j system.
*/
public static void init() {
parent.start();
Loggers.addAppender(LogManager.getLogger(""), parent);
}
@Override
public void append(LogEvent event) {
for (LoggingExpectation expectation : expectations) {
expectation.match(event);
}
public void addExpectation(LoggingExpectation expectation) {
expectations.add(new WrappedLoggingExpectation(expectation));
}
public void assertAllExpectationsMatched() {
@ -213,7 +240,7 @@ public class MockLogAppender extends AbstractAppender {
*/
private static class WrappedLoggingExpectation implements LoggingExpectation {
private final AtomicBoolean assertMatchedCalled = new AtomicBoolean(false);
private volatile boolean assertMatchedCalled = false;
private final LoggingExpectation delegate;
private WrappedLoggingExpectation(LoggingExpectation delegate) {
@ -230,7 +257,7 @@ public class MockLogAppender extends AbstractAppender {
try {
delegate.assertMatched();
} finally {
assertMatchedCalled.set(true);
assertMatchedCalled = true;
}
}
@ -243,34 +270,43 @@ public class MockLogAppender extends AbstractAppender {
/**
* Adds the list of class loggers to this {@link MockLogAppender}.
*
* Stops ({@link #stop()}) and runs some checks on the {@link MockLogAppender} once the returned object is released.
* Stops and runs some checks on the {@link MockLogAppender} once the returned object is released.
*/
public Releasable capturing(Class<?>... classes) {
return appendToLoggers(Arrays.stream(classes).map(LogManager::getLogger).toList());
return appendToLoggers(Arrays.stream(classes).map(Class::getCanonicalName).toList());
}
/**
* Same as above except takes string class names of each logger.
*/
public Releasable capturing(String... names) {
return appendToLoggers(Arrays.stream(names).map(LogManager::getLogger).toList());
return appendToLoggers(Arrays.asList(names));
}
private Releasable appendToLoggers(List<Logger> loggers) {
start();
for (final var logger : loggers) {
Loggers.addAppender(logger, this);
private Releasable appendToLoggers(List<String> loggers) {
for (String logger : loggers) {
mockAppenders.compute(logger, (k, v) -> {
if (v == null) {
v = new CopyOnWriteArrayList<>();
}
v.add(this);
return v;
});
}
return () -> {
for (final var logger : loggers) {
Loggers.removeAppender(logger, this);
isAlive = false;
for (String logger : loggers) {
mockAppenders.compute(logger, (k, v) -> {
assert v != null;
v.remove(this);
return v.isEmpty() ? null : v;
});
}
stop();
// check that all expectations have been evaluated before this is released
for (WrappedLoggingExpectation expectation : expectations) {
assertThat(
"Method assertMatched() not called on LoggingExpectation instance before release: " + expectation,
expectation.assertMatchedCalled.get(),
expectation.assertMatchedCalled,
is(true)
);
}

38
test/framework/src/test/java/org/elasticsearch/test/MockLogAppenderTests.java Normal file
View file

@ -0,0 +1,38 @@
/*
* Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one
* or more contributor license agreements. Licensed under the Elastic License
* 2.0 and the Server Side Public License, v 1; you may not use this file except
* in compliance with, at your election, the Elastic License 2.0 or the Server
* Side Public License, v 1.
*/
package org.elasticsearch.test;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import java.util.concurrent.atomic.AtomicBoolean;
public class MockLogAppenderTests extends ESTestCase {
public void testConcurrentLogAndLifecycle() throws Exception {
Logger logger = LogManager.getLogger(MockLogAppenderTests.class);
final var keepGoing = new AtomicBoolean(true);
final var logThread = new Thread(() -> {
while (keepGoing.get()) {
logger.info("test");
}
});
logThread.start();
final var appender = new MockLogAppender();
for (int i = 0; i < 1000; i++) {
try (var ignored = appender.capturing(MockLogAppenderTests.class)) {
Thread.yield();
}
}
keepGoing.set(false);
logThread.join();
}
}

2
x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authz/LoadAuthorizedIndicesTimeCheckerTests.java
View file

@ -12,7 +12,6 @@ import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.elasticsearch.action.search.SearchRequest;
import org.elasticsearch.action.search.TransportSearchAction;
import org.elasticsearch.common.logging.Loggers;
import org.elasticsearch.common.settings.ClusterSettings;
import org.elasticsearch.common.settings.Settings;
import org.elasticsearch.common.settings.SettingsException;
@ -195,7 +194,6 @@ public class LoadAuthorizedIndicesTimeCheckerTests extends ESTestCase {
);
final MockLogAppender mockAppender = new MockLogAppender();
try (var ignored = mockAppender.capturing(timerLogger.getName())) {
Loggers.addAppender(timerLogger, mockAppender);
mockAppender.addExpectation(expectation);
checker.accept(List.of());
mockAppender.assertAllExpectationsMatched();