Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly
Sign up
Appearance settings

Commit 745a803

Browse files
authored
Added operation (aka command name) to structured logging (#1758)
JAVA-5197 
1 parent b29b1e1 commit 745a803

File tree

53 files changed

+365
-158
lines changed

Some content is hidden

Large Commits have some content hidden by default. Use the searchbox below for content that may be hidden.

53 files changed

+365
-158
lines changed

‎driver-core/src/main/com/mongodb/internal/connection/BaseCluster.java‎

Lines changed: 23 additions & 43 deletions
Original file line numberDiff line numberDiff line change
@@ -145,7 +145,7 @@ public ServerTuple selectServer(final ServerSelector serverSelector, final Opera
145145
ServerDeprioritization serverDeprioritization = operationContext.getServerDeprioritization();
146146
boolean selectionWaitingLogged = false;
147147
Timeout computedServerSelectionTimeout = operationContext.getTimeoutContext().computeServerSelectionTimeout();
148-
logServerSelectionStarted(clusterId, operationContext.getId(), serverSelector, description);
148+
logServerSelectionStarted(operationContext, clusterId, serverSelector, description);
149149
while (true) {
150150
CountDownLatch currentPhaseLatch = phase.get();
151151
ClusterDescription currentDescription = description;
@@ -154,24 +154,19 @@ public ServerTuple selectServer(final ServerSelector serverSelector, final Opera
154154
computedServerSelectionTimeout, operationContext.getTimeoutContext());
155155

156156
if (!currentDescription.isCompatibleWithDriver()) {
157-
logAndThrowIncompatibleException(operationContext.getId(), serverSelector, currentDescription);
157+
logAndThrowIncompatibleException(operationContext, serverSelector, currentDescription);
158158
}
159159
if (serverTuple != null) {
160160
ServerAddress serverAddress = serverTuple.getServerDescription().getAddress();
161-
logServerSelectionSucceeded(
162-
clusterId,
163-
operationContext.getId(),
164-
serverAddress,
165-
serverSelector,
166-
currentDescription);
161+
logServerSelectionSucceeded(operationContext, clusterId, serverAddress, serverSelector, currentDescription);
167162
serverDeprioritization.updateCandidate(serverAddress);
168163
return serverTuple;
169164
}
170165
computedServerSelectionTimeout.onExpired(() ->
171166
logAndThrowTimeoutException(operationContext, serverSelector, currentDescription));
172167

173168
if (!selectionWaitingLogged) {
174-
logServerSelectionWaiting(clusterId, operationContext.getId(), computedServerSelectionTimeout, serverSelector, currentDescription);
169+
logServerSelectionWaiting(operationContext, clusterId, computedServerSelectionTimeout, serverSelector, currentDescription);
175170
selectionWaitingLogged = true;
176171
}
177172
connect();
@@ -197,11 +192,7 @@ public void selectServerAsync(final ServerSelector serverSelector, final Operati
197192
CountDownLatch currentPhase = phase.get();
198193
ClusterDescription currentDescription = description;
199194

200-
logServerSelectionStarted(
201-
clusterId,
202-
operationContext.getId(),
203-
serverSelector,
204-
currentDescription);
195+
logServerSelectionStarted(operationContext, clusterId, serverSelector, currentDescription);
205196

206197
if (!handleServerSelectionRequest(request, currentPhase, currentDescription)) {
207198
notifyWaitQueueHandler(request);
@@ -290,12 +281,11 @@ private boolean handleServerSelectionRequest(
290281

291282
try {
292283
OperationContext operationContext = request.getOperationContext();
293-
long operationId = operationContext.getId();
294284
if (currentPhase != request.phase) {
295285
CountDownLatch prevPhase = request.phase;
296286
request.phase = currentPhase;
297287
if (!description.isCompatibleWithDriver()) {
298-
logAndThrowIncompatibleException(operationId, request.originalSelector, description);
288+
logAndThrowIncompatibleException(operationContext, request.originalSelector, description);
299289
}
300290

301291

@@ -309,23 +299,13 @@ private boolean handleServerSelectionRequest(
309299

310300
if (serverTuple != null) {
311301
ServerAddress serverAddress = serverTuple.getServerDescription().getAddress();
312-
logServerSelectionSucceeded(
313-
clusterId,
314-
operationId,
315-
serverAddress,
316-
request.originalSelector,
317-
description);
302+
logServerSelectionSucceeded(operationContext, clusterId, serverAddress, request.originalSelector, description);
318303
serverDeprioritization.updateCandidate(serverAddress);
319304
request.onResult(serverTuple, null);
320305
return true;
321306
}
322307
if (prevPhase == null) {
323-
logServerSelectionWaiting(
324-
clusterId,
325-
operationId,
326-
request.getTimeout(),
327-
request.originalSelector,
328-
description);
308+
logServerSelectionWaiting(operationContext, clusterId, request.getTimeout(), request.originalSelector, description);
329309
}
330310
}
331311

@@ -410,11 +390,11 @@ protected ClusterableServer createServer(final ServerAddress serverAddress) {
410390
}
411391

412392
private void logAndThrowIncompatibleException(
413-
final longoperationId,
393+
final OperationContextoperationContext,
414394
final ServerSelector serverSelector,
415395
final ClusterDescription clusterDescription) {
416396
MongoIncompatibleDriverException exception = createIncompatibleException(clusterDescription);
417-
logServerSelectionFailed(clusterId, operationId, exception, serverSelector, clusterDescription);
397+
logServerSelectionFailed(operationContext, clusterId, exception, serverSelector, clusterDescription);
418398
throw exception;
419399
}
420400

@@ -448,7 +428,7 @@ private void logAndThrowTimeoutException(
448428
MongoTimeoutException exception = operationContext.getTimeoutContext().hasTimeoutMS()
449429
? new MongoOperationTimeoutException(message) : new MongoTimeoutException(message);
450430

451-
logServerSelectionFailed(clusterId, operationContext.getId(), exception, serverSelector, clusterDescription);
431+
logServerSelectionFailed(operationContext, clusterId, exception, serverSelector, clusterDescription);
452432
throw exception;
453433
}
454434

@@ -557,34 +537,34 @@ public void run() {
557537
}
558538

559539
static void logServerSelectionStarted(
540+
final OperationContext operationContext,
560541
final ClusterId clusterId,
561-
final long operationId,
562542
final ServerSelector serverSelector,
563543
final ClusterDescription clusterDescription) {
564544
if (STRUCTURED_LOGGER.isRequired(DEBUG, clusterId)) {
565545
STRUCTURED_LOGGER.log(new LogMessage(
566546
SERVER_SELECTION, DEBUG, "Server selection started", clusterId,
567547
asList(
568-
new Entry(OPERATION, null),
569-
new Entry(OPERATION_ID, operationId),
548+
new Entry(OPERATION, operationContext.getOperationName()),
549+
new Entry(OPERATION_ID, operationContext.getId()),
570550
new Entry(SELECTOR, serverSelector.toString()),
571551
new Entry(TOPOLOGY_DESCRIPTION, clusterDescription.getShortDescription())),
572552
"Server selection started for operation[ {}] with ID {}. Selector: {}, topology description: {}"));
573553
}
574554
}
575555

576556
private static void logServerSelectionWaiting(
557+
final OperationContext operationContext,
577558
final ClusterId clusterId,
578-
final long operationId,
579559
final Timeout timeout,
580560
final ServerSelector serverSelector,
581561
final ClusterDescription clusterDescription) {
582562
if (STRUCTURED_LOGGER.isRequired(INFO, clusterId)) {
583563
STRUCTURED_LOGGER.log(new LogMessage(
584564
SERVER_SELECTION, INFO, "Waiting for suitable server to become available", clusterId,
585565
asList(
586-
new Entry(OPERATION, null),
587-
new Entry(OPERATION_ID, operationId),
566+
new Entry(OPERATION, operationContext.getOperationName()),
567+
new Entry(OPERATION_ID, operationContext.getId()),
588568
timeout.call(MILLISECONDS,
589569
() -> new Entry(REMAINING_TIME_MS, "infinite"),
590570
(ms) -> new Entry(REMAINING_TIME_MS, ms),
@@ -597,8 +577,8 @@ private static void logServerSelectionWaiting(
597577
}
598578

599579
private static void logServerSelectionFailed(
580+
final OperationContext operationContext,
600581
final ClusterId clusterId,
601-
final long operationId,
602582
final MongoException failure,
603583
final ServerSelector serverSelector,
604584
final ClusterDescription clusterDescription) {
@@ -612,8 +592,8 @@ private static void logServerSelectionFailed(
612592
STRUCTURED_LOGGER.log(new LogMessage(
613593
SERVER_SELECTION, DEBUG, "Server selection failed", clusterId,
614594
asList(
615-
new Entry(OPERATION, null),
616-
new Entry(OPERATION_ID, operationId),
595+
new Entry(OPERATION, operationContext.getOperationName()),
596+
new Entry(OPERATION_ID, operationContext.getId()),
617597
new Entry(FAILURE, failureDescription),
618598
new Entry(SELECTOR, serverSelector.toString()),
619599
new Entry(TOPOLOGY_DESCRIPTION, clusterDescription.getShortDescription())),
@@ -622,17 +602,17 @@ private static void logServerSelectionFailed(
622602
}
623603

624604
static void logServerSelectionSucceeded(
605+
final OperationContext operationContext,
625606
final ClusterId clusterId,
626-
final long operationId,
627607
final ServerAddress serverAddress,
628608
final ServerSelector serverSelector,
629609
final ClusterDescription clusterDescription) {
630610
if (STRUCTURED_LOGGER.isRequired(DEBUG, clusterId)) {
631611
STRUCTURED_LOGGER.log(new LogMessage(
632612
SERVER_SELECTION, DEBUG, "Server selection succeeded", clusterId,
633613
asList(
634-
new Entry(OPERATION, null),
635-
new Entry(OPERATION_ID, operationId),
614+
new Entry(OPERATION, operationContext.getOperationName()),
615+
new Entry(OPERATION_ID, operationContext.getId()),
636616
new Entry(SERVER_HOST, serverAddress.getHost()),
637617
new Entry(SERVER_PORT, serverAddress instanceof UnixServerAddress ? null : serverAddress.getPort()),
638618
new Entry(SELECTOR, serverSelector.toString()),

‎driver-core/src/main/com/mongodb/internal/connection/LoadBalancedCluster.java‎

Lines changed: 7 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -222,9 +222,9 @@ public ServerTuple selectServer(final ServerSelector serverSelector, final Opera
222222
throw createResolvedToMultipleHostsException();
223223
}
224224
ClusterDescription curDescription = description;
225-
logServerSelectionStarted(clusterId, operationContext.getId(), serverSelector, curDescription);
225+
logServerSelectionStarted(operationContext, clusterId, serverSelector, curDescription);
226226
ServerTuple serverTuple = new ServerTuple(assertNotNull(server), curDescription.getServerDescriptions().get(0));
227-
logServerSelectionSucceeded(clusterId, operationContext.getId(), serverTuple.getServerDescription().getAddress(),
227+
logServerSelectionSucceeded(operationContext, clusterId, serverTuple.getServerDescription().getAddress(),
228228
serverSelector, curDescription);
229229
return serverTuple;
230230
}
@@ -254,8 +254,8 @@ public void selectServerAsync(final ServerSelector serverSelector, final Operati
254254
return;
255255
}
256256
Timeout computedServerSelectionTimeout = operationContext.getTimeoutContext().computeServerSelectionTimeout();
257-
ServerSelectionRequest serverSelectionRequest = new ServerSelectionRequest(operationContext.getId(), serverSelector,
258-
operationContext, computedServerSelectionTimeout, callback);
257+
ServerSelectionRequest serverSelectionRequest = new ServerSelectionRequest(serverSelector, operationContext,
258+
computedServerSelectionTimeout, callback);
259259
if (initializationCompleted) {
260260
handleServerSelectionRequest(serverSelectionRequest);
261261
} else {
@@ -309,9 +309,9 @@ private void handleServerSelectionRequest(final ServerSelectionRequest serverSel
309309
} else {
310310
ClusterDescription curDescription = description;
311311
logServerSelectionStarted(
312-
clusterId, serverSelectionRequest.operationId, serverSelectionRequest.serverSelector, curDescription);
312+
serverSelectionRequest.operationContext, clusterId, serverSelectionRequest.serverSelector, curDescription);
313313
ServerTuple serverTuple = new ServerTuple(assertNotNull(server), curDescription.getServerDescriptions().get(0));
314-
logServerSelectionSucceeded(clusterId, serverSelectionRequest.operationId,
314+
logServerSelectionSucceeded(serverSelectionRequest.operationContext, clusterId,
315315
serverTuple.getServerDescription().getAddress(), serverSelectionRequest.serverSelector, curDescription);
316316
serverSelectionRequest.onSuccess(serverTuple);
317317
}
@@ -416,15 +416,13 @@ public void run() {
416416
}
417417

418418
private static final class ServerSelectionRequest {
419-
private final long operationId;
420419
private final ServerSelector serverSelector;
421420
private final SingleResultCallback<ServerTuple> callback;
422421
private final Timeout timeout;
423422
private final OperationContext operationContext;
424423

425-
private ServerSelectionRequest(final longoperationId, finalServerSelector serverSelector, final OperationContext operationContext,
424+
private ServerSelectionRequest(final ServerSelector serverSelector, final OperationContext operationContext,
426425
final Timeout timeout, final SingleResultCallback<ServerTuple> callback) {
427-
this.operationId = operationId;
428426
this.serverSelector = serverSelector;
429427
this.timeout = timeout;
430428
this.operationContext = operationContext;

‎driver-core/src/main/com/mongodb/internal/connection/OperationContext.java‎

Lines changed: 28 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -49,10 +49,17 @@ public class OperationContext {
4949
private final TimeoutContext timeoutContext;
5050
@Nullable
5151
private final ServerApi serverApi;
52+
@Nullable
53+
private final String operationName;
5254

5355
public OperationContext(final RequestContext requestContext, final SessionContext sessionContext, final TimeoutContext timeoutContext,
5456
@Nullable final ServerApi serverApi) {
55-
this(NEXT_ID.incrementAndGet(), requestContext, sessionContext, timeoutContext, new ServerDeprioritization(), serverApi);
57+
this(requestContext, sessionContext, timeoutContext, serverApi, null);
58+
}
59+
60+
public OperationContext(final RequestContext requestContext, final SessionContext sessionContext, final TimeoutContext timeoutContext,
61+
@Nullable final ServerApi serverApi, @Nullable final String operationName) {
62+
this(NEXT_ID.incrementAndGet(), requestContext, sessionContext, timeoutContext, new ServerDeprioritization(), serverApi, operationName);
5663
}
5764

5865
public static OperationContext simpleOperationContext(
@@ -61,23 +68,29 @@ public static OperationContext simpleOperationContext(
6168
IgnorableRequestContext.INSTANCE,
6269
NoOpSessionContext.INSTANCE,
6370
new TimeoutContext(timeoutSettings),
64-
serverApi);
71+
serverApi,
72+
null);
6573
}
6674

6775
public static OperationContext simpleOperationContext(final TimeoutContext timeoutContext) {
6876
return new OperationContext(
6977
IgnorableRequestContext.INSTANCE,
7078
NoOpSessionContext.INSTANCE,
7179
timeoutContext,
80+
null,
7281
null);
7382
}
7483

7584
public OperationContext withSessionContext(final SessionContext sessionContext) {
76-
return new OperationContext(id, requestContext, sessionContext, timeoutContext, serverDeprioritization, serverApi);
85+
return new OperationContext(id, requestContext, sessionContext, timeoutContext, serverDeprioritization, serverApi, operationName);
7786
}
7887

7988
public OperationContext withTimeoutContext(final TimeoutContext timeoutContext) {
80-
return new OperationContext(id, requestContext, sessionContext, timeoutContext, serverDeprioritization, serverApi);
89+
return new OperationContext(id, requestContext, sessionContext, timeoutContext, serverDeprioritization, serverApi, operationName);
90+
}
91+
92+
public OperationContext withOperationName(final String operationName) {
93+
return new OperationContext(id, requestContext, sessionContext, timeoutContext, serverDeprioritization, serverApi, operationName);
8194
}
8295

8396
public long getId() {
@@ -101,33 +114,42 @@ public ServerApi getServerApi() {
101114
return serverApi;
102115
}
103116

117+
@Nullable
118+
public String getOperationName() {
119+
return operationName;
120+
}
121+
104122
@VisibleForTesting(otherwise = VisibleForTesting.AccessModifier.PRIVATE)
105123
public OperationContext(final long id,
106124
final RequestContext requestContext,
107125
final SessionContext sessionContext,
108126
final TimeoutContext timeoutContext,
109127
final ServerDeprioritization serverDeprioritization,
110-
@Nullable final ServerApi serverApi) {
128+
@Nullable final ServerApi serverApi,
129+
@Nullable final String operationName) {
111130
this.id = id;
112131
this.serverDeprioritization = serverDeprioritization;
113132
this.requestContext = requestContext;
114133
this.sessionContext = sessionContext;
115134
this.timeoutContext = timeoutContext;
116135
this.serverApi = serverApi;
136+
this.operationName = operationName;
117137
}
118138

119139
@VisibleForTesting(otherwise = VisibleForTesting.AccessModifier.PRIVATE)
120140
public OperationContext(final long id,
121141
final RequestContext requestContext,
122142
final SessionContext sessionContext,
123143
final TimeoutContext timeoutContext,
124-
@Nullable final ServerApi serverApi) {
144+
@Nullable final ServerApi serverApi,
145+
@Nullable final String operationName) {
125146
this.id = id;
126147
this.serverDeprioritization = new ServerDeprioritization();
127148
this.requestContext = requestContext;
128149
this.sessionContext = sessionContext;
129150
this.timeoutContext = timeoutContext;
130151
this.serverApi = serverApi;
152+
this.operationName = operationName;
131153
}
132154

133155

‎driver-core/src/main/com/mongodb/internal/logging/LogMessage.java‎

Lines changed: 0 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -104,9 +104,6 @@ public enum Name {
104104
COMMAND_NAME("commandName"),
105105
REQUEST_ID("requestId"),
106106
OPERATION_ID("operationId"),
107-
/**
108-
* Not supported.
109-
*/
110107
OPERATION("operation"),
111108
AWAITED("awaited"),
112109
SERVICE_ID("serviceId"),

‎driver-core/src/main/com/mongodb/internal/operation/AbortTransactionOperation.java‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -31,6 +31,7 @@
3131
* <p>This class is not part of the public API and may be removed or changed at any time</p>
3232
*/
3333
public class AbortTransactionOperation extends TransactionOperation {
34+
private static final String COMMAND_NAME = "abortTransaction";
3435
private BsonDocument recoveryToken;
3536

3637
public AbortTransactionOperation(final WriteConcern writeConcern) {
@@ -43,8 +44,8 @@ public AbortTransactionOperation recoveryToken(@Nullable final BsonDocument reco
4344
}
4445

4546
@Override
46-
protected String getCommandName() {
47-
return "abortTransaction";
47+
public String getCommandName() {
48+
return COMMAND_NAME;
4849
}
4950

5051
@Override

0 commit comments

Comments
(0)

AltStyle によって変換されたページ (->オリジナル) /