You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@camel.apache.org by "Claus Ibsen (Jira)" <ji...@apache.org> on 2021/11/01 12:15:00 UTC

[jira] [Updated] (CAMEL-17156) camel-aws - Cancelling "Extending visibility window" while processing completed causes interruption exception

     [ https://issues.apache.org/jira/browse/CAMEL-17156?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Claus Ibsen updated CAMEL-17156:
--------------------------------
    Summary: camel-aws - Cancelling  "Extending visibility window" while processing completed causes interruption exception  (was: Cancelling  "Extending visibility window" while processing completed causes interruption exception)

> camel-aws - Cancelling  "Extending visibility window" while processing completed causes interruption exception
> --------------------------------------------------------------------------------------------------------------
>
>                 Key: CAMEL-17156
>                 URL: https://issues.apache.org/jira/browse/CAMEL-17156
>             Project: Camel
>          Issue Type: Bug
>          Components: camel-aws2
>    Affects Versions: 3.12.0
>            Reporter: Simon Rasmussen
>            Priority: Minor
>              Labels: sqs
>             Fix For: 3.13.0
>
>
> The issue happens when the Sqs2Consomer has `extendMessageVisibility` enabled. At that point, Sqs2Consumer will create an extend task which is allowed to interrupt running task:
> {code:java}
>  exchange.adapt(ExtendedExchange.class).addOnCompletion(new Synchronization() {
>                     @Override
>                     public void onComplete(Exchange exchange) {
>                         cancelExtender(exchange);
>                     }
>                     @Override
>                     public void onFailure(Exchange exchange) {
>                         cancelExtender(exchange);
>                     }
>                     private void cancelExtender(Exchange exchange) {
>                         // cancel task as we are done
>                         LOG.trace("Processing done so cancelling TimeoutExtender task for exchangeId: {}",
>                                 exchange.getExchangeId());
>                         scheduledFuture.cancel(true);
>                     }
>                 });
> {code}
> This causes below stack trace.
> {code:java}
> 	
> 2021-11-01 08:51:45.970  WARN 10 --- [TimeoutExtender] o.a.c.component.aws2.sqs.Sqs2Consumer    : [] Extending visibility window failed for exchange Exchange[CE30770DB50EE42-0000000000000718]. Will not attempt to extend visibility further. This exception will be ignored.
> software.amazon.awssdk.core.exception.AbortedException: Thread was interrupted
> 	at software.amazon.awssdk.core.exception.AbortedException$BuilderImpl.build(AbortedException.java:84) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.exception.AbortedException.create(AbortedException.java:38) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptTimeoutTrackingStage.handleInterruptedException(ApiCallAttemptTimeoutTrackingStage.java:142) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptTimeoutTrackingStage.translatePipelineException(ApiCallAttemptTimeoutTrackingStage.java:106) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptTimeoutTrackingStage.execute(ApiCallAttemptTimeoutTrackingStage.java:90) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptTimeoutTrackingStage.execute(ApiCallAttemptTimeoutTrackingStage.java:42) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.TimeoutExceptionHandlingStage.execute(TimeoutExceptionHandlingStage.java:78) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.TimeoutExceptionHandlingStage.execute(TimeoutExceptionHandlingStage.java:40) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptMetricCollectionStage.execute(ApiCallAttemptMetricCollectionStage.java:50) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptMetricCollectionStage.execute(ApiCallAttemptMetricCollectionStage.java:36) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.RetryableStage.execute(RetryableStage.java:80) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.RetryableStage.execute(RetryableStage.java:36) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.StreamManagingStage.execute(StreamManagingStage.java:56) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.StreamManagingStage.execute(StreamManagingStage.java:36) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallTimeoutTrackingStage.executeWithTimer(ApiCallTimeoutTrackingStage.java:80) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallTimeoutTrackingStage.execute(ApiCallTimeoutTrackingStage.java:60) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallTimeoutTrackingStage.execute(ApiCallTimeoutTrackingStage.java:42) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallMetricCollectionStage.execute(ApiCallMetricCollectionStage.java:48) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallMetricCollectionStage.execute(ApiCallMetricCollectionStage.java:31) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.ExecutionFailureExceptionReportingStage.execute(ExecutionFailureExceptionReportingStage.java:37) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.ExecutionFailureExceptionReportingStage.execute(ExecutionFailureExceptionReportingStage.java:26) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.AmazonSyncHttpClient$RequestExecutionBuilderImpl.execute(AmazonSyncHttpClient.java:193) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.invoke(BaseSyncClientHandler.java:103) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.doExecute(BaseSyncClientHandler.java:167) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.lambda$execute$1(BaseSyncClientHandler.java:82) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.measureApiCallSuccess(BaseSyncClientHandler.java:175) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.execute(BaseSyncClientHandler.java:76) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.client.handler.SdkSyncClientHandler.execute(SdkSyncClientHandler.java:45) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.awscore.client.handler.AwsSyncClientHandler.execute(AwsSyncClientHandler.java:56) ~[aws-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.services.sqs.DefaultSqsClient.changeMessageVisibility(DefaultSqsClient.java:348) ~[sqs-2.17.42.jar:na]
> 	at org.apache.camel.component.aws2.sqs.Sqs2Consumer$TimeoutExtender.run(Sqs2Consumer.java:381) ~[camel-aws2-sqs-3.12.0.jar:3.12.0]
> 	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[na:na]
> 	at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[na:na]
> 	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[na:na]
> 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[na:na]
> 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[na:na]
> 	at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]
> Caused by: software.amazon.awssdk.core.exception.SdkInterruptedException: null
> 	at software.amazon.awssdk.core.internal.http.InterruptMonitor.checkInterrupted(InterruptMonitor.java:40) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.AfterTransmissionExecutionInterceptorsStage.execute(AfterTransmissionExecutionInterceptorsStage.java:34) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.AfterTransmissionExecutionInterceptorsStage.execute(AfterTransmissionExecutionInterceptorsStage.java:28) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206) ~[sdk-core-2.17.42.jar:na]
> 	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptTimeoutTrackingStage.execute(ApiCallAttemptTimeoutTrackingStage.java:73) ~[sdk-core-2.17.42.jar:na]
> 	... 35 common frames omitted
> {code}
> There are 2 solutions to this:
> 1: Do not interrupt the running task, this will allow the messageExtension request to complete, and no exception is thrown as this is handled gracefully already by catching `ReceiptHandleIsInvalidException`
> 2: Catch the `AbortedException` in `TimeoutExtender#run`.
> I have been testing option #1 for a few hours now, and it seem like an acceptable solution



--
This message was sent by Atlassian Jira
(v8.3.4#803005)