mirrors
/
elasticsearch
mirror of https://mirror.osredm.com/root/elasticsearch.git
2
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Wait for logs in tests without busy-waiting (#113589) 

Introduces `MockLog#awaitAllExpectationsMatched` to allow tests to wait
until all the expected log messages have been seen without having to use
`assertBusy()`.
This commit is contained in:
David Turner 2024-09-26 16:10:39 +01:00 committed by GitHub
parent 0ea8a78ca7
commit ade235bf0f
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
15 changed files with 224 additions and 111 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

74
qa/no-bootstrap-tests/src/test/java/org/elasticsearch/bootstrap/SpawnerNoBootstrapTests.java
View File

@ -13,7 +13,6 @@ import com.carrotsearch.randomizedtesting.annotations.ThreadLeakFilters;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.lucene.tests.util.LuceneTestCase;
import org.apache.lucene.util.Constants;
import org.elasticsearch.Version;
@ -36,7 +35,6 @@ import java.nio.file.attribute.PosixFilePermission;
import java.util.HashSet;
import java.util.List;
import java.util.Set;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.TimeUnit;
import java.util.function.Function;
@ -70,34 +68,6 @@ public class SpawnerNoBootstrapTests extends LuceneTestCase {
MockLog.init();
}
static class ExpectedStreamMessage implements MockLog.LoggingExpectation {
final String expectedLogger;
final String expectedMessage;
final CountDownLatch matched;
volatile boolean saw;
ExpectedStreamMessage(String logger, String message, CountDownLatch matched) {
this.expectedLogger = logger;
this.expectedMessage = message;
this.matched = matched;
}
@Override
public void match(LogEvent event) {
if (event.getLoggerName().equals(expectedLogger)
&& event.getLevel().equals(Level.WARN)
&& event.getMessage().getFormattedMessage().equals(expectedMessage)) {
saw = true;
matched.countDown();
}
}
@Override
public void assertMatched() {
assertTrue("Expected to see message [" + expectedMessage + "] on logger [" + expectedLogger + "]", saw);
}
}
/**
* Simplest case: a module with no controller daemon.
*/
@ -209,32 +179,32 @@ public class SpawnerNoBootstrapTests extends LuceneTestCase {
String stderrLoggerName = "test_plugin-controller-stderr";
Loggers.setLevel(LogManager.getLogger(stdoutLoggerName), Level.TRACE);
Loggers.setLevel(LogManager.getLogger(stderrLoggerName), Level.TRACE);
CountDownLatch messagesLoggedLatch = new CountDownLatch(2);
try (var mockLog = MockLog.capture(stdoutLoggerName, stderrLoggerName)) {
if (expectSpawn) {
mockLog.addExpectation(new ExpectedStreamMessage(stdoutLoggerName, "I am alive", messagesLoggedLatch));
mockLog.addExpectation(new ExpectedStreamMessage(stderrLoggerName, "I am an error", messagesLoggedLatch));
if (expectSpawn) {
final Process process;
try (var mockLog = MockLog.capture(stdoutLoggerName, stderrLoggerName)) {
mockLog.addExpectation(new MockLog.SeenEventExpectation("stdout", stdoutLoggerName, Level.WARN, "I am alive"));
mockLog.addExpectation(new MockLog.SeenEventExpectation("stderr", stderrLoggerName, Level.WARN, "I am an error"));
try (var spawner = new Spawner()) {
spawner.spawnNativeControllers(environment);
List<Process> processes = spawner.getProcesses();
// as there should only be a reference in the list for the module that had the controller daemon, we expect one here
assertThat(processes, hasSize(1));
process = processes.get(0);
// fail if we don't get the expected log messages soonish
mockLog.awaitAllExpectationsMatched();
}
}
Spawner spawner = new Spawner();
spawner.spawnNativeControllers(environment);
List<Process> processes = spawner.getProcesses();
if (expectSpawn) {
// as there should only be a reference in the list for the module that had the controller daemon, we expect one here
assertThat(processes, hasSize(1));
Process process = processes.get(0);
// fail if we don't get the expected log messages within one second; usually it will be even quicker
assertTrue(messagesLoggedLatch.await(1, TimeUnit.SECONDS));
spawner.close();
// fail if the process does not die within one second; usually it will be even quicker but it depends on OS scheduling
assertTrue(process.waitFor(1, TimeUnit.SECONDS));
} else {
assertThat(processes, is(empty()));
// fail if the process does not die within one second; usually it will be even quicker but it depends on OS scheduling
assertTrue(process.waitFor(1, TimeUnit.SECONDS));
} else {
try (var spawner = new Spawner()) {
spawner.spawnNativeControllers(environment);
assertThat(spawner.getProcesses(), is(empty()));
}
mockLog.assertAllExpectationsMatched();
}
}

42
server/src/internalClusterTest/java/org/elasticsearch/common/network/ThreadWatchdogIT.java
View File

@ -9,7 +9,7 @@
package org.elasticsearch.common.network;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.Level;
import org.elasticsearch.action.ActionListenerResponseHandler;
import org.elasticsearch.action.support.SubscribableListener;
import org.elasticsearch.client.Request;
@ -23,7 +23,6 @@ import org.elasticsearch.common.settings.Settings;
import org.elasticsearch.common.settings.SettingsFilter;
import org.elasticsearch.common.util.CollectionUtils;
import org.elasticsearch.common.util.concurrent.EsExecutors;
import org.elasticsearch.common.util.concurrent.RunOnce;
import org.elasticsearch.features.NodeFeature;
import org.elasticsearch.plugins.ActionPlugin;
import org.elasticsearch.plugins.Plugin;
@ -43,7 +42,6 @@ import org.elasticsearch.transport.TransportService;
import java.io.IOException;
import java.util.Collection;
import java.util.List;
import java.util.concurrent.CountDownLatch;
import java.util.function.Predicate;
import java.util.function.Supplier;
@ -103,26 +101,24 @@ public class ThreadWatchdogIT extends ESIntegTestCase {
}
private static void blockAndWaitForWatchdogLogs() {
final var threadName = Thread.currentThread().getName();
final var logsSeenLatch = new CountDownLatch(2);
final var warningSeen = new RunOnce(logsSeenLatch::countDown);
final var threadDumpSeen = new RunOnce(logsSeenLatch::countDown);
MockLog.assertThatLogger(() -> safeAwait(logsSeenLatch), ThreadWatchdog.class, new MockLog.LoggingExpectation() {
@Override
public void match(LogEvent event) {
final var formattedMessage = event.getMessage().getFormattedMessage();
if (formattedMessage.contains("the following threads are active but did not make progress in the preceding [100ms]:")
&& formattedMessage.contains(threadName)) {
warningSeen.run();
}
if (formattedMessage.contains("hot threads dump due to active threads not making progress")) {
threadDumpSeen.run();
}
}
@Override
public void assertMatched() {}
});
MockLog.awaitLogger(
() -> {},
ThreadWatchdog.class,
new MockLog.SeenEventExpectation(
"warning",
ThreadWatchdog.class.getCanonicalName(),
Level.WARN,
"*the following threads are active but did not make progress in the preceding [100ms]:*"
+ Thread.currentThread().getName()
+ "*"
),
new MockLog.SeenEventExpectation(
"thread dump",
ThreadWatchdog.class.getCanonicalName(),
Level.WARN,
"*hot threads dump due to active threads not making progress*"
)
);
}
public void testThreadWatchdogHttpLogging() throws IOException {

2
server/src/internalClusterTest/java/org/elasticsearch/discovery/single/SingleNodeDiscoveryIT.java
View File

@ -160,7 +160,7 @@ public class SingleNodeDiscoveryIT extends ESIntegTestCase {
other.beforeTest(random());
final ClusterState first = internalCluster().getInstance(ClusterService.class).state();
assertThat(first.nodes().getSize(), equalTo(1));
assertBusy(mockLog::assertAllExpectationsMatched);
mockLog.awaitAllExpectationsMatched();
} finally {
other.close();
}

16
server/src/internalClusterTest/java/org/elasticsearch/indices/cluster/ShardLockFailureIT.java
View File

@ -72,9 +72,9 @@ public class ShardLockFailureIT extends ESIntegTestCase {
var ignored1 = internalCluster().getInstance(NodeEnvironment.class, node).shardLock(shardId, "blocked for test");
var mockLog = MockLog.capture(IndicesClusterStateService.class);
) {
final CountDownLatch countDownLatch = new CountDownLatch(1);
mockLog.addExpectation(new MockLog.LoggingExpectation() {
private final CountDownLatch countDownLatch = new CountDownLatch(1);
int debugMessagesSeen = 0;
int warnMessagesSeen = 0;
@ -101,14 +101,20 @@ public class ShardLockFailureIT extends ESIntegTestCase {
}
@Override
public void assertMatched() {}
public void assertMatched() {
fail("unused");
}
@Override
public void awaitMatched(long millis) throws InterruptedException {
assertTrue(countDownLatch.await(millis, TimeUnit.MILLISECONDS));
}
});
updateIndexSettings(Settings.builder().putNull(IndexMetadata.INDEX_ROUTING_EXCLUDE_GROUP_PREFIX + "._name"), indexName);
ensureYellow(indexName);
assertTrue(countDownLatch.await(30, TimeUnit.SECONDS));
mockLog.awaitAllExpectationsMatched();
assertEquals(ClusterHealthStatus.YELLOW, clusterAdmin().prepareHealth(TEST_REQUEST_TIMEOUT, indexName).get().getStatus());
mockLog.assertAllExpectationsMatched();
}
ensureGreen(indexName);
@ -153,7 +159,7 @@ public class ShardLockFailureIT extends ESIntegTestCase {
);
updateIndexSettings(Settings.builder().putNull(IndexMetadata.INDEX_ROUTING_EXCLUDE_GROUP_PREFIX + "._name"), indexName);
assertBusy(mockLog::assertAllExpectationsMatched);
mockLog.awaitAllExpectationsMatched();
final var clusterHealthResponse = clusterAdmin().prepareHealth(TEST_REQUEST_TIMEOUT, indexName)
.setWaitForEvents(Priority.LANGUID)
.setTimeout(TimeValue.timeValueSeconds(10))

2
server/src/internalClusterTest/java/org/elasticsearch/search/fieldcaps/FieldCapabilitiesIT.java
View File

@ -693,7 +693,7 @@ public class FieldCapabilitiesIT extends ESIntegTestCase {
}
}, 30, TimeUnit.SECONDS);
cancellable.cancel();
assertBusy(mockLog::assertAllExpectationsMatched);
mockLog.awaitAllExpectationsMatched();
logger.info("--> waiting for field-caps tasks to be cancelled");
assertBusy(() -> {
List<TaskInfo> tasks = clusterAdmin().prepareListTasks()

2
server/src/test/java/org/elasticsearch/cluster/service/ClusterApplierServiceTests.java
View File

@ -181,7 +181,7 @@ public class ClusterApplierServiceTests extends ESTestCase {
fail();
}
});
assertBusy(mockLog::assertAllExpectationsMatched);
mockLog.awaitAllExpectationsMatched();
}
}

2
server/src/test/java/org/elasticsearch/cluster/service/MasterServiceTests.java
View File

@ -526,7 +526,7 @@ public class MasterServiceTests extends ESTestCase {
fail();
}
});
assertBusy(mockLog::assertAllExpectationsMatched);
mockLog.awaitAllExpectationsMatched();
}
}

6
server/src/test/java/org/elasticsearch/index/shard/IndexShardTests.java
View File

@ -4191,7 +4191,7 @@ public class IndexShardTests extends IndexShardTestCase {
);
shard.flushOnIdle(0);
assertFalse(shard.isActive());
assertBusy(mockLog::assertAllExpectationsMatched);
mockLog.awaitAllExpectationsMatched();
// While the first flush is happening, index one more doc (to turn the shard's active flag to true),
// and issue a second flushOnIdle request which should not wait for the ongoing flush
@ -4206,7 +4206,7 @@ public class IndexShardTests extends IndexShardTestCase {
)
);
shard.flushOnIdle(0);
assertBusy(mockLog::assertAllExpectationsMatched);
mockLog.awaitAllExpectationsMatched();
// A direct call to flush (with waitIfOngoing=false) should not wait and return false immediately
assertFalse(shard.flush(new FlushRequest().waitIfOngoing(false).force(false)));
@ -4223,7 +4223,7 @@ public class IndexShardTests extends IndexShardTestCase {
"released flush lock"
)
);
assertBusy(mockLog::assertAllExpectationsMatched);
mockLog.awaitAllExpectationsMatched();
// The second flushOnIdle (that did not happen) should have turned the active flag to true
assertTrue(shard.isActive());

2
server/src/test/java/org/elasticsearch/monitor/fs/FsHealthServiceTests.java
View File

@ -146,7 +146,7 @@ public class FsHealthServiceTests extends ESTestCase {
disruptFileSystemProvider.injectIOException.set(true);
fsHealthService.new FsHealthMonitor().run();
assertEquals(env.nodeDataPaths().length, disruptFileSystemProvider.getInjectedPathCount());
assertBusy(mockLog::assertAllExpectationsMatched);
mockLog.awaitAllExpectationsMatched();
} finally {
PathUtilsForTesting.teardown();
ThreadPool.terminate(testThreadPool, 500, TimeUnit.MILLISECONDS);

4
server/src/test/java/org/elasticsearch/tasks/BanFailureLoggingTests.java
View File

@ -184,8 +184,8 @@ public class BanFailureLoggingTests extends TaskManagerTestCase {
// acceptable; we mostly ignore the result of cancellation anyway
}
// assert busy since failure to remove a ban may be logged after cancellation completed
assertBusy(mockLog::assertAllExpectationsMatched);
// await since failure to remove a ban may be logged after cancellation completed
mockLog.awaitAllExpectationsMatched();
}
assertTrue("child tasks did not finish in time", childTaskLock.tryLock(15, TimeUnit.SECONDS));

4
server/src/test/java/org/elasticsearch/threadpool/ThreadPoolTests.java
View File

@ -128,7 +128,7 @@ public class ThreadPoolTests extends ESTestCase {
final ThreadPool.CachedTimeThread thread = new ThreadPool.CachedTimeThread("[timer]", 200, 100);
thread.start();
assertBusy(mockLog::assertAllExpectationsMatched);
mockLog.awaitAllExpectationsMatched();
thread.interrupt();
thread.join();
@ -297,7 +297,7 @@ public class ThreadPoolTests extends ESTestCase {
}
};
threadPool.schedule(runnable, TimeValue.timeValueMillis(randomLongBetween(0, 300)), EsExecutors.DIRECT_EXECUTOR_SERVICE);
assertBusy(mockLog::assertAllExpectationsMatched);
mockLog.awaitAllExpectationsMatched();
} finally {
assertTrue(terminate(threadPool));
}

108
test/framework/src/main/java/org/elasticsearch/test/MockLog.java
View File

@ -16,6 +16,7 @@ import org.apache.logging.log4j.core.config.Property;
import org.elasticsearch.common.logging.Loggers;
import org.elasticsearch.common.regex.Regex;
import org.elasticsearch.core.Releasable;
import org.elasticsearch.core.TimeValue;
import java.util.Arrays;
import java.util.List;
@ -23,10 +24,13 @@ import java.util.Map;
import java.util.Objects;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.CopyOnWriteArrayList;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.TimeUnit;
import java.util.regex.Pattern;
import static org.hamcrest.CoreMatchers.equalTo;
import static org.hamcrest.MatcherAssert.assertThat;
import static org.hamcrest.Matchers.greaterThan;
import static org.hamcrest.Matchers.is;
/**
@ -112,10 +116,46 @@ public class MockLog implements Releasable {
}
}
public void awaitAllExpectationsMatched() {
awaitAllExpectationsMatched(ESTestCase.SAFE_AWAIT_TIMEOUT);
}
// exposed for testing
void awaitAllExpectationsMatched(TimeValue waitTime) {
final var deadlineNanos = System.nanoTime() + waitTime.nanos();
final var nanosPerMilli = TimeValue.timeValueMillis(1).nanos();
try {
for (LoggingExpectation expectation : expectations) {
final var remainingMillis = (deadlineNanos - System.nanoTime() + nanosPerMilli - 1) / nanosPerMilli; // round up
assertThat(remainingMillis, greaterThan(0L));
expectation.awaitMatched(remainingMillis);
}
} catch (InterruptedException interruptedException) {
Thread.currentThread().interrupt();
throw new AssertionError("interrupted", interruptedException);
}
}
/**
* Keeps track of whether the {@link LogEvent} instances it receives match the expected content.
*/
public interface LoggingExpectation {
/**
* Called on every {@link LogEvent} received by the captured appenders.
*/
void match(LogEvent event);
/**
* Returns if this expectation is matched, otherwise throws an {@link AssertionError}.
*/
void assertMatched();
/**
* Returns if this expectation is matched within the given number of milliseconds, otherwise throws an {@link AssertionError}.
*/
default void awaitMatched(long millis) throws InterruptedException {
assertMatched();
}
}
public abstract static class AbstractEventExpectation implements LoggingExpectation {
@ -123,14 +163,13 @@ public class MockLog implements Releasable {
protected final String logger;
protected final Level level;
protected final String message;
volatile boolean saw;
protected final CountDownLatch seenLatch = new CountDownLatch(1);
public AbstractEventExpectation(String name, String logger, Level level, String message) {
this.name = name;
this.logger = logger;
this.level = level;
this.message = message;
this.saw = false;
}
@Override
@ -138,11 +177,11 @@ public class MockLog implements Releasable {
if (event.getLevel().equals(level) && event.getLoggerName().equals(logger) && innerMatch(event)) {
if (Regex.isSimpleMatchPattern(message)) {
if (Regex.simpleMatch(message, event.getMessage().getFormattedMessage())) {
saw = true;
seenLatch.countDown();
}
} else {
if (event.getMessage().getFormattedMessage().contains(message)) {
saw = true;
seenLatch.countDown();
}
}
}
@ -162,7 +201,7 @@ public class MockLog implements Releasable {
@Override
public void assertMatched() {
assertThat("expected not to see " + name + " but did", saw, equalTo(false));
assertThat("expected not to see " + name + " but did", seenLatch.getCount(), equalTo(1L));
}
}
@ -174,7 +213,12 @@ public class MockLog implements Releasable {
@Override
public void assertMatched() {
assertThat("expected to see " + name + " but did not", saw, equalTo(true));
assertThat("expected to see " + name + " but did not", seenLatch.getCount(), equalTo(0L));
}
@Override
public void awaitMatched(long millis) throws InterruptedException {
assertThat("expected to see " + name + " but did not", seenLatch.await(millis, TimeUnit.MILLISECONDS), equalTo(true));
}
}
@ -195,7 +239,17 @@ public class MockLog implements Releasable {
if (expectSeen) {
super.assertMatched();
} else {
assertThat("expected not to see " + name + " yet but did", saw, equalTo(false));
assertThat("expected not to see " + name + " yet but did", seenLatch.getCount(), equalTo(1L));
}
}
@Override
public void awaitMatched(long millis) throws InterruptedException {
if (expectSeen) {
super.awaitMatched(millis);
} else {
// do not wait for negative expectation
assertThat("expected not to see " + name + " yet but did", seenLatch.getCount(), equalTo(1L));
}
}
}
@ -229,11 +283,11 @@ public class MockLog implements Releasable {
public static class PatternSeenEventExpectation implements LoggingExpectation {
protected final String name;
protected final String logger;
protected final Level level;
protected final Pattern pattern;
volatile boolean saw;
private final String name;
private final String logger;
private final Level level;
private final Pattern pattern;
private final CountDownLatch seenLatch = new CountDownLatch(1);
public PatternSeenEventExpectation(String name, String logger, Level level, String pattern) {
this.name = name;
@ -246,16 +300,20 @@ public class MockLog implements Releasable {
public void match(LogEvent event) {
if (event.getLevel().equals(level) && event.getLoggerName().equals(logger)) {
if (pattern.matcher(event.getMessage().getFormattedMessage()).matches()) {
saw = true;
seenLatch.countDown();
}
}
}
@Override
public void assertMatched() {
assertThat(name, saw, equalTo(true));
assertThat(name, seenLatch.getCount(), equalTo(0L));
}
@Override
public void awaitMatched(long millis) throws InterruptedException {
assertThat(name, seenLatch.await(millis, TimeUnit.MILLISECONDS), equalTo(true));
}
}
/**
@ -284,6 +342,15 @@ public class MockLog implements Releasable {
}
}
@Override
public void awaitMatched(long millis) throws InterruptedException {
try {
delegate.awaitMatched(millis);
} finally {
assertMatchedCalled = true;
}
}
@Override
public String toString() {
return delegate.toString();
@ -336,4 +403,17 @@ public class MockLog implements Releasable {
mockLog.assertAllExpectationsMatched();
}
}
/**
* Executes an action and waits until the given logging expectations are satisfied.
*/
public static void awaitLogger(Runnable action, Class<?> loggerOwner, MockLog.LoggingExpectation... expectations) {
try (var mockLog = MockLog.capture(loggerOwner)) {
for (var expectation : expectations) {
mockLog.addExpectation(expectation);
}
action.run();
mockLog.awaitAllExpectationsMatched();
}
}
}

6
test/framework/src/main/java/org/elasticsearch/transport/AbstractSimpleTransportTestCase.java
View File

@ -1373,7 +1373,7 @@ public abstract class AbstractSimpleTransportTestCase extends ESTestCase {
serviceA.sendRequest(nodeB, "internal:test", new StringMessageRequest("", 10), noopResponseHandler);
assertBusy(mockLog::assertAllExpectationsMatched);
mockLog.awaitAllExpectationsMatched();
////////////////////////////////////////////////////////////////////////
// tests for included action type "internal:testError" which returns an error
@ -1420,7 +1420,7 @@ public abstract class AbstractSimpleTransportTestCase extends ESTestCase {
serviceA.sendRequest(nodeB, "internal:testError", new StringMessageRequest(""), noopResponseHandler);
assertBusy(mockLog::assertAllExpectationsMatched);
mockLog.awaitAllExpectationsMatched();
////////////////////////////////////////////////////////////////////////
// tests for excluded action type "internal:testNotSeen"
@ -1467,7 +1467,7 @@ public abstract class AbstractSimpleTransportTestCase extends ESTestCase {
submitRequest(serviceA, nodeB, "internal:testNotSeen", new StringMessageRequest(""), noopResponseHandler).get();
assertBusy(mockLog::assertAllExpectationsMatched);
mockLog.awaitAllExpectationsMatched();
}
}

63
test/framework/src/test/java/org/elasticsearch/test/MockLogTests.java
View File

@ -9,8 +9,11 @@
package org.elasticsearch.test;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.elasticsearch.core.TimeValue;
import org.elasticsearch.test.junit.annotations.TestLogging;
import java.util.concurrent.atomic.AtomicBoolean;
@ -27,7 +30,7 @@ public class MockLogTests extends ESTestCase {
logThread.start();
for (int i = 0; i < 1000; i++) {
try (var mockLog = MockLog.capture(MockLogTests.class)) {
try (var ignored = MockLog.capture(MockLogTests.class)) {
Thread.yield();
}
}
@ -35,4 +38,62 @@ public class MockLogTests extends ESTestCase {
keepGoing.set(false);
logThread.join();
}
@TestLogging(reason = "checking log behaviour", value = "org.elasticsearch.test.MockLogTests:INFO")
public void testAwaitUnseenEvent() {
try (var mockLog = MockLog.capture(MockLogTests.class)) {
mockLog.addExpectation(
new MockLog.UnseenEventExpectation("unseen", MockLogTests.class.getCanonicalName(), Level.INFO, "unexpected")
);
Thread.currentThread().interrupt(); // ensures no blocking calls
mockLog.awaitAllExpectationsMatched();
mockLog.assertAllExpectationsMatched();
logger.info("unexpected");
expectThrows(AssertionError.class, mockLog::awaitAllExpectationsMatched);
expectThrows(AssertionError.class, mockLog::assertAllExpectationsMatched);
assertTrue(Thread.interrupted()); // clear interrupt flag again
}
}
@TestLogging(reason = "checking log behaviour", value = "org.elasticsearch.test.MockLogTests:INFO")
public void testAwaitSeenEvent() throws InterruptedException {
try (var mockLog = MockLog.capture(MockLogTests.class)) {
mockLog.addExpectation(new MockLog.SeenEventExpectation("seen", MockLogTests.class.getCanonicalName(), Level.INFO, "expected"));
expectThrows(AssertionError.class, () -> mockLog.awaitAllExpectationsMatched(TimeValue.timeValueMillis(10)));
expectThrows(AssertionError.class, mockLog::assertAllExpectationsMatched);
final var logThread = new Thread(() -> {
logger.info("expected");
mockLog.assertAllExpectationsMatched();
});
logThread.start();
mockLog.awaitAllExpectationsMatched();
mockLog.assertAllExpectationsMatched();
logThread.join();
}
}
@TestLogging(reason = "checking log behaviour", value = "org.elasticsearch.test.MockLogTests:INFO")
public void testAwaitPatternEvent() throws InterruptedException {
try (var mockLog = MockLog.capture(MockLogTests.class)) {
mockLog.addExpectation(
new MockLog.PatternSeenEventExpectation("seen", MockLogTests.class.getCanonicalName(), Level.INFO, ".*expected.*")
);
expectThrows(AssertionError.class, () -> mockLog.awaitAllExpectationsMatched(TimeValue.timeValueMillis(10)));
expectThrows(AssertionError.class, mockLog::assertAllExpectationsMatched);
final var logThread = new Thread(() -> {
logger.info("blah blah expected blah blah");
mockLog.assertAllExpectationsMatched();
});
logThread.start();
mockLog.awaitAllExpectationsMatched();
mockLog.assertAllExpectationsMatched();
logThread.join();
}
}
}

2
x-pack/plugin/snapshot-based-recoveries/src/internalClusterTest/java/org/elasticsearch/xpack/snapshotbasedrecoveries/recovery/SnapshotBasedIndexRecoveryIT.java
View File

@ -623,7 +623,7 @@ public class SnapshotBasedIndexRecoveryIT extends AbstractSnapshotIntegTestCase
assertAcked(indicesAdmin().prepareDelete(indexName).get());
assertBusy(mockLog::assertAllExpectationsMatched);
mockLog.awaitAllExpectationsMatched();
}
respondToRecoverSnapshotFile.countDown();