Added logging specification tests #1740
Conversation
This comment was marked as resolved.
This comment was marked as resolved.
Sorry, something went wrong.
JAVA-4770
There was a problem hiding this comment.
Pull Request Overview
This PR removes skip markers for several logging tests and updates logging-related code to support the new logging specification tests. Key changes include:
- Enabling logging specification tests by removing skip instructions for JAVA-4770.
- Updating test methods to include new ignoreMessages parameters.
- Refactoring logging routines in core connection components to use StructuredLogger.
Reviewed Changes
Copilot reviewed 11 out of 11 changed files in this pull request and generated no comments.
Show a summary per file
| File | Description |
|---|---|
| driver-sync/src/test/functional/com/mongodb/client/unified/UnifiedTestModifications.java | Removed skip markers for logging tests. |
| driver-sync/src/test/functional/com/mongodb/client/unified/UnifiedTest.java | Added parameter to pass ignoreMessages to log message assertion. |
| driver-sync/src/test/functional/com/mongodb/client/unified/LogMatcher.java | Updated log filtering and renaming helper methods. |
| driver-sync/src/test/functional/com/mongodb/client/unified/ContextElement.java | Updated mapping to utilize the new log document conversion method. |
| driver-reactive-streams/src/test/functional/com/mongodb/reactivestreams/client/unified/UnifiedServerDiscoveryAndMonitoringTest.java | Minor formatting update. |
| driver-core/src/main/com/mongodb/internal/logging/LogMessage.java | Added a new log entry type AWAITED. |
| driver-core/src/main/com/mongodb/internal/connection/SingleServerCluster.java | Modified the order of setting the server instance relative to publishing a description. |
| driver-core/src/main/com/mongodb/internal/connection/LoadBalancedCluster.java | Replaced topology closed logging with topology monitoring stopping. |
| driver-core/src/main/com/mongodb/internal/connection/DefaultServerMonitor.java | Added structured logging methods for heartbeat events and monitoring lifecycle. |
| driver-core/src/main/com/mongodb/internal/connection/DefaultServer.java | Introduced StructuredLogger for connection logging. |
| driver-core/src/main/com/mongodb/internal/connection/BaseCluster.java | Updated logging method names to align with the new structured logging pattern. |
Comments suppressed due to low confidence (1)
driver-core/src/main/com/mongodb/internal/connection/SingleServerCluster.java:63
- Reordering the call to server.set so that it occurs after publishDescription may impact the initialization flow. Please verify that this change is intentional and does not introduce any race conditions.
server.set(createServer(settings.getHosts().get(0)));
| @@ -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)) | |||
There was a problem hiding this comment.
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.
| new LogMessage.Entry(TOPOLOGY_ID, serverId.getClusterId()), | ||
| new LogMessage.Entry(AWAITED, awaited)), | ||
| "Heartbeat started for {}:{} on connection with driver-generated ID {} and server-generated ID {} " | ||
| + "in topology with ID {}. Awaited: {}")); |
There was a problem hiding this comment.
This is extremely minor, but the + is not indented here, but is below.
| @@ -336,7 +336,7 @@ 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(30)); | |||
There was a problem hiding this comment.
Updated to 15 - I just wanted to ensure that the server monitor through runs at least once. I think it defaults to every 10 seconds.
Changed to 15 to ensure servermonitor runs at least once.
Nit removed
There was a problem hiding this comment.
Strangely, when I run the tests locally, both the sync and reactive runners consistently fail the standalone-logging: Topology lifecycle test.
java.lang.AssertionError: Expected BSON values to be equal
Assertion Context:
Value Matching Context:
Key: message
Expected value:
BsonString{value='Topology description changed'}
Actual value:
BsonString{value='Stopped server monitoring'}
I imagine you're not seeing that?
| @@ -235,14 +235,15 @@ public static void applyCustomizations(final TestDef def) { | |||
|
|
|||
| // server-discovery-and-monitoring (SDAM) | |||
|
|
|||
| def.retry("Flaky test,due to a race waiting for the failed heartbeat.") | |||
There was a problem hiding this comment.
I hate to add new flaky tests off the bat like this. Do you understand the root cause of the flakiness? I'm curious also if they are flaky for other drivers.
JAVA-4770