Skip to content

Added logging specification tests #1740

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 16 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -116,9 +116,9 @@ abstract class BaseCluster implements Cluster {
this.settings = notNull("settings", settings);
this.serverFactory = notNull("serverFactory", serverFactory);
this.clusterListener = singleClusterListener(settings);
logTopologyMonitoringStarting(clusterId);
ClusterOpeningEvent clusterOpeningEvent = new ClusterOpeningEvent(clusterId);
clusterListener.clusterOpening(clusterOpeningEvent);
logTopologyOpening(clusterId, clusterOpeningEvent);
description = new ClusterDescription(settings.getMode(), UNKNOWN, emptyList(),
settings, serverFactory.getSettings());
}
Expand Down Expand Up @@ -219,9 +219,9 @@ public void close() {
phase.get().countDown();
fireChangeEvent(new ClusterDescription(settings.getMode(), UNKNOWN, emptyList(), settings, serverFactory.getSettings()),
description);
logTopologyMonitoringStopping(clusterId);
ClusterClosedEvent clusterClosedEvent = new ClusterClosedEvent(clusterId);
clusterListener.clusterClosed(clusterClosedEvent);
logTopologyClosedEvent(clusterId, clusterClosedEvent);
stopWaitQueueHandler();
}
}
Expand Down Expand Up @@ -249,8 +249,8 @@ protected void updateDescription(final ClusterDescription newDescription) {
protected void fireChangeEvent(final ClusterDescription newDescription, final ClusterDescription previousDescription) {
if (!wouldDescriptionsGenerateEquivalentEvents(newDescription, previousDescription)) {
ClusterDescriptionChangedEvent changedEvent = new ClusterDescriptionChangedEvent(getClusterId(), newDescription, previousDescription);
clusterListener.clusterDescriptionChanged(changedEvent);
logTopologyDescriptionChanged(getClusterId(), changedEvent);
clusterListener.clusterDescriptionChanged(changedEvent);
}
}

Expand Down Expand Up @@ -632,9 +632,7 @@ static void logServerSelectionSucceeded(
}
}

static void logTopologyOpening(
final ClusterId clusterId,
final ClusterOpeningEvent clusterOpeningEvent) {
static void logTopologyMonitoringStarting(final ClusterId clusterId) {
if (STRUCTURED_LOGGER.isRequired(DEBUG, clusterId)) {
STRUCTURED_LOGGER.log(new LogMessage(
TOPOLOGY, DEBUG, "Starting topology monitoring", clusterId,
Expand All @@ -659,9 +657,7 @@ static void logTopologyDescriptionChanged(
}
}

static void logTopologyClosedEvent(
final ClusterId clusterId,
final ClusterClosedEvent clusterClosedEvent) {
static void logTopologyMonitoringStopping(final ClusterId clusterId) {
if (STRUCTURED_LOGGER.isRequired(DEBUG, clusterId)) {
STRUCTURED_LOGGER.log(new LogMessage(
TOPOLOGY, DEBUG, "Stopped topology monitoring", clusterId,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -75,7 +75,6 @@ class DefaultServer implements ClusterableServer {
this.connectionPool = notNull("connectionPool", connectionPool);

this.serverId = serverId;

serverListener.serverOpening(new ServerOpeningEvent(this.serverId));

this.serverMonitor = serverMonitor;
Expand Down

Large diffs are not rendered by default.

Original file line number Diff line number Diff line change
Expand Up @@ -63,7 +63,7 @@
import static com.mongodb.connection.ServerConnectionState.CONNECTING;
import static com.mongodb.internal.connection.BaseCluster.logServerSelectionStarted;
import static com.mongodb.internal.connection.BaseCluster.logServerSelectionSucceeded;
import static com.mongodb.internal.connection.BaseCluster.logTopologyClosedEvent;
import static com.mongodb.internal.connection.BaseCluster.logTopologyMonitoringStopping;
import static com.mongodb.internal.event.EventListenerHelper.singleClusterListener;
import static java.lang.String.format;
import static java.util.Collections.emptyList;
Expand Down Expand Up @@ -273,9 +273,9 @@ public void close() {
if (localServer != null) {
localServer.close();
}
logTopologyMonitoringStopping(clusterId);
ClusterClosedEvent clusterClosedEvent = new ClusterClosedEvent(clusterId);
clusterListener.clusterClosed(clusterClosedEvent);
logTopologyClosedEvent(clusterId, clusterClosedEvent);
}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -58,9 +58,9 @@ public SingleServerCluster(final ClusterId clusterId, final ClusterSettings sett
// synchronized in the constructor because the change listener is re-entrant to this instance.
// In other words, we are leaking a reference to "this" from the constructor.
withLock(() -> {
server.set(createServer(settings.getHosts().get(0)));
publishDescription(ServerDescription.builder().state(CONNECTING).address(settings.getHosts().get(0))
Copy link
Member Author

@rozza rozza Jun 16, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The tests expect the toplogy description changed to connecting & unknown to be logged before the starting the server monitor log message.

Creating the server first meant that they were the wrong way around.

.build());
server.set(createServer(settings.getHosts().get(0)));
});
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -108,6 +108,7 @@ public enum Name {
* Not supported.
*/
OPERATION("operation"),
AWAITED("awaited"),
SERVICE_ID("serviceId"),
SERVER_CONNECTION_ID("serverConnectionId"),
DRIVER_CONNECTION_ID("driverConnectionId"),
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,6 @@
package com.mongodb.reactivestreams.client.unified;

import org.junit.jupiter.params.provider.Arguments;

import java.util.Collection;

final class UnifiedServerDiscoveryAndMonitoringTest extends UnifiedReactiveStreamsTest {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -495,7 +495,7 @@ public String toString() {
+ new BsonDocument("messages", expectedMessages).toJson(JsonWriterSettings.builder().indent(true).build()) + "\n"
+ " actualMessages="
+ new BsonDocument("messages", new BsonArray(actualMessages.stream()
.map(LogMatcher::asDocument).collect(Collectors.toList())))
.map(LogMatcher::logMessageAsDocument).collect(Collectors.toList())))
.toJson(JsonWriterSettings.builder().indent(true).build()) + "\n";
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -336,12 +336,12 @@ public <T> void waitForServerMonitorEvents(final String client, final Class<T> e
BsonDocument expectedEventContents = getEventContents(expectedEvent);
try {
serverMonitorListener.waitForEvents(expectedEventType,
event -> serverMonitorEventMatches(expectedEventContents, event, null), count, Duration.ofSeconds(10));
event -> serverMonitorEventMatches(expectedEventContents, event, null), count, Duration.ofSeconds(15));
context.pop();
} catch (InterruptedException e) {
throw new RuntimeException(e);
} catch (TimeoutException e) {
fail(context.getMessage("Timed out waiting for server monitor events"));
fail(context.getMessage(e.getMessage()));
}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@

import java.util.Collection;
import java.util.List;
import java.util.stream.Collectors;

import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertTrue;
Expand All @@ -47,15 +48,20 @@ final class LogMatcher {
this.context = context;
}

void assertLogMessageEquality(final String client, final boolean ignoreExtraMessages, final BsonArray expectedMessages,
void assertLogMessageEquality(final String client, final BsonArray ignoreMessages,
final boolean ignoreExtraMessages, final BsonArray expectedMessages,
final List<LogMessage> actualMessages, final Iterable<Tweak> tweaks) {
context.push(ContextElement.ofLogMessages(client, expectedMessages, actualMessages));

List<LogMessage> logMessages = actualMessages.stream()
.filter(logMessage -> !ignoreMessages.contains(logMessageAsIgnoreMessageDocument(logMessage)))
.collect(Collectors.toList());

if (ignoreExtraMessages) {
assertTrue(context.getMessage("Number of messages must be greater than or equal to the expected number of messages"),
actualMessages.size() >= expectedMessages.size());
logMessages.size() >= expectedMessages.size());
} else {
assertEquals(context.getMessage("Number of log messages must be the same"), expectedMessages.size(), actualMessages.size());
assertEquals(context.getMessage("Number of log messages must be the same"), expectedMessages.size(), logMessages.size());
}

for (int i = 0; i < expectedMessages.size(); i++) {
Expand All @@ -64,14 +70,22 @@ void assertLogMessageEquality(final String client, final boolean ignoreExtraMess
expectedMessage = tweak.apply(expectedMessage);
}
if (expectedMessage != null) {
valueMatcher.assertValuesMatch(expectedMessage, asDocument(actualMessages.get(i)));
valueMatcher.assertValuesMatch(expectedMessage, logMessageAsDocument(logMessages.get(i)));
}
}

context.pop();
}

static BsonDocument asDocument(final LogMessage message) {
private static BsonDocument logMessageAsIgnoreMessageDocument(final LogMessage message) {
BsonDocument document = new BsonDocument();
document.put("level", new BsonString(message.getLevel().name().toLowerCase()));
document.put("component", new BsonString(message.getComponent().getValue()));
document.put("data", new BsonDocument("message", new BsonString(message.getMessageId())));
return document;
}

static BsonDocument logMessageAsDocument(final LogMessage message) {
BsonDocument document = new BsonDocument();
document.put("component", new BsonString(message.getComponent().getValue()));
document.put("level", new BsonString(message.getLevel().name().toLowerCase()));
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -481,10 +481,11 @@ private void compareLogMessages(final UnifiedTestContext rootContext, final Bson
for (BsonValue cur : definition.getArray("expectLogMessages")) {
BsonDocument curLogMessagesForClient = cur.asDocument();
boolean ignoreExtraMessages = curLogMessagesForClient.getBoolean("ignoreExtraMessages", BsonBoolean.FALSE).getValue();
BsonArray ignoreMessages = curLogMessagesForClient.getArray("ignoreMessages", new BsonArray());
String clientId = curLogMessagesForClient.getString("client").getValue();
TestLoggingInterceptor loggingInterceptor =
entities.getClientLoggingInterceptor(clientId);
rootContext.getLogMatcher().assertLogMessageEquality(clientId, ignoreExtraMessages,
rootContext.getLogMatcher().assertLogMessageEquality(clientId, ignoreMessages, ignoreExtraMessages,
curLogMessagesForClient.getArray("messages"), loggingInterceptor.getMessages(), tweaks);
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -238,11 +238,6 @@ public static void applyCustomizations(final TestDef def) {
def.skipJira("https://jira.mongodb.org/browse/JAVA-5230")
.test("server-discovery-and-monitoring", "serverMonitoringMode", "connect with serverMonitoringMode=auto >=4.4")
.test("server-discovery-and-monitoring", "serverMonitoringMode", "connect with serverMonitoringMode=stream >=4.4");
def.skipJira("https://jira.mongodb.org/browse/JAVA-4770")
.file("server-discovery-and-monitoring", "standalone-logging")
.file("server-discovery-and-monitoring", "replicaset-logging")
.file("server-discovery-and-monitoring", "sharded-logging")
.file("server-discovery-and-monitoring", "loadbalanced-logging");
def.skipJira("https://jira.mongodb.org/browse/JAVA-5564")
.test("server-discovery-and-monitoring", "serverMonitoringMode", "poll waits after successful heartbeat");
def.skipJira("https://jira.mongodb.org/browse/JAVA-4536")
Expand Down