Skip to content

Add databaseName to command succeeded/failed events/logs #1213

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.

Sign up for GitHub

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

Merged
jyemin merged 3 commits into from
Oct 5, 2023
Merged

Add databaseName to command succeeded/failed events/logs #1213

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
1d6c496
Add databaseName to command succeeded/failed events/logs
jyemin Oct 3, 2023
292cc92
Fix tests
jyemin Oct 3, 2023
345bf9c
Fix LoggingCommandEventSenderSpecification
jyemin Oct 3, 2023
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
39 changes: 35 additions & 4 deletions driver-core/src/main/com/mongodb/event/CommandEvent.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,8 @@ public abstract class CommandEvent {
private final int requestId;
private final ConnectionDescription connectionDescription;
private final String commandName;
private final String databaseName;

private final long operationId;

/**
Expand All @@ -41,30 +43,49 @@ public abstract class CommandEvent {
* @param requestId the request id
* @param connectionDescription the connection description
* @param commandName the command name
* @since 4.10
* @param databaseName the database name
* @since 4.11
*/
public CommandEvent(@Nullable final RequestContext requestContext, final long operationId, final int requestId,
final ConnectionDescription connectionDescription, final String commandName) {
final ConnectionDescription connectionDescription, final String commandName, final String databaseName) {
this.requestContext = requestContext;
this.requestId = requestId;
this.connectionDescription = connectionDescription;
this.commandName = commandName;
this.databaseName = databaseName;
this.operationId = operationId;
}

/**
* Construct an instance.
*
* @param requestContext the request context
* @param operationId the operation id
* @param requestId the request id
* @param connectionDescription the connection description
* @param commandName the command name
* @since 4.10
* @deprecated Prefer {@link CommandEvent#CommandEvent(RequestContext, long, int, ConnectionDescription, String, String)}
*/
@Deprecated
public CommandEvent(@Nullable final RequestContext requestContext, final long operationId, final int requestId,
final ConnectionDescription connectionDescription, final String commandName) {
this(requestContext, -1, requestId, connectionDescription, commandName, "");
}

/**
* Construct an instance.
* @param requestContext the request context
* @param requestId the request id
* @param connectionDescription the connection description
* @param commandName the command name
* @since 4.4
* @deprecated Prefer {@link CommandEvent#CommandEvent(RequestContext, long, int, ConnectionDescription, String)}
* @deprecated Prefer {@link CommandEvent#CommandEvent(RequestContext, long, int, ConnectionDescription, String, String)}
*/
@Deprecated
public CommandEvent(@Nullable final RequestContext requestContext, final int requestId,
final ConnectionDescription connectionDescription, final String commandName) {
this(requestContext, -1, requestId, connectionDescription, commandName);
this(requestContext, -1, requestId, connectionDescription, commandName, "");
}

/**
Expand Down Expand Up @@ -114,6 +135,16 @@ public String getCommandName() {
return commandName;
}

/**
* Gets the database on which the operation will be executed.
*
* @return the database name
* @since 4.11
*/
public String getDatabaseName() {
return databaseName;
}

/**
* Gets the request context associated with this event.
*
Expand Down
25 changes: 24 additions & 1 deletion driver-core/src/main/com/mongodb/event/CommandFailedEvent.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,27 @@ public final class CommandFailedEvent extends CommandEvent {
private final long elapsedTimeNanos;
private final Throwable throwable;

/**
* Construct an instance.
*
* @param requestContext the request context
* @param operationId the operation id
* @param requestId the request id
* @param connectionDescription the connection description
* @param commandName the command name
* @param elapsedTimeNanos the non-negative elapsed time in nanoseconds for the operation to complete
* @param throwable the throwable cause of the failure
* @since 4.11
*/
public CommandFailedEvent(@Nullable final RequestContext requestContext, final long operationId, final int requestId,
final ConnectionDescription connectionDescription, final String commandName,
final String databaseName, final long elapsedTimeNanos, final Throwable throwable) {
super(requestContext, operationId, requestId, connectionDescription, commandName, databaseName);
isTrueArgument("elapsed time is not negative", elapsedTimeNanos >= 0);
this.elapsedTimeNanos = elapsedTimeNanos;
this.throwable = throwable;
}

/**
* Construct an instance.
*
Expand All @@ -45,7 +66,9 @@ public final class CommandFailedEvent extends CommandEvent {
* @param elapsedTimeNanos the non-negative elapsed time in nanoseconds for the operation to complete
* @param throwable the throwable cause of the failure
* @since 4.10
* {@link CommandFailedEvent#CommandFailedEvent(RequestContext, long, int, ConnectionDescription, String, String, long, Throwable)}
*/
@Deprecated
public CommandFailedEvent(@Nullable final RequestContext requestContext, final long operationId, final int requestId,
final ConnectionDescription connectionDescription, final String commandName, final long elapsedTimeNanos,
final Throwable throwable) {
Expand All @@ -65,7 +88,7 @@ public CommandFailedEvent(@Nullable final RequestContext requestContext, final l
* @param throwable the throwable cause of the failure
* @since 4.4
* @deprecated Prefer
* {@link CommandFailedEvent#CommandFailedEvent(RequestContext, long, int, ConnectionDescription, String, long, Throwable)}
* {@link CommandFailedEvent#CommandFailedEvent(RequestContext, long, int, ConnectionDescription, String, String, long, Throwable)}
*/
@Deprecated
public CommandFailedEvent(@Nullable final RequestContext requestContext, final int requestId,
Expand Down
13 changes: 1 addition & 12 deletions driver-core/src/main/com/mongodb/event/CommandStartedEvent.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,6 @@
* @since 3.1
*/
public final class CommandStartedEvent extends CommandEvent {
private final String databaseName;
private final BsonDocument command;

/**
Expand All @@ -45,8 +44,7 @@ public final class CommandStartedEvent extends CommandEvent {
public CommandStartedEvent(@Nullable final RequestContext requestContext, final long operationId, final int requestId,
final ConnectionDescription connectionDescription, final String databaseName, final String commandName,
final BsonDocument command) {
super(requestContext, operationId, requestId, connectionDescription, commandName);
this.databaseName = databaseName;
super(requestContext, operationId, requestId, connectionDescription, commandName, databaseName);
this.command = command;
}

Expand Down Expand Up @@ -87,15 +85,6 @@ public CommandStartedEvent(final int requestId, final ConnectionDescription conn
this(null, requestId, connectionDescription, databaseName, commandName, command);
}

/**
* Gets the database on which the operation will be executed.
*
* @return the database name
*/
public String getDatabaseName() {
return databaseName;
}

/**
* Gets the command document. The document is only usable within the method that delivered the event. If it's needed for longer, it
* must be cloned via {@link Object#clone()}.
Expand Down
27 changes: 26 additions & 1 deletion driver-core/src/main/com/mongodb/event/CommandSucceededEvent.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,28 @@ public final class CommandSucceededEvent extends CommandEvent {
private final BsonDocument response;
private final long elapsedTimeNanos;

/**
* Construct an instance.
*
* @param requestContext the request context
* @param operationId the operation id
* @param requestId the request id
* @param connectionDescription the connection description
* @param commandName the command name
* @param databaseName the database name
* @param response the command response
* @param elapsedTimeNanos the non-negative elapsed time in nanoseconds for the operation to complete
* @since 4.11
*/
public CommandSucceededEvent(@Nullable final RequestContext requestContext, final long operationId, final int requestId,
final ConnectionDescription connectionDescription, final String commandName,
final String databaseName, final BsonDocument response, final long elapsedTimeNanos) {
super(requestContext, operationId, requestId, connectionDescription, commandName, databaseName);
this.response = response;
isTrueArgument("elapsed time is not negative", elapsedTimeNanos >= 0);
this.elapsedTimeNanos = elapsedTimeNanos;
}

/**
* Construct an instance.
*
Expand All @@ -45,7 +67,10 @@ public final class CommandSucceededEvent extends CommandEvent {
* @param response the command response
* @param elapsedTimeNanos the non-negative elapsed time in nanoseconds for the operation to complete
* @since 4.10
* @deprecated Prefer
* {@link CommandSucceededEvent#CommandSucceededEvent(RequestContext, long, int, ConnectionDescription, String, String, BsonDocument, long)}
*/
@Deprecated
public CommandSucceededEvent(@Nullable final RequestContext requestContext, final long operationId, final int requestId,
final ConnectionDescription connectionDescription, final String commandName, final BsonDocument response,
final long elapsedTimeNanos) {
Expand All @@ -65,7 +90,7 @@ public CommandSucceededEvent(@Nullable final RequestContext requestContext, fina
* @param elapsedTimeNanos the non-negative elapsed time in nanoseconds for the operation to complete
* @since 4.4
* @deprecated Prefer
* {@link CommandSucceededEvent#CommandSucceededEvent(RequestContext, long, int, ConnectionDescription, String, BsonDocument, long)}
* {@link CommandSucceededEvent#CommandSucceededEvent(RequestContext, long, int, ConnectionDescription, String, String, BsonDocument, long)}
*/
@Deprecated
public CommandSucceededEvent(@Nullable final RequestContext requestContext, final int requestId,
Expand Down
14 changes: 8 additions & 6 deletions driver-core/src/main/com/mongodb/internal/connection/LoggingCommandEventSender.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -97,7 +97,7 @@ class LoggingCommandEventSender implements CommandEventSender {
@Override
public void sendStartedEvent() {
if (loggingRequired()) {
String messagePrefix = "Command \"{}\" started on database {}";
String messagePrefix = "Command \"{}\" started on database \"{}\"";
String command = redactionRequired ? "{}" : getTruncatedJsonCommand(commandDocument);

logEventMessage(messagePrefix, "Command started", null, entries -> {
Expand Down Expand Up @@ -131,19 +131,20 @@ public void sendFailedEvent(final Throwable t) {
long elapsedTimeNanos = System.nanoTime() - startTimeNanos;

if (loggingRequired()) {
String messagePrefix = "Command \"{}\" failed in {} ms";
String messagePrefix = "Command \"{}\" failed on database \"{}\" in {} ms";

logEventMessage(messagePrefix, "Command failed", commandEventException,
entries -> {
entries.add(new Entry(COMMAND_NAME, commandName));
entries.add(new Entry(DATABASE_NAME, message.getNamespace().getDatabaseName()));
entries.add(new Entry(DURATION_MS, elapsedTimeNanos / NANOS_PER_MILLI));
},
entries -> entries.add(new Entry(COMMAND_CONTENT, null)));
}

if (eventRequired()) {
sendCommandFailedEvent(message, commandName, description, elapsedTimeNanos, commandEventException, commandListener,
requestContext, operationContext);
sendCommandFailedEvent(message, message.getNamespace().getDatabaseName(), commandName, description, elapsedTimeNanos,
Copy link
Member

@vbabanin vbabanin Oct 5, 2023 •
edited
Loading

Choose a reason for hiding this comment

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

nit/optional: message.getNamespace().getDatabaseName() is used in several places, so it can be extracted to a variable for improved readability.

commandEventException, commandListener, requestContext, operationContext);
}
}

Expand All @@ -161,7 +162,7 @@ private void sendSucceededEvent(final BsonDocument reply) {
long elapsedTimeNanos = System.nanoTime() - startTimeNanos;

if (loggingRequired()) {
String format = "Command \"{}\" succeeded in {} ms using a connection with driver-generated ID {}"
String format = "Command \"{}\" succeeded on database \"{}\" in {} ms using a connection with driver-generated ID {}"
+ "[ and server-generated ID {}] to {}:{}[ with service ID {}]. The request ID is {}"
+ " and the operation ID is {}. Command reply: {}";

Expand All @@ -171,14 +172,15 @@ private void sendSucceededEvent(final BsonDocument reply) {
logEventMessage("Command succeeded", null,
entries -> {
entries.add(new Entry(COMMAND_NAME, commandName));
entries.add(new Entry(DATABASE_NAME, message.getNamespace().getDatabaseName()));
entries.add(new Entry(DURATION_MS, elapsedTimeNanos / NANOS_PER_MILLI));
},
entries -> entries.add(new Entry(REPLY, replyString)), format);
}

if (eventRequired()) {
BsonDocument responseDocumentForEvent = redactionRequired ? new BsonDocument() : reply;
sendCommandSucceededEvent(message, commandName, responseDocumentForEvent, description,
sendCommandSucceededEvent(message, message.getNamespace().getDatabaseName(), commandName, responseDocumentForEvent, description,
elapsedTimeNanos, commandListener, requestContext, operationContext);
}
}
Expand Down
12 changes: 7 additions & 5 deletions driver-core/src/main/com/mongodb/internal/connection/ProtocolHelper.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -289,28 +289,30 @@ static void sendCommandStartedEvent(final RequestMessage message, final String d
}
}

static void sendCommandSucceededEvent(final RequestMessage message, final String commandName, final BsonDocument response,
final ConnectionDescription connectionDescription, final long elapsedTimeNanos,
static void sendCommandSucceededEvent(final RequestMessage message, final String databaseName, final String commandName,
final BsonDocument response, final ConnectionDescription connectionDescription, final long elapsedTimeNanos,
final CommandListener commandListener, final RequestContext requestContext, final OperationContext operationContext) {
notNull("requestContext", requestContext);
try {
commandListener.commandSucceeded(new CommandSucceededEvent(getRequestContextForEvent(requestContext),
operationContext.getId(), message.getId(), connectionDescription, commandName, response, elapsedTimeNanos));
operationContext.getId(), message.getId(), connectionDescription, commandName, databaseName, response,
elapsedTimeNanos));
} catch (Exception e) {
if (PROTOCOL_EVENT_LOGGER.isWarnEnabled()) {
PROTOCOL_EVENT_LOGGER.warn(format("Exception thrown raising command succeeded event to listener %s", commandListener), e);
}
}
}

static void sendCommandFailedEvent(final RequestMessage message, final String commandName,
static void sendCommandFailedEvent(final RequestMessage message, final String databaseName, final String commandName,
final ConnectionDescription connectionDescription, final long elapsedTimeNanos,
final Throwable throwable, final CommandListener commandListener, final RequestContext requestContext,
final OperationContext operationContext) {
notNull("requestContext", requestContext);
try {
commandListener.commandFailed(new CommandFailedEvent(getRequestContextForEvent(requestContext),
operationContext.getId(), message.getId(), connectionDescription, commandName, elapsedTimeNanos, throwable));
operationContext.getId(), message.getId(), connectionDescription, commandName, databaseName, elapsedTimeNanos,
throwable));
} catch (Exception e) {
if (PROTOCOL_EVENT_LOGGER.isWarnEnabled()) {
PROTOCOL_EVENT_LOGGER.warn(format("Exception thrown raising command failed event to listener %s", commandListener), e);
Expand Down
2 changes: 1 addition & 1 deletion driver-core/src/test/functional/com/mongodb/internal/connection/TestCommandListener.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -250,7 +250,7 @@ else if (!observeSensitiveCommands) {
lock.lock();
try {
events.add(new CommandSucceededEvent(event.getRequestContext(), event.getOperationId(), event.getRequestId(),
event.getConnectionDescription(), event.getCommandName(),
event.getConnectionDescription(), event.getCommandName(), event.getDatabaseName(),
event.getResponse() == null ? null : event.getResponse().clone(),
event.getElapsedTime(TimeUnit.NANOSECONDS)));
commandCompletedCondition.signal();
Expand Down
Loading