You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@beam.apache.org by ke...@apache.org on 2017/06/30 21:31:05 UTC
[03/50] beam git commit: [BEAM-1187] Improve logging to contain the
number of retries done due to IOException and unsuccessful response codes.
[BEAM-1187] Improve logging to contain the number of retries done due to IOException and unsuccessful response codes.
Project: http://git-wip-us.apache.org/repos/asf/beam/repo
Commit: http://git-wip-us.apache.org/repos/asf/beam/commit/03741ba0
Tree: http://git-wip-us.apache.org/repos/asf/beam/tree/03741ba0
Diff: http://git-wip-us.apache.org/repos/asf/beam/diff/03741ba0
Branch: refs/heads/gearpump-runner
Commit: 03741ba0b55e446cd2583e7ccc88f79ec21705b5
Parents: beb21f4
Author: Luke Cwik <lc...@google.com>
Authored: Fri Jun 23 09:32:49 2017 -0700
Committer: Luke Cwik <lc...@google.com>
Committed: Tue Jun 27 16:08:53 2017 -0700
----------------------------------------------------------------------
.../sdk/util/RetryHttpRequestInitializer.java | 148 ++++++++++++-------
.../util/RetryHttpRequestInitializerTest.java | 31 ++--
2 files changed, 116 insertions(+), 63 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/beam/blob/03741ba0/sdks/java/extensions/google-cloud-platform-core/src/main/java/org/apache/beam/sdk/util/RetryHttpRequestInitializer.java
----------------------------------------------------------------------
diff --git a/sdks/java/extensions/google-cloud-platform-core/src/main/java/org/apache/beam/sdk/util/RetryHttpRequestInitializer.java b/sdks/java/extensions/google-cloud-platform-core/src/main/java/org/apache/beam/sdk/util/RetryHttpRequestInitializer.java
index a23bee3..fd908cf 100644
--- a/sdks/java/extensions/google-cloud-platform-core/src/main/java/org/apache/beam/sdk/util/RetryHttpRequestInitializer.java
+++ b/sdks/java/extensions/google-cloud-platform-core/src/main/java/org/apache/beam/sdk/util/RetryHttpRequestInitializer.java
@@ -17,8 +17,9 @@
*/
package org.apache.beam.sdk.util;
-import com.google.api.client.http.HttpBackOffIOExceptionHandler;
-import com.google.api.client.http.HttpBackOffUnsuccessfulResponseHandler;
+import static com.google.api.client.util.BackOffUtils.next;
+
+import com.google.api.client.http.HttpIOExceptionHandler;
import com.google.api.client.http.HttpRequest;
import com.google.api.client.http.HttpRequestInitializer;
import com.google.api.client.http.HttpResponse;
@@ -60,65 +61,106 @@ public class RetryHttpRequestInitializer implements HttpRequestInitializer {
*/
private static final int HANGING_GET_TIMEOUT_SEC = 80;
- private static class LoggingHttpBackOffIOExceptionHandler
- extends HttpBackOffIOExceptionHandler {
- public LoggingHttpBackOffIOExceptionHandler(BackOff backOff) {
- super(backOff);
+ /** Handlers used to provide additional logging information on unsuccessful HTTP requests. */
+ private static class LoggingHttpBackOffHandler
+ implements HttpIOExceptionHandler, HttpUnsuccessfulResponseHandler {
+
+ private final Sleeper sleeper;
+ private final BackOff ioExceptionBackOff;
+ private final BackOff unsuccessfulResponseBackOff;
+ private final Set<Integer> ignoredResponseCodes;
+ private int ioExceptionRetries;
+ private int unsuccessfulResponseRetries;
+
+ private LoggingHttpBackOffHandler(
+ Sleeper sleeper,
+ BackOff ioExceptionBackOff,
+ BackOff unsucessfulResponseBackOff,
+ Set<Integer> ignoredResponseCodes) {
+ this.sleeper = sleeper;
+ this.ioExceptionBackOff = ioExceptionBackOff;
+ this.unsuccessfulResponseBackOff = unsucessfulResponseBackOff;
+ this.ignoredResponseCodes = ignoredResponseCodes;
}
@Override
public boolean handleIOException(HttpRequest request, boolean supportsRetry)
throws IOException {
- boolean willRetry = super.handleIOException(request, supportsRetry);
+ // We will retry if the request supports retry or the backoff was successful.
+ // Note that the order of these checks is important since
+ // backOffWasSuccessful will perform a sleep.
+ boolean willRetry = supportsRetry && backOffWasSuccessful(ioExceptionBackOff);
if (willRetry) {
+ ioExceptionRetries += 1;
LOG.debug("Request failed with IOException, will retry: {}", request.getUrl());
} else {
- LOG.warn(
- "Request failed with IOException (caller responsible for retrying): {}",
+ String message = "Request failed with IOException, "
+ + "performed {} retries due to IOExceptions, "
+ + "performed {} retries due to unsuccessful status codes, "
+ + "HTTP framework says request {} be retried, "
+ + "(caller responsible for retrying): {}";
+ LOG.warn(message,
+ ioExceptionRetries,
+ unsuccessfulResponseRetries,
+ supportsRetry ? "can" : "cannot",
request.getUrl());
}
return willRetry;
}
- }
-
- private static class LoggingHttpBackoffUnsuccessfulResponseHandler
- implements HttpUnsuccessfulResponseHandler {
- private final HttpBackOffUnsuccessfulResponseHandler handler;
- private final Set<Integer> ignoredResponseCodes;
-
- public LoggingHttpBackoffUnsuccessfulResponseHandler(BackOff backoff,
- Sleeper sleeper, Set<Integer> ignoredResponseCodes) {
- this.ignoredResponseCodes = ignoredResponseCodes;
- handler = new HttpBackOffUnsuccessfulResponseHandler(backoff);
- handler.setSleeper(sleeper);
- handler.setBackOffRequired(
- new HttpBackOffUnsuccessfulResponseHandler.BackOffRequired() {
- @Override
- public boolean isRequired(HttpResponse response) {
- int statusCode = response.getStatusCode();
- return (statusCode == 0) // Code 0 usually means no response / network error
- || (statusCode / 100 == 5) // 5xx: server error
- || statusCode == 429; // 429: Too many requests
- }
- });
- }
@Override
- public boolean handleResponse(HttpRequest request, HttpResponse response,
- boolean supportsRetry) throws IOException {
- boolean retry = handler.handleResponse(request, response, supportsRetry);
- if (retry) {
+ public boolean handleResponse(HttpRequest request, HttpResponse response, boolean supportsRetry)
+ throws IOException {
+ // We will retry if the request supports retry and the status code requires a backoff
+ // and the backoff was successful. Note that the order of these checks is important since
+ // backOffWasSuccessful will perform a sleep.
+ boolean willRetry = supportsRetry
+ && retryOnStatusCode(response.getStatusCode())
+ && backOffWasSuccessful(unsuccessfulResponseBackOff);
+ if (willRetry) {
+ unsuccessfulResponseRetries += 1;
LOG.debug("Request failed with code {}, will retry: {}",
response.getStatusCode(), request.getUrl());
+ } else {
+ String message = "Request failed with code {}, "
+ + "performed {} retries due to IOExceptions, "
+ + "performed {} retries due to unsuccessful status codes, "
+ + "HTTP framework says request {} be retried, "
+ + "(caller responsible for retrying): {}";
+ if (ignoredResponseCodes.contains(response.getStatusCode())) {
+ // Log ignored response codes at a lower level
+ LOG.debug(message,
+ response.getStatusCode(),
+ ioExceptionRetries,
+ unsuccessfulResponseRetries,
+ supportsRetry ? "can" : "cannot",
+ request.getUrl());
+ } else {
+ LOG.warn(message,
+ response.getStatusCode(),
+ ioExceptionRetries,
+ unsuccessfulResponseRetries,
+ supportsRetry ? "can" : "cannot",
+ request.getUrl());
+ }
+ }
+ return willRetry;
+ }
- } else if (!ignoredResponseCodes.contains(response.getStatusCode())) {
- LOG.warn(
- "Request failed with code {} (caller responsible for retrying): {}",
- response.getStatusCode(),
- request.getUrl());
+ /** Returns true iff performing the backoff was successful. */
+ private boolean backOffWasSuccessful(BackOff backOff) {
+ try {
+ return next(sleeper, backOff);
+ } catch (InterruptedException | IOException e) {
+ return false;
}
+ }
- return retry;
+ /** Returns true iff the {@code statusCode} represents an error that should be retried. */
+ private boolean retryOnStatusCode(int statusCode) {
+ return (statusCode == 0) // Code 0 usually means no response / network error
+ || (statusCode / 100 == 5) // 5xx: server error
+ || statusCode == 429; // 429: Too many requests
}
}
@@ -174,20 +216,20 @@ public class RetryHttpRequestInitializer implements HttpRequestInitializer {
// TODO: Do this exclusively for work requests.
request.setReadTimeout(HANGING_GET_TIMEOUT_SEC * 1000);
- // Back off on retryable http errors.
- request.setUnsuccessfulResponseHandler(
+ LoggingHttpBackOffHandler loggingHttpBackOffHandler = new LoggingHttpBackOffHandler(
+ sleeper,
+ // Retry immediately on IOExceptions.
+ BackOff.ZERO_BACKOFF,
+ // Back off on retryable http errors.
// A back-off multiplier of 2 raises the maximum request retrying time
// to approximately 5 minutes (keeping other back-off parameters to
// their default values).
- new LoggingHttpBackoffUnsuccessfulResponseHandler(
- new ExponentialBackOff.Builder().setNanoClock(nanoClock)
- .setMultiplier(2).build(),
- sleeper, ignoredResponseCodes));
-
- // Retry immediately on IOExceptions.
- LoggingHttpBackOffIOExceptionHandler loggingBackoffHandler =
- new LoggingHttpBackOffIOExceptionHandler(BackOff.ZERO_BACKOFF);
- request.setIOExceptionHandler(loggingBackoffHandler);
+ new ExponentialBackOff.Builder().setNanoClock(nanoClock).setMultiplier(2).build(),
+ ignoredResponseCodes
+ );
+
+ request.setUnsuccessfulResponseHandler(loggingHttpBackOffHandler);
+ request.setIOExceptionHandler(loggingHttpBackOffHandler);
// Set response initializer
if (responseInterceptor != null) {
http://git-wip-us.apache.org/repos/asf/beam/blob/03741ba0/sdks/java/extensions/google-cloud-platform-core/src/test/java/org/apache/beam/sdk/util/RetryHttpRequestInitializerTest.java
----------------------------------------------------------------------
diff --git a/sdks/java/extensions/google-cloud-platform-core/src/test/java/org/apache/beam/sdk/util/RetryHttpRequestInitializerTest.java b/sdks/java/extensions/google-cloud-platform-core/src/test/java/org/apache/beam/sdk/util/RetryHttpRequestInitializerTest.java
index 37551a4..13a9309 100644
--- a/sdks/java/extensions/google-cloud-platform-core/src/test/java/org/apache/beam/sdk/util/RetryHttpRequestInitializerTest.java
+++ b/sdks/java/extensions/google-cloud-platform-core/src/test/java/org/apache/beam/sdk/util/RetryHttpRequestInitializerTest.java
@@ -49,10 +49,11 @@ import java.net.SocketTimeoutException;
import java.security.PrivateKey;
import java.util.Arrays;
import java.util.concurrent.atomic.AtomicLong;
+import org.apache.beam.sdk.testing.ExpectedLogs;
import org.hamcrest.Matchers;
import org.junit.After;
-import org.junit.Assert;
import org.junit.Before;
+import org.junit.Rule;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.junit.runners.JUnit4;
@@ -67,6 +68,8 @@ import org.mockito.stubbing.Answer;
@RunWith(JUnit4.class)
public class RetryHttpRequestInitializerTest {
+ @Rule public ExpectedLogs expectedLogs = ExpectedLogs.none(RetryHttpRequestInitializer.class);
+
@Mock private PrivateKey mockPrivateKey;
@Mock private LowLevelHttpRequest mockLowLevelRequest;
@Mock private LowLevelHttpResponse mockLowLevelResponse;
@@ -135,6 +138,7 @@ public class RetryHttpRequestInitializerTest {
verify(mockLowLevelRequest).setTimeout(anyInt(), anyInt());
verify(mockLowLevelRequest).execute();
verify(mockLowLevelResponse).getStatusCode();
+ expectedLogs.verifyNotLogged("Request failed");
}
/**
@@ -153,7 +157,7 @@ public class RetryHttpRequestInitializerTest {
HttpResponse response = result.executeUnparsed();
assertNotNull(response);
} catch (HttpResponseException e) {
- Assert.assertThat(e.getMessage(), Matchers.containsString("403"));
+ assertThat(e.getMessage(), Matchers.containsString("403"));
}
verify(mockHttpResponseInterceptor).interceptResponse(any(HttpResponse.class));
@@ -162,6 +166,7 @@ public class RetryHttpRequestInitializerTest {
verify(mockLowLevelRequest).setTimeout(anyInt(), anyInt());
verify(mockLowLevelRequest).execute();
verify(mockLowLevelResponse).getStatusCode();
+ expectedLogs.verifyWarn("Request failed with code 403");
}
/**
@@ -188,6 +193,7 @@ public class RetryHttpRequestInitializerTest {
verify(mockLowLevelRequest, times(3)).setTimeout(anyInt(), anyInt());
verify(mockLowLevelRequest, times(3)).execute();
verify(mockLowLevelResponse, times(3)).getStatusCode();
+ expectedLogs.verifyDebug("Request failed with code 503");
}
/**
@@ -211,6 +217,7 @@ public class RetryHttpRequestInitializerTest {
verify(mockLowLevelRequest, times(2)).setTimeout(anyInt(), anyInt());
verify(mockLowLevelRequest, times(2)).execute();
verify(mockLowLevelResponse).getStatusCode();
+ expectedLogs.verifyDebug("Request failed with IOException");
}
/**
@@ -224,19 +231,22 @@ public class RetryHttpRequestInitializerTest {
int n = 0;
@Override
public Integer answer(InvocationOnMock invocation) {
- return (n++ < retries - 1) ? 503 : 200;
+ return n++ < retries ? 503 : 9999;
}});
Storage.Buckets.Get result = storage.buckets().get("test");
- HttpResponse response = result.executeUnparsed();
- assertNotNull(response);
+ try {
+ result.executeUnparsed();
+ fail();
+ } catch (Throwable t) {
+ }
verify(mockHttpResponseInterceptor).interceptResponse(any(HttpResponse.class));
- verify(mockLowLevelRequest, atLeastOnce()).addHeader(anyString(),
- anyString());
- verify(mockLowLevelRequest, times(retries)).setTimeout(anyInt(), anyInt());
- verify(mockLowLevelRequest, times(retries)).execute();
- verify(mockLowLevelResponse, times(retries)).getStatusCode();
+ verify(mockLowLevelRequest, atLeastOnce()).addHeader(anyString(), anyString());
+ verify(mockLowLevelRequest, times(retries + 1)).setTimeout(anyInt(), anyInt());
+ verify(mockLowLevelRequest, times(retries + 1)).execute();
+ verify(mockLowLevelResponse, times(retries + 1)).getStatusCode();
+ expectedLogs.verifyWarn("performed 10 retries due to unsuccessful status codes");
}
/**
@@ -276,6 +286,7 @@ public class RetryHttpRequestInitializerTest {
} catch (Throwable e) {
assertThat(e, Matchers.<Throwable>instanceOf(SocketTimeoutException.class));
assertEquals(1 + defaultNumberOfRetries, executeCount.get());
+ expectedLogs.verifyWarn("performed 10 retries due to IOExceptions");
}
}
}