Add apiCallAttempt timeout and apiCall timeout feature for asynchrounous operations #657

zoewangg · 2018-08-10T22:42:42Z

Add apiCallAttempt timeout and apiCall timeout feature for asynchronous operations.

apiCallTimeout: time out config for the entire api call request (including signing, retry, etc)
apiCallAttemptTimeout: time out config for an api call attempt.

I renamed the original timeout classes. Below are the new classes:

TimeoutTask interface of the timer task to abort the abortable
-> AsyncTimeoutTask implementation for asynchronous operation
TimeoutTracker interface to track the TimeoutTask and the ScheduledFuture
-> ApiCallTimeoutTracker default implementations to track Api call time out task AsyncTimeoutTask
-> NoOpTimeoutTracker when timeout is not enabled

~~I removed all the existing timer unit tests using the AmazonSyncHttpClient because I'm working on adding more tests using the generated clients and those tests would cover the existing tests.~~
~~Second thoughts: will fix them and add them back~~
Added them back.

TODOs:

~~add more protocol tests with both apiCallTimeout and apiCallAttemptTimeout enabled.~~
~~add javadocs~~
~~clean up logs~~

dagnir · 2018-08-14T17:39:59Z

Still going through it but I had a some questions regarding the async timeouts:

What are the situations in which a customer would want to use a timer on an async call? Since we return a CompletableFuture it seems like it's easy for them to do their own timing out if necessary:

e.g.

CompletableFuture<GetObjectResponse> f = s3Client.getObject(request, toFileTransformer);

// do other stuff

f.get(10, TimeUnit.MILLISECONDS);

I think we should also clearly define what it means to timeout an async task since by definition it doesn't happen synchronously with the current thread. For example, does the timer start when we submit the request to async client? Or when the async client actually starts executing the request?

shorea · 2018-08-14T17:44:04Z

I think timeouts for async is more about releasing resources than customer SLAs. I.E. close the connection and give it back to the pool, don't submit to our future completion executor, etc.

zoewangg · 2018-08-14T18:07:59Z

Customer might still want to timeout if the request is taking too long and could take up resources and there might be other chained operations in the completableFuture that are getting "blocked".

For example:

CompletableFuture.allOf(s3Async.getObject(oneRequest), s3Async.getObject(anotherrequest));

f.get(10, TimeUnit.MILLISECONDS) could work but that's a blocking call.

Side note: Java 9 introduced CompletableFutre.orTimeout https://docs.oracle.com/javase/9/docs/api/java/util/concurrent/CompletableFuture.html#orTimeout-long-java.util.concurrent.TimeUnit- which is pretty cool.

I think we should also clearly define what it means to timeout an async task since by definition it doesn't happen synchronously with the current thread. does the timer start when we submit the request to async client? Or when the async client actually starts executing the request?

Yeah, I'll add more javadocs.

For ApiCallTimeout, timer starts in the signing stage. https://github.com/aws/aws-sdk-java-v2/pull/657/files#diff-427c7fb0c6f7ebb4aa635811a210f908R130

For ApiCallAttemptTimeout, timer starts right before making http requests. https://github.com/aws/aws-sdk-java-v2/pull/657/files#diff-e3a70123328ddb47abe656e045204a99R224

dagnir · 2018-08-14T18:16:07Z

@shorea I thought about that as well, but it seems like timeout is the wrong place to hang it on. Resource cleanup should all take place if the customer cancels the future while the request is executing as well right? I'm not sure sure if we do that today, but I don't think we do.

dagnir · 2018-08-14T17:48:18Z

core/sdk-core/src/main/java/software/amazon/awssdk/core/client/config/SdkClientOption.java

@@ -87,6 +94,10 @@
    public static final SdkClientOption<SdkHttpClient> SYNC_HTTP_CLIENT =
            new SdkClientOption<>(SdkHttpClient.class);

+    public static final SdkClientOption<Duration> API_CALL_ATTEMPT_TIME_OUT = new SdkClientOption<>(Duration.class);


nit: should be TIMEOUT to match spelling of the getter/setter as well as the spelling of timeout in other places.

+1 good catch. it's too tempting to separate them when they are all uppercase!

dagnir · 2018-08-14T18:54:19Z

...dk-core/src/main/java/software/amazon/awssdk/core/internal/http/timers/AsyncTimeoutTask.java

+    }
+
+    @Override
+    public void run() {


Do we need to do anything special when streaming responses? Do we bubble an exception to the Subscriber?

Not that I'm aware of. The exception is bubbled to AsyncResponseTransformer.exceptionOccurred.

We have a test for streaming operation: https://github.com/aws/aws-sdk-java-v2/pull/657/files#diff-a78559873b6762403653c7ac0f1beb9eR103

dagnir · 2018-08-14T18:57:19Z

.../sdk-core/src/main/java/software/amazon/awssdk/core/internal/http/timers/TimeoutTracker.java


    /**
     * @return True if client execution has been aborted by the timer task. False otherwise
     */
-    boolean hasTimeoutExpired();
+    boolean isTimedOut();


minor: this makes it sound like the task itself has timed out. Maybe something like hasExecuted?

millems · 2018-08-16T17:18:42Z

+1 to cleaning up if the user cancels the future (eg. if they're using Java 9's orTimeout()).

I still think we should support global timeouts within the SDK so that the customer doesn't always have to enforce it at the future level, and can use the same timeout configuration with sync and async.

millems · 2018-08-16T17:20:59Z

core/sdk-core/src/main/java/software/amazon/awssdk/core/RequestOverrideConfiguration.java

@@ -73,6 +79,43 @@ protected RequestOverrideConfiguration(Builder<?> builder) {
        return apiNames;
    }

+    /**
+     * The amount of time to wait for the http request to complete before giving up and timing out. A positive value
+     * enables this feature.


Should it be "this value will always be positive, if present"? (same comment below)

millems · 2018-08-16T17:22:11Z

core/sdk-core/src/main/java/software/amazon/awssdk/core/RequestOverrideConfiguration.java

+     * don't get aborted until several seconds after the timer has been breached. Because of this, the request timeout
+     * feature should not be used when absolute precision is needed.
+     *
+     * @see Builder#apiCallAttemptTimeout(Duration)


Can we have a section here that differentiates between this and apiCallTimeout? I see there's one down there already.

millems · 2018-08-16T17:27:31Z

...k-core/src/main/java/software/amazon/awssdk/core/client/builder/SdkDefaultClientBuilder.java

@@ -226,6 +230,7 @@ private SdkClientConfiguration finalizeAsyncConfiguration(SdkClientConfiguration
     */
    private SdkClientConfiguration finalizeConfiguration(SdkClientConfiguration config) {
        return config.toBuilder()
+                     .option(TIMEOUT_EXECUTOR_SERVICE, resolveTimeoutExecutorService())


Initial thought without looking further in the code first: We already have an internal scheduled executor service for retries. Can we use the same one for timeouts?

yeah, we can, probably need to rename the existingASYNC_RETRY_EXECUTOR_SERVICE to SDK_INTERNAL_EXECUTOR_SERVICE(or something else)?

reused the scheduled executor and renamed it to SCHEDULED_EXECUTOR_SERVICE

millems · 2018-08-16T17:28:47Z

...ore/src/main/java/software/amazon/awssdk/core/client/config/ClientOverrideConfiguration.java

    }

    @Override
    public Builder toBuilder() {
        return new DefaultClientOverrideConfigurationBuilder().advancedOptions(advancedOptions.toBuilder())
                                                              .headers(headers)
                                                              .retryPolicy(retryPolicy)
+                                                              .apiCallAttemptTimeout(apiCallAttemptTimeout)
+                                                              .apiCallAttemptTimeout(apiCallAttemptTimeout)


good catch! fixed

millems · 2018-08-16T17:29:57Z

...core/src/main/java/software/amazon/awssdk/core/exception/ApiCallAttemptTimeoutException.java

+    public static ApiCallAttemptTimeoutException create() {
+        return builder().message("HTTP request execution did not complete before the specified timeout configuration.")
+                        .build();
+    }


Can we specify the timeout that was configured here as well?

millems · 2018-08-16T17:38:11Z

...ava/software/amazon/awssdk/core/internal/http/pipeline/stages/MakeAsyncHttpRequestStage.java

+            return requestConfig.apiCallAttemptTimeout().get().toMillis();
+        }
+
+        if (apiCallAttemptTimeout != null) {


Seems duplicated from elsewhere.

the other place is getApiTimoeut and this is getApiCallAttemptTimeout

millems · 2018-08-16T17:38:43Z

...rc/main/java/software/amazon/awssdk/core/internal/http/response/SdkErrorResponseHandler.java

@@ -51,6 +51,7 @@ private SdkException handleServiceException(SdkHttpFullResponse response, Execut
        try {
            return delegate.handle(response, executionAttributes);
        } catch (InterruptedException e) {
+            Thread.currentThread().interrupt();
            throw e;


Same question here. Where were we not interrupting the thread before? Can we just fix it there instead of re-interrupting here?

yeah, reverted the change and will create a backlog item to track those.

millems · 2018-08-16T17:40:10Z

core/sdk-core/src/test/resources/log4j.properties

@@ -31,7 +31,7 @@ log4j.logger.org.apache.http.wire=INFO
 log4j.logger.org.apache.http=DEBUG
 # log4j.logger.org.apache.http.wire=DEBUG
 #
-# log4j.logger.com.amazonaws=DEBUG
+log4j.logger.sofeware.amazonaws.awssdk=TRACE


software*? needed?

millems · 2018-08-16T17:40:25Z

services/dynamodb/src/test/resources/log4j.properties

@@ -27,8 +27,9 @@ log4j.appender.A1.layout.ConversionPattern=%d [%t] %-5p %c - %m%n
 #log4j.logger.httpclient.wire=DEBUG

 # HttpClient 4 Wire Logging
-log4j.logger.org.apache.http.wire=DEBUG
+log4j.logger.org.apache=TRACE


Are these needed?

millems · 2018-08-16T17:41:48Z

utils/src/main/java/software/amazon/awssdk/utils/Validate.java

+    public static Duration isPositiveIfPresent(Duration duration, String fieldName) {
+        if (duration == null) {
+            return null;
+        }


Maybe isPositiveOrNull? "Present" implies there's an optional involved, to me. Can isPositive delegate to here now for its positivity check?

I also think the naming convention elsewhere is to include "param" in the method name if the second parameter is a field name. Otherwise it would be a string format for the caller to specify the whole message... but it looks like that's already been broken by isPositive, so nevermind!

dagnir

I might have missed it, but are API call attempt timeouts implement for sync calls?

dagnir · 2018-08-16T18:00:18Z

...main/java/software/amazon/awssdk/core/internal/http/pipeline/stages/AsyncRetryableStage.java

+                context.apiCallTimeoutTracker(timeoutTracker);
+
+                future.whenComplete((o, t) -> {
+                    if (t != null) {


Why do we need this check here?

We need the checks here because we don't want it to timeout if the completableFuture fails exceptionally. I'll add a test for it.

If the future has already been completed, the timeout task should not have any effect though right? Unless it tries to force the timeout exception by using obtrudeException: https://docs.oracle.com/javase/8/docs/api/java/util/concurrent/CompletableFuture.html#obtrudeException-java.lang.Throwable-

Whoops.. I meant to write if (t == null)(The unit tests succeeded because there were either response unmarshaller expception or ApiCallAttemptTimeoutException got retried). But yeah, I think you are right, we should remove the check here.

dagnir · 2018-08-16T20:18:28Z

...dk-core/src/main/java/software/amazon/awssdk/core/internal/http/timers/AsyncTimeoutTask.java

+    public void run() {
+        log.trace(() -> "Times up. Aborting the request");
+        hasExecuted = true;
+        if (completableFuture != null && !completableFuture.isDone()) {


When would we have a null future?

yeah, it should not be null. I'll add the validation in the constructor.

dagnir · 2018-08-16T20:20:54Z

...re/src/main/java/software/amazon/awssdk/core/internal/http/timers/ApiCallTimeoutTracker.java

+
+    @Override
+    public void cancel() {
+        if (future != null && !future.isDone()) {


Same here, would we ever have a null future?

yup. same as above, will remove the null check here and add validation in the constructor.

zoewangg · 2018-08-16T20:44:04Z

@dagnir Timeouts for sync were implemented before and we removed them via #494 because timeouts for async were not working back then and we wanted to keep consistent for async and sync.

Hmmm, we are in the same situation now except that this time it's sync that is missing the timeout feature.

dagnir

Some weird linebreaks in the javadocs for apiCallTimeout, apiCallAttemptTimeout getters/setters. Can we fix those as well?

dagnir · 2018-08-20T21:12:43Z

...re/src/main/java/software/amazon/awssdk/core/internal/http/timers/ApiCallTimeoutTracker.java

+
+    @Override
+    public void cancel() {
+        if (!future.isDone()) {


I don't think we need this check. If the future is already complete cancel() should have no effect. There's also no guarantee isDone would still be false when we call cancel

dagnir · 2018-08-20T21:14:45Z

core/sdk-core/src/main/java/software/amazon/awssdk/core/internal/http/timers/TimerUtils.java

+    public static <T> TimeoutTracker timeCompletableFuture(CompletableFuture<T> completableFuture,
+                                                           ScheduledExecutorService timeoutExecutor,
+                                                           SdkClientException exceptionToThrow,
+                                                           long timeoutInMills) {


minor: Taking Duration as a param would be more flexible

hmmm. I actually prefer using long here because we don't need another null check here.

Fair enough; it's an internal util so I' don't feel strongly either way.

dagnir · 2018-08-20T21:17:41Z

utils/src/main/java/software/amazon/awssdk/utils/Validate.java

+     *
+     * @param duration Number to validate
+     * @param fieldName Field name to display in exception message if not positive.
+     * @return Duration if positive.


nit: "or null"

dagnir · 2018-08-20T21:21:38Z

utils/src/main/java/software/amazon/awssdk/utils/OptionalUtils.java

+            return firstValue;
+        }
+
+        T value = fallbackValue.get();


If fallbackValue is empty get() will throw an exception here. I think we can just return fallbackValue here

Oops nm, it's a Supplier, not an Optional. In that case we can just change this to Optional.ofNullable(value)

dagnir

LGTM. Can you add a changelog message? Can you also clarify in your commit and and changelog message that it's for async only?

…rounous calls.

…1d0a417c Pull request: release <- staging/388a3a8b-bd1c-4999-82b9-975d1d0a417c

Khalian · 2021-11-06T00:37:33Z

core/sdk-core/src/test/java/utils/HttpTestUtils.java

-                                     .option(SdkClientOption.ASYNC_RETRY_EXECUTOR_SERVICE, Executors.newScheduledThreadPool(1))
-                                     .option(SdkAdvancedAsyncClientOption.FUTURE_COMPLETION_EXECUTOR,
-                                             Runnable::run)
+                                     .option(SdkClientOption.SCHEDULED_EXECUTOR_SERVICE, Executors.newScheduledThreadPool(1))


Isnt this thread pool technically unbounded? The core pool size is 1, but the max pool is int.max.

I believe the work queue used by the scheduledThreadPool is unbounded. Because the JDK classes only use the core pool size until the work queue is full, and the work queue is unbounded, the maximumPoolSize within the scheduled thread pool should never used.

zoewangg force-pushed the zoewang-timeoutFeature branch 3 times, most recently from 9425025 to a913b3d Compare August 13, 2018 17:59

zoewangg changed the title ~~[DRAFT] Add apiCallAttempt timeout and apiCall timeout feature~~ Add apiCallAttempt timeout and apiCall timeout feature Aug 14, 2018

dagnir reviewed Aug 14, 2018

View reviewed changes

millems reviewed Aug 16, 2018

View reviewed changes

dagnir reviewed Aug 16, 2018

View reviewed changes

dagnir reviewed Aug 20, 2018

View reviewed changes

dagnir approved these changes Aug 21, 2018

View reviewed changes

Implement apiCallAttemptTimeout and apiCallTimeout feature for asynch…

cf225b2

…rounous calls.

zoewangg force-pushed the zoewang-timeoutFeature branch from 6d498ac to cf225b2 Compare August 21, 2018 16:43

zoewangg changed the title ~~Add apiCallAttempt timeout and apiCall timeout feature~~ Add apiCallAttempt timeout and apiCall timeout feature for asynchrounous operations Aug 21, 2018

zoewangg merged commit 7ab5e15 into master Aug 21, 2018

zoewangg deleted the zoewang-timeoutFeature branch September 13, 2018 17:48

zoewangg mentioned this pull request Nov 27, 2018

Execution and Request timeouts #29

Closed

aws-sdk-java-automation added a commit that referenced this pull request Nov 1, 2019

Merge pull request #657 from aws/staging/388a3a8b-bd1c-4999-82b9-975d…

e8c5504

…1d0a417c Pull request: release <- staging/388a3a8b-bd1c-4999-82b9-975d1d0a417c

Khalian reviewed Nov 6, 2021

View reviewed changes

Add apiCallAttempt timeout and apiCall timeout feature for asynchrounous operations #657

Add apiCallAttempt timeout and apiCall timeout feature for asynchrounous operations #657

Conversation

zoewangg commented Aug 10, 2018 • edited Loading

dagnir commented Aug 14, 2018

shorea commented Aug 14, 2018

zoewangg commented Aug 14, 2018

dagnir commented Aug 14, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

millems commented Aug 16, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dagnir left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

zoewangg commented Aug 16, 2018

dagnir left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dagnir left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

zoewangg commented Aug 10, 2018 •

edited

Loading