Skip to content

Commit 305f47d

Browse files
authored
fix(spanner): honor maxAttempts and totalTimeout in streaming resume loop (#14370)
The resume loop in ResumableStreamIterator restarted a broken stream indefinitely for any retryable error, ignoring the maxAttempts and totalTimeout configured in the retry settings for ExecuteStreamingSql. A streaming query could therefore retry forever when the server kept returning a retryable error, for example when a user configured DEADLINE_EXCEEDED as a retryable code and every attempt timed out. The loop now counts consecutive failed attempts and stops retrying, rethrowing the last exception, when the configured maxAttempts is reached. It also enforces the configured totalTimeout as a wall-clock budget for a sequence of consecutive failed attempts, measured from the first failure of the sequence: a retry is only allowed when the retry delay still fits in the remaining budget. This applies both to delays from the exponential backoff and to server-supplied retry delays (RetryInfo), which previously bypassed the backoff completely. A totalTimeout of zero means that no time budget has been set, in which case only maxAttempts limits the retries, mirroring GAX. Both limits only bind for custom retry settings: the default streaming retry settings do not set maxAttempts and keep the existing unbounded resume behavior. Progress on the stream resets both budgets, where progress means receiving a resume token that differs from the last seen token, so long-running streams that regularly make progress are not terminated by an occasional transient error, while a stream that keeps returning the same token cannot reset the budget indefinitely.
1 parent 62cd972 commit 305f47d

7 files changed

Lines changed: 1056 additions & 90 deletions

File tree

java-spanner/google-cloud-spanner/src/main/java/com/google/cloud/spanner/ResumableStreamIterator.java

Lines changed: 136 additions & 43 deletions
Original file line numberDiff line numberDiff line change
@@ -28,7 +28,6 @@
2828
import com.google.api.gax.retrying.RetrySettings;
2929
import com.google.api.gax.rpc.StatusCode.Code;
3030
import com.google.cloud.spanner.AbstractResultSet.CloseableIterator;
31-
import com.google.cloud.spanner.v1.stub.SpannerStubSettings;
3231
import com.google.common.annotations.VisibleForTesting;
3332
import com.google.common.base.Preconditions;
3433
import com.google.common.collect.AbstractIterator;
@@ -38,7 +37,6 @@
3837
import io.opentelemetry.api.common.Attributes;
3938
import java.io.IOException;
4039
import java.util.LinkedList;
41-
import java.util.Objects;
4240
import java.util.Set;
4341
import java.util.concurrent.CountDownLatch;
4442
import java.util.concurrent.Executor;
@@ -52,12 +50,28 @@
5250
* track of the most recent resume token seen, and will buffer partial result set chunks that do not
5351
* have a resume token until one is seen or buffer space is exceeded, which reduces the chance of
5452
* yielding data to the caller that cannot be resumed.
53+
*
54+
* <p>The resume loop is bounded by the streaming retry settings: consecutive failed attempts are
55+
* limited by {@link RetrySettings#getMaxAttempts()} if that has been set to a value greater than
56+
* zero, and the total time spent on a sequence of consecutive failed attempts is limited by {@link
57+
* RetrySettings#getTotalTimeout()} if that has been set to a positive value. Only consecutive
58+
* failures count against these budgets: any progress on the stream (that is, receiving a resume
59+
* token that differs from the last seen resume token) resets both, so a long-running stream that
60+
* regularly makes progress is not terminated by an occasional transient error. The default settings
61+
* have no maximum number of attempts or total timeout. Setting maxAttempts to 1 disables streaming
62+
* retries.
63+
*
64+
* <p>These limits bound the number of streams that this iterator starts. Each (re)started stream is
65+
* a call through the underlying GAX callable, and GAX applies the same {@link RetrySettings} to
66+
* attempts of that call that fail before any response has been received. A stream that repeatedly
67+
* fails before its first response can therefore consist of up to maxAttempts RPC attempts itself,
68+
* so a configured maxAttempts of N bounds the total number of RPC attempts without progress by N*N,
69+
* not by N. The total timeout is measured in wall-clock time from the first failure of the sequence
70+
* and therefore spans both layers.
5571
*/
5672
@VisibleForTesting
5773
abstract class ResumableStreamIterator extends AbstractIterator<PartialResultSet>
5874
implements CloseableIterator<PartialResultSet> {
59-
private static final RetrySettings DEFAULT_STREAMING_RETRY_SETTINGS =
60-
SpannerStubSettings.newBuilder().executeStreamingSqlSettings().getRetrySettings();
6175
private final ErrorHandler errorHandler;
6276
private AsyncResultSet.StreamMessageListener streamMessageListener;
6377
private final RetrySettings streamingRetrySettings;
@@ -69,7 +83,20 @@ abstract class ResumableStreamIterator extends AbstractIterator<PartialResultSet
6983
private final ISpan span;
7084
private final TraceWrapper tracer;
7185
private CloseableIterator<PartialResultSet> stream;
86+
87+
/**
88+
* The number of consecutive failed attempts without any progress on the stream. Reset to zero
89+
* every time the stream returns a new resume token.
90+
*/
7291
private int attempts;
92+
93+
/**
94+
* The value of {@link System#nanoTime()} at the first failure of the current sequence of
95+
* consecutive failed attempts. Only meaningful when {@link #attempts} is nonzero. Used to enforce
96+
* {@link RetrySettings#getTotalTimeout()} when a positive timeout is configured.
97+
*/
98+
private long retrySequenceStartNanos = -1L;
99+
73100
private ByteString resumeToken;
74101
private boolean finished;
75102
private final XGoogSpannerRequestId requestId;
@@ -123,17 +150,42 @@ protected ResumableStreamIterator(
123150
this.requestId = xGoogRequestIdCreator.nextRequestId(0);
124151
}
125152

126-
private ExponentialBackOff newBackOff() {
127-
if (Objects.equals(streamingRetrySettings, DEFAULT_STREAMING_RETRY_SETTINGS)) {
128-
return new ExponentialBackOff.Builder()
129-
.setMultiplier(streamingRetrySettings.getRetryDelayMultiplier())
130-
.setInitialIntervalMillis(
131-
Math.max(10, (int) streamingRetrySettings.getInitialRetryDelay().toMillis()))
132-
.setMaxIntervalMillis(
133-
Math.max(1000, (int) streamingRetrySettings.getMaxRetryDelay().toMillis()))
134-
.setMaxElapsedTimeMillis(Integer.MAX_VALUE) // Prevent Backoff.STOP from getting returned.
135-
.build();
153+
/**
154+
* Returns true if the number of consecutive failed attempts has reached the maximum number of
155+
* attempts in the retry settings. {@link RetrySettings#getMaxAttempts()} equal to zero means that
156+
* no maximum has been set, and that the number of attempts is unlimited. This is also the value
157+
* in the default streaming retry settings, which means that only users who have explicitly opted
158+
* in to a maximum number of attempts are affected by this limit.
159+
*/
160+
private boolean maxAttemptsExhausted() {
161+
int maxAttempts = streamingRetrySettings.getMaxAttempts();
162+
return maxAttempts > 0 && attempts >= maxAttempts;
163+
}
164+
165+
/**
166+
* Returns true if retrying after the proposed delay would exceed the total timeout in the retry
167+
* settings. The total timeout limits the wall-clock time that is spent on a sequence of
168+
* consecutive failed attempts without progress, measured from the first failure of the sequence.
169+
* It is only enforced for retry settings that set a positive total timeout: a total timeout of
170+
* zero means that no total timeout has been set, and that only maxAttempts (if set) limits the
171+
* retries. This mirrors the interpretation of these values in GAX.
172+
*/
173+
private boolean totalTimeoutExceeded(long proposedDelayMillis) {
174+
long totalTimeoutMillis = streamingRetrySettings.getTotalTimeout().toMillis();
175+
if (totalTimeoutMillis <= 0L) {
176+
return false;
177+
}
178+
long elapsedMillis = TimeUnit.NANOSECONDS.toMillis(nanoTime() - retrySequenceStartNanos);
179+
if (elapsedMillis < 0L) {
180+
elapsedMillis = 0L;
181+
}
182+
if (elapsedMillis >= totalTimeoutMillis) {
183+
return true;
136184
}
185+
return Math.max(proposedDelayMillis, 0L) >= totalTimeoutMillis - elapsedMillis;
186+
}
187+
188+
private ExponentialBackOff newBackOff() {
137189
return new ExponentialBackOff.Builder()
138190
.setMultiplier(streamingRetrySettings.getRetryDelayMultiplier())
139191
// All of these values must be > 0.
@@ -150,19 +202,14 @@ private ExponentialBackOff newBackOff() {
150202
(int)
151203
Math.min(
152204
streamingRetrySettings.getMaxRetryDelay().toMillis(), Integer.MAX_VALUE)))
153-
.setMaxElapsedTimeMillis(
154-
Math.max(
155-
1,
156-
(int)
157-
Math.min(
158-
streamingRetrySettings.getTotalTimeout().toMillis(), Integer.MAX_VALUE)))
205+
// The total timeout is enforced explicitly in computeNext(), based on the elapsed time
206+
// since the first failure of the current retry sequence. Prevent the backoff from
207+
// returning BackOff.STOP, as that would misinterpret a total timeout of zero (that is, no
208+
// total timeout) as a total timeout of one millisecond.
209+
.setMaxElapsedTimeMillis(Integer.MAX_VALUE)
159210
.build();
160211
}
161212

162-
private void backoffSleep(Context context, BackOff backoff) throws SpannerException {
163-
backoffSleep(context, nextBackOffMillis(backoff));
164-
}
165-
166213
private static long nextBackOffMillis(BackOff backoff) throws SpannerException {
167214
try {
168215
return backoff.nextBackOffMillis();
@@ -263,6 +310,14 @@ protected PartialResultSet computeNext() {
263310
PartialResultSet next = stream.next();
264311
boolean hasResumeToken = !next.getResumeToken().isEmpty();
265312
if (hasResumeToken) {
313+
// Only a resume token that differs from the last seen token is progress: a stream
314+
// that repeatedly returns the token that was used to resume it has not moved past it.
315+
if (!next.getResumeToken().equals(resumeToken)) {
316+
// The stream made progress, so reset the budget for consecutive failed attempts.
317+
attempts = 0;
318+
backOff = null;
319+
retrySequenceStartNanos = -1L;
320+
}
266321
resumeToken = next.getResumeToken();
267322
safeToRetry = true;
268323
}
@@ -287,25 +342,7 @@ protected PartialResultSet computeNext() {
287342
}
288343
} catch (SpannerException spannerException) {
289344
if (safeToRetry && isRetryable(spannerException)) {
290-
span.addAnnotation("Stream broken. Safe to retry", spannerException);
291-
logger.log(Level.FINE, "Retryable exception, will sleep and retry", spannerException);
292-
// Truncate any items in the buffer before the last retry token.
293-
while (!buffer.isEmpty() && buffer.getLast().getResumeToken().isEmpty()) {
294-
buffer.removeLast();
295-
}
296-
assert buffer.isEmpty() || buffer.getLast().getResumeToken().equals(resumeToken);
297-
stream = null;
298-
try (IScope s = tracer.withSpan(span)) {
299-
long delay = spannerException.getRetryDelayInMillis();
300-
if (delay != -1) {
301-
backoffSleep(context, delay);
302-
} else {
303-
if (this.backOff == null) {
304-
this.backOff = newBackOff();
305-
}
306-
backoffSleep(context, this.backOff);
307-
}
308-
}
345+
handleRetryableException(context, spannerException);
309346

310347
continue;
311348
}
@@ -331,6 +368,62 @@ && prepareIteratorForRetryOnDifferentGrpcChannel()) {
331368
}
332369
}
333370

371+
/** Monotonic time source, overridable for deterministic retry-budget tests. */
372+
@VisibleForTesting
373+
long nanoTime() {
374+
return System.nanoTime();
375+
}
376+
377+
@VisibleForTesting
378+
long checkRetryBudgetAndGetDelay(SpannerException spannerException) {
379+
if (attempts == 0) {
380+
retrySequenceStartNanos = nanoTime();
381+
}
382+
attempts++;
383+
if (maxAttemptsExhausted()) {
384+
span.addAnnotation(
385+
"Stream broken. Not retrying because the maximum number of attempts has been"
386+
+ " exhausted",
387+
spannerException);
388+
span.setStatus(spannerException);
389+
throw spannerException;
390+
}
391+
// Determine the retry delay: either the delay that the server included in the error, or
392+
// otherwise a delay determined by the exponential backoff.
393+
long delayMillis = spannerException.getRetryDelayInMillis();
394+
if (delayMillis == -1L) {
395+
if (this.backOff == null) {
396+
this.backOff = newBackOff();
397+
}
398+
delayMillis = nextBackOffMillis(this.backOff);
399+
}
400+
// The total timeout budget applies regardless of whether the delay came from the server
401+
// or from the backoff.
402+
if (totalTimeoutExceeded(delayMillis)) {
403+
span.addAnnotation(
404+
"Stream broken. Not retrying because the total timeout has been exhausted",
405+
spannerException);
406+
span.setStatus(spannerException);
407+
throw spannerException;
408+
}
409+
return delayMillis;
410+
}
411+
412+
private void handleRetryableException(Context context, SpannerException spannerException) {
413+
long delayMillis = checkRetryBudgetAndGetDelay(spannerException);
414+
span.addAnnotation("Stream broken. Safe to retry", spannerException);
415+
logger.log(Level.FINE, "Retryable exception, will sleep and retry", spannerException);
416+
// Truncate any items in the buffer before the last retry token.
417+
while (!buffer.isEmpty() && buffer.getLast().getResumeToken().isEmpty()) {
418+
buffer.removeLast();
419+
}
420+
assert buffer.isEmpty() || buffer.getLast().getResumeToken().equals(resumeToken);
421+
stream = null;
422+
try (IScope s = tracer.withSpan(span)) {
423+
backoffSleep(context, delayMillis);
424+
}
425+
}
426+
334427
private void startGrpcStreaming() {
335428
if (stream == null) {
336429
span.addAnnotation(

java-spanner/google-cloud-spanner/src/main/java/com/google/cloud/spanner/SpannerOptions.java

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1669,6 +1669,15 @@ public Builder setRetrySettings(RetrySettings retrySettings) {
16691669
* href="https://github.com/googleapis/googleapis/blob/master/google/spanner/v1/spanner_gapic.yaml">spanner_gapic.yaml</a>.
16701670
* Retries are configured for idempotent methods but not for non-idempotent methods.
16711671
*
1672+
* <p>For streaming queries and reads, configure {@code executeStreamingSqlSettings()} and
1673+
* {@code streamingReadSettings()}, respectively. Set {@code maxAttempts=1} to disable streaming
1674+
* retries; an empty set of retryable codes does not disable retries for intrinsically retryable
1675+
* errors. Defaults allow unlimited streaming resumes. When customizing retry settings, set the
1676+
* total timeout explicitly: calling {@code toBuilder()} on the stub's retry settings copies
1677+
* GAPIC's generated one-hour {@code totalTimeout}; set it to zero explicitly for unlimited
1678+
* resumes. Limits apply to consecutive failures and reset when the stream makes progress by
1679+
* returning a new resume token.
1680+
*
16721681
* <p>You can set the same {@link RetrySettings} for all unary methods by calling this:
16731682
*
16741683
* <pre><code>

java-spanner/google-cloud-spanner/src/main/java/com/google/cloud/spanner/spi/v1/GapicSpannerRpc.java

Lines changed: 22 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -271,6 +271,15 @@ public class GapicSpannerRpc implements SpannerRpc {
271271
private static final CallOptions.Key<Boolean> BASE_CONTEXT_MARKER_KEY =
272272
CallOptions.Key.create("BASE_CONTEXT_MARKER_KEY");
273273

274+
// Normalize the generated placeholder to the historical streaming resume policy.
275+
static final RetrySettings DEFAULT_STREAMING_RETRY_SETTINGS =
276+
RetrySettings.newBuilder()
277+
.setTotalTimeoutDuration(Duration.ZERO)
278+
.setMaxAttempts(0)
279+
.setInitialRetryDelayDuration(Duration.ofMillis(10))
280+
.setMaxRetryDelayDuration(Duration.ofMillis(1000))
281+
.build();
282+
274283
private final RequestIdCreator requestIdCreator = new RequestIdCreatorImpl();
275284
private boolean rpcIsClosed;
276285
private final SpannerStub spannerStub;
@@ -452,8 +461,14 @@ public GapicSpannerRpc(final SpannerOptions options) {
452461
DIRECTPATH_CHANNEL_CREATED =
453462
((GrpcTransportChannel) clientContext.getTransportChannel()).isDirectPath()
454463
&& isEnableDirectAccess;
455-
this.readRetrySettings =
464+
SpannerStubSettings.Builder defaultStubSettings = SpannerStubSettings.newBuilder();
465+
RetrySettings configuredReadRetrySettings =
456466
options.getSpannerStubSettings().streamingReadSettings().getRetrySettings();
467+
this.readRetrySettings =
468+
configuredReadRetrySettings.equals(
469+
defaultStubSettings.streamingReadSettings().getRetrySettings())
470+
? DEFAULT_STREAMING_RETRY_SETTINGS
471+
: configuredReadRetrySettings;
457472
Set<Code> streamingReadRetryableCodes =
458473
options.getSpannerStubSettings().streamingReadSettings().getRetryableCodes();
459474
this.readRetryableCodes =
@@ -463,8 +478,13 @@ public GapicSpannerRpc(final SpannerOptions options) {
463478
.add(Code.RESOURCE_EXHAUSTED)
464479
.build()
465480
: streamingReadRetryableCodes;
466-
this.executeQueryRetrySettings =
481+
RetrySettings configuredQueryRetrySettings =
467482
options.getSpannerStubSettings().executeStreamingSqlSettings().getRetrySettings();
483+
this.executeQueryRetrySettings =
484+
configuredQueryRetrySettings.equals(
485+
defaultStubSettings.executeStreamingSqlSettings().getRetrySettings())
486+
? DEFAULT_STREAMING_RETRY_SETTINGS
487+
: configuredQueryRetrySettings;
468488
Set<Code> executeStreamingSqlRetryableCodes =
469489
options.getSpannerStubSettings().executeStreamingSqlSettings().getRetryableCodes();
470490
this.executeQueryRetryableCodes =

java-spanner/google-cloud-spanner/src/test/java/com/google/cloud/spanner/MockSpannerServiceImpl.java

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -517,6 +517,19 @@ public static SimulatedExecutionTime ofStreamException(Exception exception, long
517517
0, 0, Collections.singletonList(exception), false, Collections.singleton(streamIndex));
518518
}
519519

520+
/**
521+
* Creates a {@link SimulatedExecutionTime} that throws the given exceptions at the given
522+
* indices in the returned stream. The exceptions and stream indices are matched by position:
523+
* the first exception is thrown when the first call reaches the first stream index, the second
524+
* exception when the next call reaches the second stream index, and so on. The stream index is
525+
* reset for each (retried) call.
526+
*/
527+
public static SimulatedExecutionTime ofStreamExceptions(
528+
Collection<? extends Exception> exceptions, Collection<Long> streamIndices) {
529+
Preconditions.checkArgument(exceptions.size() == streamIndices.size());
530+
return new SimulatedExecutionTime(0, 0, exceptions, false, streamIndices);
531+
}
532+
520533
public static SimulatedExecutionTime stickyDatabaseNotFoundException(String name) {
521534
return ofStickyException(
522535
SpannerExceptionFactoryTest.newStatusDatabaseNotFoundException(name));

0 commit comments

Comments
 (0)