From 0c2f73c0870e496a7c7e5b44bcddbdf26a0d1ec7 Mon Sep 17 00:00:00 2001 From: Jeff Yemin Date: Mon, 27 Mar 2023 16:43:11 -0400 Subject: [PATCH 1/4] Add operation id and elapsed time to connection check out/in events JAVA-4907 --- .../event/ConnectionCheckOutFailedEvent.java | 48 ++++++++++++++++- .../event/ConnectionCheckOutStartedEvent.java | 27 +++++++++- .../event/ConnectionCheckedInEvent.java | 46 ++++++++++++++++- .../event/ConnectionCheckedOutEvent.java | 45 +++++++++++++++- .../main/com/mongodb/internal/Timeout.java | 4 ++ .../connection/DefaultConnectionPool.java | 51 +++++++++++++------ 6 files changed, 201 insertions(+), 20 deletions(-) diff --git a/driver-core/src/main/com/mongodb/event/ConnectionCheckOutFailedEvent.java b/driver-core/src/main/com/mongodb/event/ConnectionCheckOutFailedEvent.java index 33aff9ae414..06bd1506185 100644 --- a/driver-core/src/main/com/mongodb/event/ConnectionCheckOutFailedEvent.java +++ b/driver-core/src/main/com/mongodb/event/ConnectionCheckOutFailedEvent.java @@ -18,6 +18,8 @@ import com.mongodb.connection.ServerId; +import java.util.concurrent.TimeUnit; + import static com.mongodb.assertions.Assertions.notNull; /** @@ -53,19 +55,40 @@ public enum Reason { } private final ServerId serverId; + private final long operationId; + private final long elapsedTimeNanos; + private final Reason reason; /** * Construct an instance * * @param serverId the server id + * @param operationId the operation id + * @param elapsedTimeNanos the elapsed time between check out started and check out failed * @param reason the reason the connection check out failed + * @since 4.10 */ - public ConnectionCheckOutFailedEvent(final ServerId serverId, final Reason reason) { + public ConnectionCheckOutFailedEvent(final ServerId serverId, final long operationId, final long elapsedTimeNanos, + final Reason reason) { this.serverId = notNull("serverId", serverId); + this.operationId = operationId; + this.elapsedTimeNanos = elapsedTimeNanos; this.reason = notNull("reason", reason); } + /** + * Construct an instance + * + * @param serverId the server id + * @param reason the reason the connection check out failed + * @deprecated Prefer {@link ConnectionCheckOutFailedEvent#ConnectionCheckOutFailedEvent(ServerId, long, long, Reason)} + */ + @Deprecated + public ConnectionCheckOutFailedEvent(final ServerId serverId, final Reason reason) { + this(serverId, -1, -1, reason); + } + /** * Gets the server id * @@ -75,6 +98,27 @@ public ServerId getServerId() { return serverId; } + /** + * Gets the operation identifier + * + * @return the operation identifier + * @since 4.10 + */ + public long getOperationId() { + return operationId; + } + + /** + * Gets the elapsed time between check out started and check out failed. + * + * @param timeUnit the time unit + * @return the elapsed time + * @since 4.10 + */ + public long getElapsedTime(final TimeUnit timeUnit) { + return timeUnit.convert(elapsedTimeNanos, TimeUnit.NANOSECONDS); + } + /** * Gets the reason for the check out failure. * @@ -90,6 +134,8 @@ public String toString() { return "ConnectionCheckOutFailedEvent{" + "server=" + serverId.getAddress() + ", clusterId=" + serverId.getClusterId() + + ", operationId=" + operationId + + ", elapsedTimeNanos=" + elapsedTimeNanos + ", reason=" + reason + '}'; } diff --git a/driver-core/src/main/com/mongodb/event/ConnectionCheckOutStartedEvent.java b/driver-core/src/main/com/mongodb/event/ConnectionCheckOutStartedEvent.java index f7f1bfdf8e9..463d7b2e39b 100644 --- a/driver-core/src/main/com/mongodb/event/ConnectionCheckOutStartedEvent.java +++ b/driver-core/src/main/com/mongodb/event/ConnectionCheckOutStartedEvent.java @@ -27,14 +27,28 @@ */ public final class ConnectionCheckOutStartedEvent { private final ServerId serverId; + private final long operationId; /** * Construct an instance * * @param serverId the server id + * @param operationId the operation id */ - public ConnectionCheckOutStartedEvent(final ServerId serverId) { + public ConnectionCheckOutStartedEvent(final ServerId serverId, final long operationId) { this.serverId = notNull("serverId", serverId); + this.operationId = operationId; + } + + /** + * Construct an instance + * + * @param serverId the server id + * @deprecated Prefer {@link ConnectionCheckOutStartedEvent#ConnectionCheckOutStartedEvent(ServerId, long)} + */ + @Deprecated + public ConnectionCheckOutStartedEvent(final ServerId serverId) { + this(serverId, -1); } /** @@ -46,11 +60,22 @@ public ServerId getServerId() { return serverId; } + /** + * Gets the operation identifier + * + * @return the operation identifier + * @since 4.10 + */ + public long getOperationId() { + return operationId; + } + @Override public String toString() { return "ConnectionCheckOutStartedEvent{" + "server=" + serverId.getAddress() + ", clusterId=" + serverId.getClusterId() + + ", operationId=" + operationId + '}'; } } diff --git a/driver-core/src/main/com/mongodb/event/ConnectionCheckedInEvent.java b/driver-core/src/main/com/mongodb/event/ConnectionCheckedInEvent.java index 37e1b2a4aa8..7fcdd97bdb5 100644 --- a/driver-core/src/main/com/mongodb/event/ConnectionCheckedInEvent.java +++ b/driver-core/src/main/com/mongodb/event/ConnectionCheckedInEvent.java @@ -18,6 +18,8 @@ import com.mongodb.connection.ConnectionId; +import java.util.concurrent.TimeUnit; + import static com.mongodb.assertions.Assertions.notNull; /** @@ -27,14 +29,33 @@ */ public final class ConnectionCheckedInEvent { private final ConnectionId connectionId; + private final long operationId; + private final long elapsedTimeNanos; + /** * Construct an instance * * @param connectionId the connectionId + * @param operationId the operation id + * @param elapsedTimeNanos the elapsed time between check out and check in + * @since 4.10 */ - public ConnectionCheckedInEvent(final ConnectionId connectionId) { + public ConnectionCheckedInEvent(final ConnectionId connectionId, final long operationId, final long elapsedTimeNanos) { this.connectionId = notNull("connectionId", connectionId); + this.operationId = operationId; + this.elapsedTimeNanos = elapsedTimeNanos; + } + + /** + * Construct an instance + * + * @param connectionId the connectionId + * @deprecated Prefer {@link ConnectionCheckedInEvent#ConnectionCheckedInEvent(ConnectionId, long, long)} + */ + @Deprecated + public ConnectionCheckedInEvent(final ConnectionId connectionId) { + this(connectionId, -1, -1); } /** @@ -46,12 +67,35 @@ public ConnectionId getConnectionId() { return connectionId; } + /** + * Gets the operation identifier + * + * @return the operation identifier + * @since 4.10 + */ + public long getOperationId() { + return operationId; + } + + /** + * Gets the elapsed time between check out and check in. + * + * @param timeUnit the time unit + * @return the elapsed time + * @since 4.10 + */ + public long getElapsedTime(final TimeUnit timeUnit) { + return timeUnit.convert(elapsedTimeNanos, TimeUnit.NANOSECONDS); + } + @Override public String toString() { return "ConnectionCheckedInEvent{" + "connectionId=" + connectionId + ", server=" + connectionId.getServerId().getAddress() + ", clusterId=" + connectionId.getServerId().getClusterId() + + ", operationId=" + operationId + + ", elapsedTimeNanos=" + elapsedTimeNanos + '}'; } } diff --git a/driver-core/src/main/com/mongodb/event/ConnectionCheckedOutEvent.java b/driver-core/src/main/com/mongodb/event/ConnectionCheckedOutEvent.java index 5ba6ff3f3f4..b2ff6632cd7 100644 --- a/driver-core/src/main/com/mongodb/event/ConnectionCheckedOutEvent.java +++ b/driver-core/src/main/com/mongodb/event/ConnectionCheckedOutEvent.java @@ -18,6 +18,8 @@ import com.mongodb.connection.ConnectionId; +import java.util.concurrent.TimeUnit; + import static com.mongodb.assertions.Assertions.notNull; /** @@ -27,14 +29,32 @@ */ public final class ConnectionCheckedOutEvent { private final ConnectionId connectionId; + private final long operationId; + private final long elapsedTimeNanos; /** * Construct an instance * * @param connectionId the connectionId + * @param operationId the operation id + * @param elapsedTimeNanos the elapsed time between check out started and check out + * @since 4.10 */ - public ConnectionCheckedOutEvent(final ConnectionId connectionId) { + public ConnectionCheckedOutEvent(final ConnectionId connectionId, final long operationId, final long elapsedTimeNanos) { this.connectionId = notNull("connectionId", connectionId); + this.operationId = operationId; + this.elapsedTimeNanos = elapsedTimeNanos; + } + + /** + * Construct an instance + * + * @param connectionId the connectionId + * @deprecated Prefer {@link ConnectionCheckedOutEvent#ConnectionCheckedOutEvent(ConnectionId, long, long)} + */ + @Deprecated + public ConnectionCheckedOutEvent(final ConnectionId connectionId) { + this(connectionId, -1, -1); } /** @@ -46,12 +66,35 @@ public ConnectionId getConnectionId() { return connectionId; } + /** + * Gets the operation identifier + * + * @return the operation identifier + * @since 4.10 + */ + public long getOperationId() { + return operationId; + } + + /** + * Gets the elapsed time between check out started and check out. + * + * @param timeUnit the time unit + * @return the elapsed time + * @since 4.10 + */ + public long getElapsedTime(final TimeUnit timeUnit) { + return timeUnit.convert(elapsedTimeNanos, TimeUnit.NANOSECONDS); + } + @Override public String toString() { return "ConnectionCheckedOutEvent{" + "connectionId=" + connectionId + ", server=" + connectionId.getServerId().getAddress() + ", clusterId=" + connectionId.getServerId().getClusterId() + + ", operationId=" + operationId + + ", elapsedTimeNanos=" + elapsedTimeNanos + '}'; } } diff --git a/driver-core/src/main/com/mongodb/internal/Timeout.java b/driver-core/src/main/com/mongodb/internal/Timeout.java index 7c2a2245aae..3c0cdfdfb3d 100644 --- a/driver-core/src/main/com/mongodb/internal/Timeout.java +++ b/driver-core/src/main/com/mongodb/internal/Timeout.java @@ -94,6 +94,10 @@ public static Timeout immediate() { return IMMEDIATE; } + public long getStartNanos() { + return startNanos; + } + /** * Must not be called on {@linkplain #isInfinite() infinite} or {@linkplain #isImmediate() immediate} timeouts. *

diff --git a/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java b/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java index a5d55f8e930..16ff56b041d 100644 --- a/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java +++ b/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java @@ -168,7 +168,7 @@ public InternalConnection get(final OperationContext operationContext) { @Override public InternalConnection get(final OperationContext operationContext, final long timeoutValue, final TimeUnit timeUnit) { - connectionPoolListener.connectionCheckOutStarted(new ConnectionCheckOutStartedEvent(serverId)); + connectionPoolListener.connectionCheckOutStarted(new ConnectionCheckOutStartedEvent(serverId, operationContext.getId())); Timeout timeout = Timeout.startNow(timeoutValue, timeUnit); try { stateAndGeneration.throwIfClosedOrPaused(); @@ -176,10 +176,12 @@ public InternalConnection get(final OperationContext operationContext, final lon if (!connection.opened()) { connection = openConcurrencyLimiter.openOrGetAvailable(connection, timeout); } - connectionPoolListener.connectionCheckedOut(new ConnectionCheckedOutEvent(getId(connection))); + connection.checkedOutForOperation(operationContext); + connectionPoolListener.connectionCheckedOut(new ConnectionCheckedOutEvent(getId(connection), operationContext.getId(), + System.nanoTime() - timeout.getStartNanos())); return connection; } catch (Exception e) { - throw (RuntimeException) checkOutFailed(e); + throw (RuntimeException) checkOutFailed(e, operationContext, System.nanoTime() - timeout.getStartNanos()); } } @@ -190,13 +192,14 @@ public void getAsync(final OperationContext operationContext, final SingleResult } connectionPoolListener.connectionCheckOutStarted(new ConnectionCheckOutStartedEvent(serverId)); Timeout timeout = Timeout.startNow(settings.getMaxWaitTime(NANOSECONDS)); - SingleResultCallback eventSendingCallback = (result, failure) -> { + SingleResultCallback eventSendingCallback = (connection, failure) -> { SingleResultCallback errHandlingCallback = errorHandlingCallback(callback, LOGGER); if (failure == null) { - connectionPoolListener.connectionCheckedOut(new ConnectionCheckedOutEvent(getId(result))); - errHandlingCallback.onResult(result, null); + connection.checkedOutForOperation(operationContext); + connectionPoolListener.connectionCheckedOut(new ConnectionCheckedOutEvent(getId(connection))); + errHandlingCallback.onResult(connection, null); } else { - errHandlingCallback.onResult(null, checkOutFailed(failure)); + errHandlingCallback.onResult(null, checkOutFailed(failure, operationContext, System.nanoTime() - timeout.getStartNanos())); } }; try { @@ -238,20 +241,23 @@ public void getAsync(final OperationContext operationContext, final SingleResult * and returns {@code t} if it is not {@link MongoOpenConnectionInternalException}, * or returns {@code t.}{@linkplain MongoOpenConnectionInternalException#getCause() getCause()} otherwise. */ - private Throwable checkOutFailed(final Throwable t) { + private Throwable checkOutFailed(final Throwable t, final OperationContext operationContext, final long elapsedTimeNanos) { Throwable result = t; + Reason reason; if (t instanceof MongoTimeoutException) { - connectionPoolListener.connectionCheckOutFailed(new ConnectionCheckOutFailedEvent(serverId, Reason.TIMEOUT)); + reason = Reason.TIMEOUT; } else if (t instanceof MongoOpenConnectionInternalException) { - connectionPoolListener.connectionCheckOutFailed(new ConnectionCheckOutFailedEvent(serverId, Reason.CONNECTION_ERROR)); + reason = Reason.CONNECTION_ERROR; result = t.getCause(); } else if (t instanceof MongoConnectionPoolClearedException) { - connectionPoolListener.connectionCheckOutFailed(new ConnectionCheckOutFailedEvent(serverId, Reason.CONNECTION_ERROR)); + reason = Reason.CONNECTION_ERROR; } else if (ConcurrentPool.isPoolClosedException(t)) { - connectionPoolListener.connectionCheckOutFailed(new ConnectionCheckOutFailedEvent(serverId, Reason.POOL_CLOSED)); + reason = Reason.POOL_CLOSED; } else { - connectionPoolListener.connectionCheckOutFailed(new ConnectionCheckOutFailedEvent(serverId, Reason.UNKNOWN)); + reason = Reason.UNKNOWN; } + connectionPoolListener.connectionCheckOutFailed(new ConnectionCheckOutFailedEvent(serverId, operationContext.getId(), + elapsedTimeNanos, reason)); return result; } @@ -516,6 +522,8 @@ private class PooledConnection implements InternalConnection { private final UsageTrackingInternalConnection wrapped; private final AtomicBoolean isClosed = new AtomicBoolean(); private Connection.PinningMode pinningMode; + private volatile long operationId; + private volatile long checkedOutTimeNanos; PooledConnection(final UsageTrackingInternalConnection wrapped) { this.wrapped = notNull("wrapped", wrapped); @@ -526,12 +534,21 @@ public int getGeneration() { return wrapped.getGeneration(); } + /** + * Associates this with the operation context and establishes the checked out start time + */ + public void checkedOutForOperation(final OperationContext operationContext) { + this.checkedOutTimeNanos = System.nanoTime(); + this.operationId = operationContext.getId(); + } + @Override public void open() { assertFalse(isClosed.get()); try { connectionCreated(connectionPoolListener, wrapped.getDescription().getConnectionId()); wrapped.open(); + checkedOutTimeNanos = System.nanoTime(); } catch (Exception e) { closeAndHandleOpenFailure(); throw new MongoOpenConnectionInternalException(e); @@ -544,6 +561,7 @@ public void openAsync(final SingleResultCallback callback) { assertFalse(isClosed.get()); connectionCreated(connectionPoolListener, wrapped.getDescription().getConnectionId()); wrapped.openAsync((nullResult, failure) -> { + checkedOutTimeNanos = System.nanoTime(); if (failure != null) { closeAndHandleOpenFailure(); callback.onResult(null, new MongoOpenConnectionInternalException(failure)); @@ -559,7 +577,8 @@ public void close() { // All but the first call is a no-op if (!isClosed.getAndSet(true)) { unmarkAsPinned(); - connectionPoolListener.connectionCheckedIn(new ConnectionCheckedInEvent(getId(wrapped))); + connectionPoolListener.connectionCheckedIn(new ConnectionCheckedInEvent(getId(wrapped), operationId, + System.nanoTime() - checkedOutTimeNanos)); if (LOGGER.isTraceEnabled()) { LOGGER.trace(format("Checked in connection [%s] to server %s", getId(wrapped), serverId.getAddress())); } @@ -731,7 +750,7 @@ public ServerDescription getInitialServerDescription() { /** * This internal exception is used to express an exceptional situation encountered when opening a connection. * It exists because it allows consolidating the code that sends events for exceptional situations in a - * {@linkplain #checkOutFailed(Throwable) single place}, it must not be observable by an external code. + * {@linkplain #checkOutFailed(Throwable, OperationContext, long) single place}, it must not be observable by an external code. */ private static final class MongoOpenConnectionInternalException extends RuntimeException { private static final long serialVersionUID = 1; @@ -919,7 +938,7 @@ private PooledConnection openWithConcurrencyLimit(final PooledConnection connect * */ void openAsyncWithConcurrencyLimit( - final PooledConnection connection, final Timeout timeout, final SingleResultCallback callback) { + final PooledConnection connection, final Timeout timeout, final SingleResultCallback callback) { PooledConnection availableConnection; try {//phase one availableConnection = acquirePermitOrGetAvailableOpenedConnection(true, timeout); From 0316a90b6c4086b2dfe096a56a38c8caf82ce2cd Mon Sep 17 00:00:00 2001 From: Jeff Yemin Date: Fri, 14 Apr 2023 15:10:15 -0400 Subject: [PATCH 2/4] * Javadoc * Use new constructors --- .../com/mongodb/event/ConnectionCheckOutStartedEvent.java | 1 + .../mongodb/internal/connection/DefaultConnectionPool.java | 5 +++-- 2 files changed, 4 insertions(+), 2 deletions(-) diff --git a/driver-core/src/main/com/mongodb/event/ConnectionCheckOutStartedEvent.java b/driver-core/src/main/com/mongodb/event/ConnectionCheckOutStartedEvent.java index 463d7b2e39b..3c8cef9e0ca 100644 --- a/driver-core/src/main/com/mongodb/event/ConnectionCheckOutStartedEvent.java +++ b/driver-core/src/main/com/mongodb/event/ConnectionCheckOutStartedEvent.java @@ -34,6 +34,7 @@ public final class ConnectionCheckOutStartedEvent { * * @param serverId the server id * @param operationId the operation id + * @since 4.10 */ public ConnectionCheckOutStartedEvent(final ServerId serverId, final long operationId) { this.serverId = notNull("serverId", serverId); diff --git a/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java b/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java index 16ff56b041d..136d93fa0ed 100644 --- a/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java +++ b/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java @@ -190,13 +190,14 @@ public void getAsync(final OperationContext operationContext, final SingleResult if (LOGGER.isTraceEnabled()) { LOGGER.trace(format("Asynchronously getting a connection from the pool for server %s", serverId)); } - connectionPoolListener.connectionCheckOutStarted(new ConnectionCheckOutStartedEvent(serverId)); + connectionPoolListener.connectionCheckOutStarted(new ConnectionCheckOutStartedEvent(serverId, operationContext.getId())); Timeout timeout = Timeout.startNow(settings.getMaxWaitTime(NANOSECONDS)); SingleResultCallback eventSendingCallback = (connection, failure) -> { SingleResultCallback errHandlingCallback = errorHandlingCallback(callback, LOGGER); if (failure == null) { connection.checkedOutForOperation(operationContext); - connectionPoolListener.connectionCheckedOut(new ConnectionCheckedOutEvent(getId(connection))); + connectionPoolListener.connectionCheckedOut(new ConnectionCheckedOutEvent(getId(connection), operationContext.getId(), + System.nanoTime() - timeout.getStartNanos())); errHandlingCallback.onResult(connection, null); } else { errHandlingCallback.onResult(null, checkOutFailed(failure, operationContext, System.nanoTime() - timeout.getStartNanos())); From 697ba0d2957191468e9831798bd7978a3d717414 Mon Sep 17 00:00:00 2001 From: Jeff Yemin Date: Fri, 14 Apr 2023 15:37:37 -0400 Subject: [PATCH 3/4] Remove elapsedTime :( --- .../event/ConnectionCheckOutFailedEvent.java | 24 +++---------------- .../event/ConnectionCheckedInEvent.java | 23 +++--------------- .../event/ConnectionCheckedOutEvent.java | 23 +++--------------- .../main/com/mongodb/internal/Timeout.java | 3 --- .../connection/DefaultConnectionPool.java | 24 +++++++------------ 5 files changed, 17 insertions(+), 80 deletions(-) diff --git a/driver-core/src/main/com/mongodb/event/ConnectionCheckOutFailedEvent.java b/driver-core/src/main/com/mongodb/event/ConnectionCheckOutFailedEvent.java index 06bd1506185..3d4ad307908 100644 --- a/driver-core/src/main/com/mongodb/event/ConnectionCheckOutFailedEvent.java +++ b/driver-core/src/main/com/mongodb/event/ConnectionCheckOutFailedEvent.java @@ -18,8 +18,6 @@ import com.mongodb.connection.ServerId; -import java.util.concurrent.TimeUnit; - import static com.mongodb.assertions.Assertions.notNull; /** @@ -56,7 +54,6 @@ public enum Reason { private final ServerId serverId; private final long operationId; - private final long elapsedTimeNanos; private final Reason reason; @@ -65,15 +62,12 @@ public enum Reason { * * @param serverId the server id * @param operationId the operation id - * @param elapsedTimeNanos the elapsed time between check out started and check out failed * @param reason the reason the connection check out failed * @since 4.10 */ - public ConnectionCheckOutFailedEvent(final ServerId serverId, final long operationId, final long elapsedTimeNanos, - final Reason reason) { + public ConnectionCheckOutFailedEvent(final ServerId serverId, final long operationId, final Reason reason) { this.serverId = notNull("serverId", serverId); this.operationId = operationId; - this.elapsedTimeNanos = elapsedTimeNanos; this.reason = notNull("reason", reason); } @@ -82,11 +76,11 @@ public ConnectionCheckOutFailedEvent(final ServerId serverId, final long operati * * @param serverId the server id * @param reason the reason the connection check out failed - * @deprecated Prefer {@link ConnectionCheckOutFailedEvent#ConnectionCheckOutFailedEvent(ServerId, long, long, Reason)} + * @deprecated Prefer {@link #ConnectionCheckOutFailedEvent(ServerId, long, Reason)} */ @Deprecated public ConnectionCheckOutFailedEvent(final ServerId serverId, final Reason reason) { - this(serverId, -1, -1, reason); + this(serverId, -1, reason); } /** @@ -108,17 +102,6 @@ public long getOperationId() { return operationId; } - /** - * Gets the elapsed time between check out started and check out failed. - * - * @param timeUnit the time unit - * @return the elapsed time - * @since 4.10 - */ - public long getElapsedTime(final TimeUnit timeUnit) { - return timeUnit.convert(elapsedTimeNanos, TimeUnit.NANOSECONDS); - } - /** * Gets the reason for the check out failure. * @@ -135,7 +118,6 @@ public String toString() { + "server=" + serverId.getAddress() + ", clusterId=" + serverId.getClusterId() + ", operationId=" + operationId - + ", elapsedTimeNanos=" + elapsedTimeNanos + ", reason=" + reason + '}'; } diff --git a/driver-core/src/main/com/mongodb/event/ConnectionCheckedInEvent.java b/driver-core/src/main/com/mongodb/event/ConnectionCheckedInEvent.java index 7fcdd97bdb5..aa72f0a1c2b 100644 --- a/driver-core/src/main/com/mongodb/event/ConnectionCheckedInEvent.java +++ b/driver-core/src/main/com/mongodb/event/ConnectionCheckedInEvent.java @@ -18,8 +18,6 @@ import com.mongodb.connection.ConnectionId; -import java.util.concurrent.TimeUnit; - import static com.mongodb.assertions.Assertions.notNull; /** @@ -30,7 +28,6 @@ public final class ConnectionCheckedInEvent { private final ConnectionId connectionId; private final long operationId; - private final long elapsedTimeNanos; /** @@ -38,24 +35,22 @@ public final class ConnectionCheckedInEvent { * * @param connectionId the connectionId * @param operationId the operation id - * @param elapsedTimeNanos the elapsed time between check out and check in * @since 4.10 */ - public ConnectionCheckedInEvent(final ConnectionId connectionId, final long operationId, final long elapsedTimeNanos) { + public ConnectionCheckedInEvent(final ConnectionId connectionId, final long operationId) { this.connectionId = notNull("connectionId", connectionId); this.operationId = operationId; - this.elapsedTimeNanos = elapsedTimeNanos; } /** * Construct an instance * * @param connectionId the connectionId - * @deprecated Prefer {@link ConnectionCheckedInEvent#ConnectionCheckedInEvent(ConnectionId, long, long)} + * @deprecated Prefer {@link #ConnectionCheckedInEvent(ConnectionId, long)} */ @Deprecated public ConnectionCheckedInEvent(final ConnectionId connectionId) { - this(connectionId, -1, -1); + this(connectionId, -1); } /** @@ -77,17 +72,6 @@ public long getOperationId() { return operationId; } - /** - * Gets the elapsed time between check out and check in. - * - * @param timeUnit the time unit - * @return the elapsed time - * @since 4.10 - */ - public long getElapsedTime(final TimeUnit timeUnit) { - return timeUnit.convert(elapsedTimeNanos, TimeUnit.NANOSECONDS); - } - @Override public String toString() { return "ConnectionCheckedInEvent{" @@ -95,7 +79,6 @@ public String toString() { + ", server=" + connectionId.getServerId().getAddress() + ", clusterId=" + connectionId.getServerId().getClusterId() + ", operationId=" + operationId - + ", elapsedTimeNanos=" + elapsedTimeNanos + '}'; } } diff --git a/driver-core/src/main/com/mongodb/event/ConnectionCheckedOutEvent.java b/driver-core/src/main/com/mongodb/event/ConnectionCheckedOutEvent.java index b2ff6632cd7..a9ddbc59d35 100644 --- a/driver-core/src/main/com/mongodb/event/ConnectionCheckedOutEvent.java +++ b/driver-core/src/main/com/mongodb/event/ConnectionCheckedOutEvent.java @@ -18,8 +18,6 @@ import com.mongodb.connection.ConnectionId; -import java.util.concurrent.TimeUnit; - import static com.mongodb.assertions.Assertions.notNull; /** @@ -30,31 +28,28 @@ public final class ConnectionCheckedOutEvent { private final ConnectionId connectionId; private final long operationId; - private final long elapsedTimeNanos; /** * Construct an instance * * @param connectionId the connectionId * @param operationId the operation id - * @param elapsedTimeNanos the elapsed time between check out started and check out * @since 4.10 */ - public ConnectionCheckedOutEvent(final ConnectionId connectionId, final long operationId, final long elapsedTimeNanos) { + public ConnectionCheckedOutEvent(final ConnectionId connectionId, final long operationId) { this.connectionId = notNull("connectionId", connectionId); this.operationId = operationId; - this.elapsedTimeNanos = elapsedTimeNanos; } /** * Construct an instance * * @param connectionId the connectionId - * @deprecated Prefer {@link ConnectionCheckedOutEvent#ConnectionCheckedOutEvent(ConnectionId, long, long)} + * @deprecated Prefer {@link #ConnectionCheckedOutEvent(ConnectionId, long)} */ @Deprecated public ConnectionCheckedOutEvent(final ConnectionId connectionId) { - this(connectionId, -1, -1); + this(connectionId, -1); } /** @@ -76,17 +71,6 @@ public long getOperationId() { return operationId; } - /** - * Gets the elapsed time between check out started and check out. - * - * @param timeUnit the time unit - * @return the elapsed time - * @since 4.10 - */ - public long getElapsedTime(final TimeUnit timeUnit) { - return timeUnit.convert(elapsedTimeNanos, TimeUnit.NANOSECONDS); - } - @Override public String toString() { return "ConnectionCheckedOutEvent{" @@ -94,7 +78,6 @@ public String toString() { + ", server=" + connectionId.getServerId().getAddress() + ", clusterId=" + connectionId.getServerId().getClusterId() + ", operationId=" + operationId - + ", elapsedTimeNanos=" + elapsedTimeNanos + '}'; } } diff --git a/driver-core/src/main/com/mongodb/internal/Timeout.java b/driver-core/src/main/com/mongodb/internal/Timeout.java index 3c0cdfdfb3d..4ca99767541 100644 --- a/driver-core/src/main/com/mongodb/internal/Timeout.java +++ b/driver-core/src/main/com/mongodb/internal/Timeout.java @@ -94,9 +94,6 @@ public static Timeout immediate() { return IMMEDIATE; } - public long getStartNanos() { - return startNanos; - } /** * Must not be called on {@linkplain #isInfinite() infinite} or {@linkplain #isImmediate() immediate} timeouts. diff --git a/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java b/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java index 136d93fa0ed..1b67e90fd04 100644 --- a/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java +++ b/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java @@ -177,11 +177,10 @@ public InternalConnection get(final OperationContext operationContext, final lon connection = openConcurrencyLimiter.openOrGetAvailable(connection, timeout); } connection.checkedOutForOperation(operationContext); - connectionPoolListener.connectionCheckedOut(new ConnectionCheckedOutEvent(getId(connection), operationContext.getId(), - System.nanoTime() - timeout.getStartNanos())); + connectionPoolListener.connectionCheckedOut(new ConnectionCheckedOutEvent(getId(connection), operationContext.getId())); return connection; } catch (Exception e) { - throw (RuntimeException) checkOutFailed(e, operationContext, System.nanoTime() - timeout.getStartNanos()); + throw (RuntimeException) checkOutFailed(e, operationContext); } } @@ -196,11 +195,10 @@ public void getAsync(final OperationContext operationContext, final SingleResult SingleResultCallback errHandlingCallback = errorHandlingCallback(callback, LOGGER); if (failure == null) { connection.checkedOutForOperation(operationContext); - connectionPoolListener.connectionCheckedOut(new ConnectionCheckedOutEvent(getId(connection), operationContext.getId(), - System.nanoTime() - timeout.getStartNanos())); + connectionPoolListener.connectionCheckedOut(new ConnectionCheckedOutEvent(getId(connection), operationContext.getId())); errHandlingCallback.onResult(connection, null); } else { - errHandlingCallback.onResult(null, checkOutFailed(failure, operationContext, System.nanoTime() - timeout.getStartNanos())); + errHandlingCallback.onResult(null, checkOutFailed(failure, operationContext)); } }; try { @@ -242,7 +240,7 @@ public void getAsync(final OperationContext operationContext, final SingleResult * and returns {@code t} if it is not {@link MongoOpenConnectionInternalException}, * or returns {@code t.}{@linkplain MongoOpenConnectionInternalException#getCause() getCause()} otherwise. */ - private Throwable checkOutFailed(final Throwable t, final OperationContext operationContext, final long elapsedTimeNanos) { + private Throwable checkOutFailed(final Throwable t, final OperationContext operationContext) { Throwable result = t; Reason reason; if (t instanceof MongoTimeoutException) { @@ -257,8 +255,7 @@ private Throwable checkOutFailed(final Throwable t, final OperationContext opera } else { reason = Reason.UNKNOWN; } - connectionPoolListener.connectionCheckOutFailed(new ConnectionCheckOutFailedEvent(serverId, operationContext.getId(), - elapsedTimeNanos, reason)); + connectionPoolListener.connectionCheckOutFailed(new ConnectionCheckOutFailedEvent(serverId, operationContext.getId(), reason)); return result; } @@ -524,7 +521,6 @@ private class PooledConnection implements InternalConnection { private final AtomicBoolean isClosed = new AtomicBoolean(); private Connection.PinningMode pinningMode; private volatile long operationId; - private volatile long checkedOutTimeNanos; PooledConnection(final UsageTrackingInternalConnection wrapped) { this.wrapped = notNull("wrapped", wrapped); @@ -539,7 +535,6 @@ public int getGeneration() { * Associates this with the operation context and establishes the checked out start time */ public void checkedOutForOperation(final OperationContext operationContext) { - this.checkedOutTimeNanos = System.nanoTime(); this.operationId = operationContext.getId(); } @@ -549,7 +544,6 @@ public void open() { try { connectionCreated(connectionPoolListener, wrapped.getDescription().getConnectionId()); wrapped.open(); - checkedOutTimeNanos = System.nanoTime(); } catch (Exception e) { closeAndHandleOpenFailure(); throw new MongoOpenConnectionInternalException(e); @@ -562,7 +556,6 @@ public void openAsync(final SingleResultCallback callback) { assertFalse(isClosed.get()); connectionCreated(connectionPoolListener, wrapped.getDescription().getConnectionId()); wrapped.openAsync((nullResult, failure) -> { - checkedOutTimeNanos = System.nanoTime(); if (failure != null) { closeAndHandleOpenFailure(); callback.onResult(null, new MongoOpenConnectionInternalException(failure)); @@ -578,8 +571,7 @@ public void close() { // All but the first call is a no-op if (!isClosed.getAndSet(true)) { unmarkAsPinned(); - connectionPoolListener.connectionCheckedIn(new ConnectionCheckedInEvent(getId(wrapped), operationId, - System.nanoTime() - checkedOutTimeNanos)); + connectionPoolListener.connectionCheckedIn(new ConnectionCheckedInEvent(getId(wrapped), operationId)); if (LOGGER.isTraceEnabled()) { LOGGER.trace(format("Checked in connection [%s] to server %s", getId(wrapped), serverId.getAddress())); } @@ -751,7 +743,7 @@ public ServerDescription getInitialServerDescription() { /** * This internal exception is used to express an exceptional situation encountered when opening a connection. * It exists because it allows consolidating the code that sends events for exceptional situations in a - * {@linkplain #checkOutFailed(Throwable, OperationContext, long) single place}, it must not be observable by an external code. + * {@linkplain #checkOutFailed(Throwable, OperationContext) single place}, it must not be observable by an external code. */ private static final class MongoOpenConnectionInternalException extends RuntimeException { private static final long serialVersionUID = 1; From 781bb2c693b1a332714e11289839416948ca8530 Mon Sep 17 00:00:00 2001 From: Jeff Yemin Date: Tue, 25 Apr 2023 14:12:39 -0400 Subject: [PATCH 4/4] Code review updates --- driver-core/src/main/com/mongodb/internal/Timeout.java | 1 - .../mongodb/internal/connection/DefaultConnectionPool.java | 6 +++--- 2 files changed, 3 insertions(+), 4 deletions(-) diff --git a/driver-core/src/main/com/mongodb/internal/Timeout.java b/driver-core/src/main/com/mongodb/internal/Timeout.java index 4ca99767541..7c2a2245aae 100644 --- a/driver-core/src/main/com/mongodb/internal/Timeout.java +++ b/driver-core/src/main/com/mongodb/internal/Timeout.java @@ -94,7 +94,6 @@ public static Timeout immediate() { return IMMEDIATE; } - /** * Must not be called on {@linkplain #isInfinite() infinite} or {@linkplain #isImmediate() immediate} timeouts. *

diff --git a/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java b/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java index 1b67e90fd04..5264f2bd548 100644 --- a/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java +++ b/driver-core/src/main/com/mongodb/internal/connection/DefaultConnectionPool.java @@ -520,7 +520,7 @@ private class PooledConnection implements InternalConnection { private final UsageTrackingInternalConnection wrapped; private final AtomicBoolean isClosed = new AtomicBoolean(); private Connection.PinningMode pinningMode; - private volatile long operationId; + private OperationContext operationContext; PooledConnection(final UsageTrackingInternalConnection wrapped) { this.wrapped = notNull("wrapped", wrapped); @@ -535,7 +535,7 @@ public int getGeneration() { * Associates this with the operation context and establishes the checked out start time */ public void checkedOutForOperation(final OperationContext operationContext) { - this.operationId = operationContext.getId(); + this.operationContext = operationContext; } @Override @@ -571,7 +571,7 @@ public void close() { // All but the first call is a no-op if (!isClosed.getAndSet(true)) { unmarkAsPinned(); - connectionPoolListener.connectionCheckedIn(new ConnectionCheckedInEvent(getId(wrapped), operationId)); + connectionPoolListener.connectionCheckedIn(new ConnectionCheckedInEvent(getId(wrapped), operationContext.getId())); if (LOGGER.isTraceEnabled()) { LOGGER.trace(format("Checked in connection [%s] to server %s", getId(wrapped), serverId.getAddress())); }