SnsAsycClient with NettyNioAsyncHttpClient causes CompletionException when publish data

When use SnsAsycClient publish data to my topics using NettyNioAsyncHttpClient as the http client, I often see Java CompletionException Caused by: java.io.IOException: Server failed to send complete response. This can happen even in a small traffic environment (30-40 rps). code and logs are pasted below.

Not sure if this has the same root cause with issue 1122

Java code

 @Bean
 public SnsAsyncClient snsAsyncClient() {
     final SdkAsyncHttpClient httpClient = NettyNioAsyncHttpClient.builder()
        .maxConcurrency(200)
        .maxPendingConnectionAcquires(15_000)
        .build();
     return SnsAsyncClient.builder().httpClient(httpClient).region(Region.AP_SOUTHEAST_2)
    .build();
 }

error logs

java.util.concurrent.CompletionException: software.amazon.awssdk.core.exception.SdkClientException
at software.amazon.awssdk.utils.CompletableFutureUtils.errorAsCompletionException(CompletableFutureUtils.java:61)
at software.amazon.awssdk.core.internal.http.pipeline.stages.AsyncExecutionFailureExceptionReportingStage.lambda$execute$0(AsyncExecutionFailureExceptionReportingStage.java:51)
at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:930)
at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:907)
at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088)
at software.amazon.awssdk.utils.CompletableFutureUtils.lambda$forwardExceptionTo$0(CompletableFutureUtils.java:75)
at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859)
at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837)
at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088)
at software.amazon.awssdk.core.internal.http.pipeline.stages.AsyncRetryableStage$RetryExecutor.retryErrorIfNeeded(AsyncRetryableStage.java:175)
at software.amazon.awssdk.core.internal.http.pipeline.stages.AsyncRetryableStage$RetryExecutor.retryIfNeeded(AsyncRetryableStage.java:126)
at software.amazon.awssdk.core.internal.http.pipeline.stages.AsyncRetryableStage$RetryExecutor.lambda$execute$0(AsyncRetryableStage.java:107)
at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859)
at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837)
at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088)
at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeAsyncHttpRequestStage$ResponseHandler.onError(MakeAsyncHttpRequestStage.java:249)
at software.amazon.awssdk.http.nio.netty.internal.ResponseHandler.lambda$notifyIfResponseNotCompleted$2(ResponseHandler.java:397)
at software.amazon.awssdk.http.nio.netty.internal.ResponseHandler.runAndLogError(ResponseHandler.java:180)
at software.amazon.awssdk.http.nio.netty.internal.ResponseHandler.notifyIfResponseNotCompleted(ResponseHandler.java:397)
at software.amazon.awssdk.http.nio.netty.internal.ResponseHandler.channelInactive(ResponseHandler.java:148)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:257)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:243)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:236)
at io.netty.handler.logging.LoggingHandler.channelInactive(LoggingHandler.java:167)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:257)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:243)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:236)
at io.netty.channel.ChannelInboundHandlerAdapter.channelInactive(ChannelInboundHandlerAdapter.java:81)
at io.netty.handler.timeout.IdleStateHandler.channelInactive(IdleStateHandler.java:278)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:257)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:243)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:236)
at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelInactive(CombinedChannelDuplexHandler.java:420)
at io.netty.handler.codec.ByteToMessageDecoder.channelInputClosed(ByteToMessageDecoder.java:393)
at io.netty.handler.codec.ByteToMessageDecoder.channelInactive(ByteToMessageDecoder.java:358)
at io.netty.handler.codec.http.HttpClientCodec$Decoder.channelInactive(HttpClientCodec.java:282)
at io.netty.channel.CombinedChannelDuplexHandler.channelInactive(CombinedChannelDuplexHandler.java:223)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:257)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:243)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:236)
at io.netty.handler.codec.ByteToMessageDecoder.channelInputClosed(ByteToMessageDecoder.java:393)
at io.netty.handler.codec.ByteToMessageDecoder.channelInactive(ByteToMessageDecoder.java:358)
at io.netty.handler.ssl.SslHandler.channelInactive(SslHandler.java:1075)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:257)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:243)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:236)
at io.netty.channel.ChannelInboundHandlerAdapter.channelInactive(ChannelInboundHandlerAdapter.java:81)
at io.netty.handler.timeout.IdleStateHandler.channelInactive(IdleStateHandler.java:278)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:257)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:243)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:236)
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1416)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:257)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:243)
at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:912)
at io.netty.channel.AbstractChannel$AbstractUnsafe$8.run(AbstractChannel.java:816)
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:416)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:515)
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:918)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: software.amazon.awssdk.core.exception.SdkClientException: null
at software.amazon.awssdk.core.exception.SdkClientException$BuilderImpl.build(SdkClientException.java:97)
at software.amazon.awssdk.core.internal.util.ThrowableUtils.asSdkException(ThrowableUtils.java:98)
at software.amazon.awssdk.core.internal.http.pipeline.stages.AsyncRetryableStage$RetryExecutor.retryIfNeeded(AsyncRetryableStage.java:125)
... 52 common frames omitted
 Caused by: java.io.IOException: Server failed to send complete response
at software.amazon.awssdk.http.nio.netty.internal.ResponseHandler.notifyIfResponseNotCompleted(ResponseHandler.java:396)
... 43 common frames omitted

Your Environment

• AWS Java SDK version used: aws sdk 2.8.7
• JDK version used: JDK 11
• Operating System and version: amazon-linux-2

[zoewangg]

Hi @WangDanny, this issue can happen when a request picks up a half-closed connection and we've made several changes to reduce the frequency of the errors. Could you try with the latest version?

Hi @zoewangg thank you very much for your reply.

I updated AWS java SDK to the latest version and also set the connectionMaxIdleTime to 5 seconds, as suggested in discussion of similar issues such as issue 1122. In past 3 days the number of errors looks reduced but I still see a burst of exceptions in the early morning of 16th (GMT+11) and the exception is now becomes io.netty.channel.ConnectTimeoutException: connection timed out: sns.ap-southeast-2.amazonaws.com/54.240.206.39:443.

Note that my code is deployed to us-east-1 which sends data to southeast-2 (as we can see in the exception). Do you have any clue about the reason of the exception and how to resolve it? my code and full exception is pasted below. Thank you very much.

Java:

@Bean
  public SnsAsyncClient snsAsyncClient() {
      final SdkAsyncHttpClient httpClient = NettyNioAsyncHttpClient.builder()
          .maxConcurrency(200)
          .connectionMaxIdleTime(Duration.ofSeconds(5))
          .build();
      return SnsAsyncClient.builder().httpClient(httpClient).region(Region.AP_SOUTHEAST_2).build();
}

gradle

implementation platform('software.amazon.awssdk:bom:2.10.16')
implementation 'software.amazon.awssdk:sns'
implementation ('software.amazon.awssdk:netty-nio-client')
implementation group: 'com.typesafe.akka', name: 'akka-actor_2.12', version: '2.6.0'
implementation group: 'org.scala-lang', name: 'scala-library', version: '2.12.10'

logs

java.util.concurrent.CompletionException: software.amazon.awssdk.core.exception.SdkClientException
at software.amazon.awssdk.utils.CompletableFutureUtils.errorAsCompletionException(CompletableFutureUtils.java:61)
at software.amazon.awssdk.core.internal.http.pipeline.stages.AsyncExecutionFailureExceptionReportingStage.lambda$execute$0(AsyncExecutionFailureExceptionReportingStage.java:51)
at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:930)
at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:907)
at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088)
at software.amazon.awssdk.utils.CompletableFutureUtils.lambda$forwardExceptionTo$0(CompletableFutureUtils.java:75)
at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859)
at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837)
at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088)
at software.amazon.awssdk.core.internal.http.pipeline.stages.AsyncRetryableStage$RetryExecutor.retryErrorIfNeeded(AsyncRetryableStage.java:175)
at software.amazon.awssdk.core.internal.http.pipeline.stages.AsyncRetryableStage$RetryExecutor.retryIfNeeded(AsyncRetryableStage.java:126)
at software.amazon.awssdk.core.internal.http.pipeline.stages.AsyncRetryableStage$RetryExecutor.lambda$execute$0(AsyncRetryableStage.java:107)
at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859)
at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837)
at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088)
at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeAsyncHttpRequestStage$ResponseHandler.onError(MakeAsyncHttpRequestStage.java:249)
at software.amazon.awssdk.http.nio.netty.internal.NettyRequestExecutor.handleFailure(NettyRequestExecutor.java:265)
at software.amazon.awssdk.http.nio.netty.internal.NettyRequestExecutor.makeRequestListener(NettyRequestExecutor.java:143)
at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:577)
at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:551)
at io.netty.util.concurrent.DefaultPromise.access$200(DefaultPromise.java:35)
at io.netty.util.concurrent.DefaultPromise$1.run(DefaultPromise.java:501)
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:510)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:518)
at io.netty.util.concurrent.SingleThreadEventExecutor$6.run(SingleThreadEventExecutor.java:1044)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: software.amazon.awssdk.core.exception.SdkClientException: null
at software.amazon.awssdk.core.exception.SdkClientException$BuilderImpl.build(SdkClientException.java:97)
at software.amazon.awssdk.core.internal.util.ThrowableUtils.asSdkException(ThrowableUtils.java:98)
at software.amazon.awssdk.core.internal.http.pipeline.stages.AsyncRetryableStage$RetryExecutor.retryIfNeeded(AsyncRetryableStage.java:125)
... 18 common frames omitted
Caused by: io.netty.channel.ConnectTimeoutException: connection timed out: sns.ap-southeast-2.amazonaws.com/54.240.206.39:443
at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe$1.run(AbstractNioChannel.java:261)
at io.netty.util.concurrent.PromiseTask$RunnableAdapter.call(PromiseTask.java:38)
at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:139)
... 6 common frames omitted

[zoewangg]

ConnectTimeoutException can be thrown when it takes too long to establish a new connection with the service. As you are making cross-region call, I'd recommend increasing connectionTimeout. The default connection timeout is 2 seconds.

https://github.com/aws/aws-sdk-java-v2/blob/master/http-clients/netty-nio-client/src/main/java/software/amazon/awssdk/http/nio/netty/NettyNioAsyncHttpClient.java#L243

[zoewangg]

Just checked the code, ConnectTimeoutException would not get retried in the SDK. We will work on a fix to retry that exception.

Update: ConnectTimeoutException is a subclass of IOException, so it should get retried.

[micah-williamson]

We are also having this problem. We recently upgraded from AWS SDK 1.x to AWS SDK 2.10.1 with the reactive http provider (NettyNioAsyncHttpClient). We didn't see any issues for the first 12 or so hours but then started getting these exceptions in proportion to the number of requests we are making.

We tried the suggestion to change the connectionTimeout but it hasn't resolved the issue.

Here is a chart of our sns requests and exceptions over time-

You can see where we were using the SDK 1.x, when we switched to SDK 2.10.1 with the http client, and when we pushed an update to set the connection timeout to 10s.

Error:

java.util.concurrent.CompletionException: software.amazon.awssdk.core.exception.SdkClientException

Constructing the SdkAsyncHttpClient and SnsAsyncClient-

SdkAsyncHttpClient sdkAsyncHttpClient = NettyNioAsyncHttpClient.builder()
                .connectionTimeout(Duration.ofSeconds(10))
                .build();

SnsAsyncClient snsAsyncClient = SnsAsyncClient.builder()
                .httpClient(sdkAsyncHttpClient)
                .region(Region.US_EAST_1)
                .build();

How we use it-

snsAsyncClient.publish(publishRequest).whenComplete(safeBiConsumer(logger, (publishResponse, error) -> {
            applicationMonitor.getSnsBacklogCounter().decrementAndGet();
            
            if(error != null) {
                applicationMonitor.getSnsExceptionsCounter().incrementAndGet();
                logger.error(error);
            } else {
                applicationMonitor.getSnsSendsCounter().incrementAndGet();
            }
        }));

We could- and should- add a retry here. But the number of exceptions seems high and increases over time.

The SNS topic we are targeting is within the same region.

Edit:

We are going to try upgrading to 2.10.22 and see if that helps. Unfortunately the issue takes several hours to first appear so we won't know if this resolves the issue right away.

[zoewangg]

Hi @iamchairs, could you provide the stacktrace for the exception? If it's Caused by: java.io.IOException: Server failed to send complete response, changing connectionTimeout would not help and upgrading to the latest SDK should resolve the issue.

Hi @iamchairs ,
if your error is java.io.IOException: Server failed to send complete response, maybe you can try to increase connectionMaxIdleTime such as connectionMaxIdleTime(Duration.ofSeconds(5)). I did that and the exception doesn't happen anymore so far.

I set connectionTimeout to try to resolve the io.netty.channel.ConnectTimeoutException: connection timed out error caused by cross region traffic. Now the timeout is 5 seconds and the gut feeling is that the number of this exception is reduced. However I did see 95 exceptions during last weekend. I am thinking to increase the timeout to 10 seconds and see. I didn't notice any of this exception when we send to sns topics in a same region.

by the way @zoewangg can you confirm that sending is retried when connectionTimeout exception happens? I would like to make sure nothing is lost due to this exception. Thank you very much.

[zoewangg]

@WangDanny Apologies for the delayed response. Are you still experiencing the issue?

To answer you question, yes, I confirm that requests failed of ConnectTimeoutException will get retried by default and the default number of max retry is 3.

[debora-ito]

Closing this due to inactivity. Feel free to reopen if you're still experiencing the issue.