[
https://issues.apache.org/jira/browse/CAMEL-25809?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Claus Ibsen updated CAMEL-25809:
--------------------------------
Fix Version/s: 4.24.0
> camel-aws2-sqs - with extendMessageVisibility=true and maxMessagesPerPoll >
> 10, the first extension can come after the visibility timeout ran out when
> the poll waited for a long-polling receive
> -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: CAMEL-25809
> URL: https://issues.apache.org/jira/browse/CAMEL-25809
> Project: Camel
> Issue Type: Bug
> Components: camel-aws2
> Reporter: shashank
> Assignee: shashank
> Priority: Major
> Fix For: 4.24.0
>
>
> With {{extendMessageVisibility=true}} the SQS consumer keeps the messages it
> processes invisible: its {{TimeoutExtender}} runs every {{max(1,
> visibilityTimeout / 2)}} seconds and extends a message whose deadline falls
> before its next run. The deadline is 80 % of {{visibilityTimeout}} counted
> from the moment the message is registered with the extender, at the start of
> {{processBatch}} (since CAMEL-25700; {{Sqs2Consumer}} lines 142-147 and 532
> on main 62c9a3ebe409). SQS counts the visibility timeout from the receive.
> Normally the two are milliseconds apart. Not when a poll sends several
> receive requests: with {{maxMessagesPerPoll}} greater than 10,
> {{PollingTask}} sends one {{ReceiveMessage}} per 10 messages concurrently and
> joins them ({{CompletableFuture.get}}), so the batch starts only when the
> last request returned. With long polling ({{waitTimeSeconds}}), a request
> that finds no more messages waits up to {{waitTimeSeconds}}, while the
> messages returned by the first request are already counting down.
> With a gap L between the receive and the start of the batch, the first
> extension comes between {{L + 0.3 x visibilityTimeout}} and {{L + 0.8 x
> visibilityTimeout}} after the receive (depending on the phase of the
> extender). It is late as soon as L is more than about 20 % of
> {{visibilityTimeout}}:
> ||visibilityTimeout||waitTimeSeconds (gap L)||first extension after the
> receive||late for||
> |30|20|29 to 44 s|14 of 15 phases|
> |30|10|19 to 34 s|4 of 15 phases|
> |60|20|38 to 68 s|8 of 30 phases|
> |10|5|8 to 13 s|3 of 5 phases|
> A late message becomes visible again while the route still processes it, and
> another consumer (another instance, or {{concurrentConsumers}} > 1) receives
> it: it is processed twice, which is what {{extendMessageVisibility}} is for.
> The extender's {{ChangeMessageVisibility}} then fails ({{MessageNotInflight}}
> / {{ReceiptHandleIsInvalid}}) and is only logged. This was noted as a
> follow-up in the review of CAMEL-25700 (apache/camel#27985).
> Trigger: {{extendMessageVisibility=true}}, {{maxMessagesPerPoll}} > 10, long
> polling with {{waitTimeSeconds}} (or the queue's
> {{ReceiveMessageWaitTimeSeconds}}) above about 20 % of {{visibilityTimeout}},
> and a queue that does not fill every receive request of a poll at once (a
> quiet or moderately busy queue). With the default {{maxMessagesPerPoll}}, or
> without long polling, the gap stays small and nothing changes.
> *Fix*: the messages of a poll are dated from the start of the poll (which is
> never after their receive), and when one of them is due before the next
> scheduled run of the extender, the extender runs at once (on its own single
> thread, so it does not overlap a scheduled run). Extensions after the first
> are unchanged. Cost: with long polling, one extra
> {{ChangeMessageVisibilityBatch}} call for a batch whose poll waited long.
> *Tests*: new {{SqsConsumerExtendMessageVisibilityLongPollTest}} with the
> module's {{AmazonSQSClientMock}} (no AWS):
> {{maxMessagesPerPoll=20&visibilityTimeout=4&extendMessageVisibility=true}},
> one request of the poll returns the message at once, the other waits 3 s (a
> long poll on a queue with no more messages), the route holds the message
> until it was extended. It asserts that the first
> {{ChangeMessageVisibilityBatch}} for the message comes less than 4 s after
> its receive. On main it fails: {{Expecting actual: 4995L to be less than:
> 4000L}} (4998 ms on the reruns). With the fix it passes; camel-aws2-sqs unit
> tests: 78 run, 0 failures.
> *How it was found*: a Z3 model of the extension schedule vs the visibility
> window (period {{max(1, V/2)}} s, deadline registration + 0.8 V, gap L
> between receive and registration): no counterexample for L = 0, a late first
> extension once L exceeds about 0.2 V; then the JUnit test above.
> *Affected*: main, camel-4.23.x, camel-4.22.x and camel-4.18.x (same deadline,
> period and concurrent receive requests; on those branches without CAMEL-25700
> a message is registered only when its turn in the batch comes, so the gap is
> larger; read, not run).
> _Filed with Claude Code on behalf of allthingssecurity._
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
