Skip to content

Commit 158b69c

Browse files
authored
Refactor to use Timeout for server selection (#1202)
JAVA-5175
1 parent 432bcb0 commit 158b69c

File tree

6 files changed

+199
-153
lines changed

6 files changed

+199
-153
lines changed

driver-core/src/main/com/mongodb/internal/binding/SingleServerBinding.java

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -149,8 +149,10 @@ public ReadPreference getReadPreference() {
149149

150150
@Override
151151
public Connection getConnection() {
152-
return cluster.selectServer(new ServerAddressSelector(serverAddress), operationContext)
153-
.getServer().getConnection(operationContext);
152+
return cluster
153+
.selectServer(new ServerAddressSelector(serverAddress), operationContext)
154+
.getServer()
155+
.getConnection(operationContext);
154156
}
155157

156158
@Override

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

Lines changed: 100 additions & 111 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@
1818

1919
import com.mongodb.MongoClientException;
2020
import com.mongodb.MongoIncompatibleDriverException;
21+
import com.mongodb.MongoInterruptedException;
2122
import com.mongodb.MongoTimeoutException;
2223
import com.mongodb.ServerAddress;
2324
import com.mongodb.connection.ClusterDescription;
@@ -35,6 +36,8 @@
3536
import com.mongodb.internal.diagnostics.logging.Logger;
3637
import com.mongodb.internal.diagnostics.logging.Loggers;
3738
import com.mongodb.internal.selector.LatencyMinimizingServerSelector;
39+
import com.mongodb.internal.time.StartTime;
40+
import com.mongodb.internal.time.Timeout;
3841
import com.mongodb.lang.Nullable;
3942
import com.mongodb.selector.CompositeServerSelector;
4043
import com.mongodb.selector.ServerSelector;
@@ -59,7 +62,6 @@
5962
import static com.mongodb.internal.VisibleForTesting.AccessModifier.PRIVATE;
6063
import static com.mongodb.internal.connection.EventHelper.wouldDescriptionsGenerateEquivalentEvents;
6164
import static com.mongodb.internal.event.EventListenerHelper.singleClusterListener;
62-
import static com.mongodb.internal.thread.InterruptionUtil.interruptAndCreateMongoInterruptedException;
6365
import static java.lang.String.format;
6466
import static java.util.Arrays.asList;
6567
import static java.util.Comparator.comparingInt;
@@ -102,47 +104,31 @@ public ClusterClock getClock() {
102104
public ServerTuple selectServer(final ServerSelector serverSelector, final OperationContext operationContext) {
103105
isTrue("open", !isClosed());
104106

105-
try {
106-
CountDownLatch currentPhase = phase.get();
107-
ClusterDescription curDescription = description;
108-
ServerSelector compositeServerSelector = getCompositeServerSelector(serverSelector);
109-
ServerTuple serverTuple = selectServer(compositeServerSelector, curDescription);
110-
111-
boolean selectionFailureLogged = false;
112-
113-
long startTimeNanos = System.nanoTime();
114-
long curTimeNanos = startTimeNanos;
115-
long maxWaitTimeNanos = getMaxWaitTimeNanos();
116-
117-
while (true) {
118-
throwIfIncompatible(curDescription);
107+
ServerSelector compositeServerSelector = getCompositeServerSelector(serverSelector);
108+
boolean selectionFailureLogged = false;
109+
StartTime startTime = StartTime.now();
110+
Timeout timeout = startServerSelectionTimeout(startTime);
119111

120-
if (serverTuple != null) {
121-
return serverTuple;
122-
}
123-
124-
if (curTimeNanos - startTimeNanos > maxWaitTimeNanos) {
125-
throw createTimeoutException(serverSelector, curDescription);
126-
}
112+
while (true) {
113+
CountDownLatch currentPhaseLatch = phase.get();
114+
ClusterDescription currentDescription = description;
115+
ServerTuple serverTuple = selectServer(compositeServerSelector, currentDescription);
127116

128-
if (!selectionFailureLogged) {
129-
logServerSelectionFailure(serverSelector, curDescription);
130-
selectionFailureLogged = true;
131-
}
132-
133-
connect();
134-
135-
currentPhase.await(Math.min(maxWaitTimeNanos - (curTimeNanos - startTimeNanos), getMinWaitTimeNanos()), NANOSECONDS);
136-
137-
curTimeNanos = System.nanoTime();
138-
139-
currentPhase = phase.get();
140-
curDescription = description;
141-
serverTuple = selectServer(compositeServerSelector, curDescription);
117+
throwIfIncompatible(currentDescription);
118+
if (serverTuple != null) {
119+
return serverTuple;
142120
}
143-
144-
} catch (InterruptedException e) {
145-
throw interruptAndCreateMongoInterruptedException(format("Interrupted while waiting for a server that matches %s", serverSelector), e);
121+
if (timeout.hasExpired()) {
122+
throw createTimeoutException(serverSelector, currentDescription, startTime);
123+
}
124+
if (!selectionFailureLogged) {
125+
logServerSelectionFailure(serverSelector, currentDescription, timeout);
126+
selectionFailureLogged = true;
127+
}
128+
connect();
129+
Timeout heartbeatLimitedTimeout = timeout.orEarlier(startMinWaitHeartbeatTimeout());
130+
heartbeatLimitedTimeout.awaitOn(currentPhaseLatch,
131+
() -> format("waiting for a server that matches %s", serverSelector));
146132
}
147133
}
148134

@@ -154,8 +140,10 @@ public void selectServerAsync(final ServerSelector serverSelector, final Operati
154140
if (LOGGER.isTraceEnabled()) {
155141
LOGGER.trace(format("Asynchronously selecting server with selector %s", serverSelector));
156142
}
157-
ServerSelectionRequest request = new ServerSelectionRequest(serverSelector, getCompositeServerSelector(serverSelector),
158-
getMaxWaitTimeNanos(), callback);
143+
StartTime startTime = StartTime.now();
144+
Timeout timeout = startServerSelectionTimeout(startTime);
145+
ServerSelectionRequest request = new ServerSelectionRequest(
146+
serverSelector, getCompositeServerSelector(serverSelector), timeout, startTime, callback);
159147

160148
CountDownLatch currentPhase = phase.get();
161149
ClusterDescription currentDescription = description;
@@ -169,49 +157,41 @@ public void selectServerAsync(final ServerSelector serverSelector, final Operati
169157
public ClusterDescription getDescription() {
170158
isTrue("open", !isClosed());
171159

172-
try {
173-
CountDownLatch currentPhase = phase.get();
174-
ClusterDescription curDescription = description;
175-
176-
boolean selectionFailureLogged = false;
160+
boolean selectionFailureLogged = false;
177161

178-
long startTimeNanos = System.nanoTime();
179-
long curTimeNanos = startTimeNanos;
180-
long maxWaitTimeNanos = getMaxWaitTimeNanos();
162+
StartTime startTime = StartTime.now();
163+
Timeout timeout = startServerSelectionTimeout(startTime);
164+
while (true) {
165+
CountDownLatch currentPhaseLatch = phase.get();
166+
ClusterDescription currentDescription = description;
181167

182-
while (curDescription.getType() == ClusterType.UNKNOWN) {
168+
if (currentDescription.getType() != ClusterType.UNKNOWN) {
169+
return currentDescription;
170+
}
183171

184-
if (curTimeNanos - startTimeNanos > maxWaitTimeNanos) {
185-
throw new MongoTimeoutException(format("Timed out after %d ms while waiting to connect. Client view of cluster state "
186-
+ "is %s",
187-
settings.getServerSelectionTimeout(MILLISECONDS),
188-
curDescription.getShortDescription()));
189-
}
172+
if (timeout.hasExpired()) {
173+
throw new MongoTimeoutException(format(
174+
"Timed out after %d ms while waiting to connect. Client view of cluster state is %s",
175+
startTime.elapsed().toMillis(),
176+
currentDescription.getShortDescription()));
177+
}
190178

191-
if (!selectionFailureLogged) {
192-
if (LOGGER.isInfoEnabled()) {
193-
if (settings.getServerSelectionTimeout(MILLISECONDS) < 0) {
194-
LOGGER.info("Cluster description not yet available. Waiting indefinitely.");
195-
} else {
196-
LOGGER.info(format("Cluster description not yet available. Waiting for %d ms before timing out",
197-
settings.getServerSelectionTimeout(MILLISECONDS)));
198-
}
179+
if (!selectionFailureLogged) {
180+
if (LOGGER.isInfoEnabled()) {
181+
if (timeout.isInfinite()) {
182+
LOGGER.info("Cluster description not yet available. Waiting indefinitely.");
183+
} else {
184+
LOGGER.info(format("Cluster description not yet available. Waiting for %d ms before timing out",
185+
timeout.remaining(MILLISECONDS)));
199186
}
200-
selectionFailureLogged = true;
201187
}
188+
selectionFailureLogged = true;
189+
}
202190

203-
connect();
204-
205-
currentPhase.await(Math.min(maxWaitTimeNanos - (curTimeNanos - startTimeNanos), getMinWaitTimeNanos()), NANOSECONDS);
206-
207-
curTimeNanos = System.nanoTime();
191+
connect();
208192

209-
currentPhase = phase.get();
210-
curDescription = description;
211-
}
212-
return curDescription;
213-
} catch (InterruptedException e) {
214-
throw interruptAndCreateMongoInterruptedException("Interrupted while waiting to connect", e);
193+
Timeout heartbeatLimitedTimeout = timeout.orEarlier(startMinWaitHeartbeatTimeout());
194+
heartbeatLimitedTimeout.awaitOn(currentPhaseLatch, () -> "waiting to connect");
215195
}
216196
}
217197

@@ -280,19 +260,20 @@ private void updatePhase() {
280260
withLock(() -> phase.getAndSet(new CountDownLatch(1)).countDown());
281261
}
282262

283-
private long getMaxWaitTimeNanos() {
284-
if (settings.getServerSelectionTimeout(NANOSECONDS) < 0) {
285-
return Long.MAX_VALUE;
286-
}
287-
return settings.getServerSelectionTimeout(NANOSECONDS);
263+
private Timeout startServerSelectionTimeout(final StartTime startTime) {
264+
long ms = settings.getServerSelectionTimeout(MILLISECONDS);
265+
return startTime.timeoutAfterOrInfiniteIfNegative(ms, MILLISECONDS);
288266
}
289267

290-
private long getMinWaitTimeNanos() {
291-
return serverFactory.getSettings().getMinHeartbeatFrequency(NANOSECONDS);
268+
private Timeout startMinWaitHeartbeatTimeout() {
269+
long minHeartbeatFrequency = serverFactory.getSettings().getMinHeartbeatFrequency(NANOSECONDS);
270+
minHeartbeatFrequency = Math.max(0, minHeartbeatFrequency);
271+
return Timeout.expiresIn(minHeartbeatFrequency, NANOSECONDS);
292272
}
293273

294-
private boolean handleServerSelectionRequest(final ServerSelectionRequest request, final CountDownLatch currentPhase,
295-
final ClusterDescription description) {
274+
private boolean handleServerSelectionRequest(
275+
final ServerSelectionRequest request, final CountDownLatch currentPhase,
276+
final ClusterDescription description) {
296277
try {
297278
if (currentPhase != request.phase) {
298279
CountDownLatch prevPhase = request.phase;
@@ -308,21 +289,23 @@ private boolean handleServerSelectionRequest(final ServerSelectionRequest reques
308289
ServerTuple serverTuple = selectServer(request.compositeSelector, description);
309290
if (serverTuple != null) {
310291
if (LOGGER.isTraceEnabled()) {
311-
LOGGER.trace(format("Asynchronously selected server %s", serverTuple.getServerDescription().getAddress()));
292+
LOGGER.trace(format("Asynchronously selected server %s",
293+
serverTuple.getServerDescription().getAddress()));
312294
}
313295
request.onResult(serverTuple, null);
314296
return true;
315297
}
316298
if (prevPhase == null) {
317-
logServerSelectionFailure(request.originalSelector, description);
299+
logServerSelectionFailure(request.originalSelector, description, request.getTimeout());
318300
}
319301
}
320302

321-
if (request.timedOut()) {
303+
if (request.getTimeout().hasExpired()) {
322304
if (LOGGER.isTraceEnabled()) {
323305
LOGGER.trace("Asynchronously failed server selection after timeout");
324306
}
325-
request.onResult(null, createTimeoutException(request.originalSelector, description));
307+
request.onResult(null, createTimeoutException(
308+
request.originalSelector, description, request.getStartTime()));
326309
return true;
327310
}
328311

@@ -333,14 +316,15 @@ private boolean handleServerSelectionRequest(final ServerSelectionRequest reques
333316
}
334317
}
335318

336-
private void logServerSelectionFailure(final ServerSelector serverSelector, final ClusterDescription curDescription) {
319+
private void logServerSelectionFailure(final ServerSelector serverSelector,
320+
final ClusterDescription curDescription, final Timeout timeout) {
337321
if (LOGGER.isInfoEnabled()) {
338-
if (settings.getServerSelectionTimeout(MILLISECONDS) < 0) {
322+
if (timeout.isInfinite()) {
339323
LOGGER.info(format("No server chosen by %s from cluster description %s. Waiting indefinitely.",
340324
serverSelector, curDescription));
341325
} else {
342326
LOGGER.info(format("No server chosen by %s from cluster description %s. Waiting for %d ms before timing out",
343-
serverSelector, curDescription, settings.getServerSelectionTimeout(MILLISECONDS)));
327+
serverSelector, curDescription, timeout.remaining(MILLISECONDS)));
344328
}
345329
}
346330
}
@@ -426,27 +410,29 @@ private MongoIncompatibleDriverException createIncompatibleException(final Clust
426410
return new MongoIncompatibleDriverException(message, curDescription);
427411
}
428412

429-
private MongoTimeoutException createTimeoutException(final ServerSelector serverSelector, final ClusterDescription curDescription) {
430-
return new MongoTimeoutException(format("Timed out after %d ms while waiting for a server that matches %s. "
431-
+ "Client view of cluster state is %s",
432-
settings.getServerSelectionTimeout(MILLISECONDS), serverSelector,
433-
curDescription.getShortDescription()));
413+
private MongoTimeoutException createTimeoutException(final ServerSelector serverSelector,
414+
final ClusterDescription curDescription, final StartTime startTime) {
415+
return new MongoTimeoutException(format(
416+
"Timed out after %d ms while waiting for a server that matches %s. Client view of cluster state is %s",
417+
startTime.elapsed().toMillis(),
418+
serverSelector,
419+
curDescription.getShortDescription()));
434420
}
435421

436422
private static final class ServerSelectionRequest {
437423
private final ServerSelector originalSelector;
438424
private final ServerSelector compositeSelector;
439-
private final long maxWaitTimeNanos;
440425
private final SingleResultCallback<ServerTuple> callback;
441-
private final long startTimeNanos = System.nanoTime();
426+
private final Timeout timeout;
427+
private final StartTime startTime;
442428
private CountDownLatch phase;
443429

444430
ServerSelectionRequest(final ServerSelector serverSelector, final ServerSelector compositeSelector,
445-
final long maxWaitTimeNanos,
446-
final SingleResultCallback<ServerTuple> callback) {
431+
final Timeout timeout, final StartTime startTime, final SingleResultCallback<ServerTuple> callback) {
447432
this.originalSelector = serverSelector;
448433
this.compositeSelector = compositeSelector;
449-
this.maxWaitTimeNanos = maxWaitTimeNanos;
434+
this.timeout = timeout;
435+
this.startTime = startTime;
450436
this.callback = callback;
451437
}
452438

@@ -458,12 +444,12 @@ void onResult(@Nullable final ServerTuple serverTuple, @Nullable final Throwable
458444
}
459445
}
460446

461-
boolean timedOut() {
462-
return System.nanoTime() - startTimeNanos > maxWaitTimeNanos;
447+
Timeout getTimeout() {
448+
return timeout;
463449
}
464450

465-
long getRemainingTime() {
466-
return startTimeNanos + maxWaitTimeNanos - System.nanoTime();
451+
StartTime getStartTime() {
452+
return startTime;
467453
}
468454
}
469455

@@ -498,25 +484,28 @@ public void run() {
498484
while (!isClosed) {
499485
CountDownLatch currentPhase = phase.get();
500486
ClusterDescription curDescription = description;
501-
long waitTimeNanos = Long.MAX_VALUE;
487+
488+
Timeout timeout = Timeout.infinite();
502489

503490
for (Iterator<ServerSelectionRequest> iter = waitQueue.iterator(); iter.hasNext();) {
504491
ServerSelectionRequest nextRequest = iter.next();
505492
if (handleServerSelectionRequest(nextRequest, currentPhase, curDescription)) {
506493
iter.remove();
507494
} else {
508-
waitTimeNanos = Math.min(nextRequest.getRemainingTime(), Math.min(getMinWaitTimeNanos(), waitTimeNanos));
495+
timeout = timeout
496+
.orEarlier(nextRequest.getTimeout())
497+
.orEarlier(startMinWaitHeartbeatTimeout());
509498
}
510499
}
511500

512501
// if there are any waiters that were not satisfied, connect
513-
if (waitTimeNanos < Long.MAX_VALUE) {
502+
if (!timeout.isInfinite()) {
514503
connect();
515504
}
516505

517506
try {
518-
currentPhase.await(waitTimeNanos, NANOSECONDS);
519-
} catch (InterruptedException closed) {
507+
timeout.awaitOn(currentPhase, () -> "ignored");
508+
} catch (MongoInterruptedException closed) {
520509
// The cluster has been closed and the while loop will exit.
521510
}
522511
}

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

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1092,7 +1092,8 @@ private PooledConnection acquirePermitOrGetAvailableOpenedConnection(final boole
10921092
if (timeout.hasExpired()) {
10931093
throw createTimeoutException(startTime);
10941094
}
1095-
timeout.awaitOn(permitAvailableOrHandedOverOrClosedOrPausedCondition);
1095+
timeout.awaitOn(permitAvailableOrHandedOverOrClosedOrPausedCondition,
1096+
() -> "acquiring permit or getting available opened connection");
10961097
}
10971098
if (availableConnection == null) {
10981099
assertTrue(permits > 0);

0 commit comments

Comments
 (0)