[
https://issues.apache.org/jira/browse/CAMEL-16718?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17363741#comment-17363741
]
Morgan L edited comment on CAMEL-16718 at 6/15/21, 4:17 PM:
------------------------------------------------------------
So, trace logs give some clues when we grep for "Asynchronous callback". Here
is the result when there is no write failure (for example, the first message is
small enough that the write completes before the client 'realizes' the channel
is closed):
{noformat}
TRACE 2021-06-15 12:03:14,514 942
org.apache.camel.impl.engine.DefaultAsyncProcessorAwaitManager [main]
Asynchronous callback received for exchangeId: 88A601D1784658B-0000000000000000
... [main] Asynchronous callback received for exchangeId:
88A601D1784658B-0000000000000001
... [Camel Thread #2 - NettyClientTCPWorker] Asynchronous callback received
for exchangeId: 88A601D1784658B-0000000000000003
... [Camel (camel-1) thread #1 - seda://egress] Asynchronous callback
received, will continue routing exchangeId: 88A601D1784658B-0000000000000003 ->
Exchange[88A601D1784658B-0000000000000003]
... [Camel Thread #2 - NettyClientTCPWorker] Asynchronous callback received
for exchangeId: 88A601D1784658B-0000000000000003
... [Camel Thread #4 - NettyClientTCPWorker] Asynchronous callback received
for exchangeId: 88A601D1784658B-0000000000000005
... [Camel (camel-1) thread #1 - seda://egress] Asynchronous callback
received, will continue routing exchangeId: 88A601D1784658B-0000000000000005 ->
Exchange[88A601D1784658B-0000000000000005]
... [Camel Thread #4 - NettyClientTCPWorker] Asynchronous callback received
for exchangeId: 88A601D1784658B-0000000000000005
{noformat}
This log features two sets of such callbacks, because both messages got routed.
However, here is the result when there is a write failure (i.e. when this bug
occurs):
{noformat}
TRACE 2021-06-15 11:57:50,602 903
org.apache.camel.impl.engine.DefaultAsyncProcessorAwaitManager [main]
Asynchronous callback received for exchangeId: 23D0A193D5CDDE3-0000000000000000
... [main] Asynchronous callback received for exchangeId:
23D0A193D5CDDE3-0000000000000001
... [Camel (camel-1) thread #1 - seda://egress] Asynchronous callback
received for exchangeId: 23D0A193D5CDDE3-0000000000000002
{noformat}
As you can see, the asynchronous callback which causes routing to continue is
never invoked.
was (Author: morgan l):
So, trace logs give some clues when we grep for "Asynchronous callback". Here
is the result when there is no write failure (for example, the first message is
small enough that the write completes before the client 'realizes' the channel
is closed):
{noformat}
TRACE 2021-06-15 12:03:14,514 942
org.apache.camel.impl.engine.DefaultAsyncProcessorAwaitManager [main]
Asynchronous callback received for exchangeId: 88A601D1784658B-0000000000000000
... [main] Asynchronous callback received for exchangeId:
88A601D1784658B-0000000000000001
... [Camel Thread #2 - NettyClientTCPWorker] Asynchronous callback received
for exchangeId: 88A601D1784658B-0000000000000003
... [Camel (camel-1) thread #1 - seda://egress] Asynchronous callback
received, will continue routing exchangeId: 88A601D1784658B-0000000000000003 ->
Exchange[88A601D1784658B-0000000000000003]
... [Camel Thread #2 - NettyClientTCPWorker] Asynchronous callback received
for exchangeId: 88A601D1784658B-0000000000000003
... [Camel Thread #4 - NettyClientTCPWorker] Asynchronous callback received
for exchangeId: 88A601D1784658B-0000000000000005
... [Camel (camel-1) thread #1 - seda://egress] Asynchronous callback
received, will continue routing exchangeId: 88A601D1784658B-0000000000000005 ->
Exchange[88A601D1784658B-0000000000000005]
... [Camel Thread #4 - NettyClientTCPWorker] Asynchronous callback received
for exchangeId: 88A601D1784658B-0000000000000005
{noformat}
However, here is the result when there is a write failure (i.e. when this bug
occurs):
{noformat}
TRACE 2021-06-15 11:57:50,602 903
org.apache.camel.impl.engine.DefaultAsyncProcessorAwaitManager [main]
Asynchronous callback received for exchangeId: 23D0A193D5CDDE3-0000000000000000
... [main] Asynchronous callback received for exchangeId:
23D0A193D5CDDE3-0000000000000001
... [Camel (camel-1) thread #1 - seda://egress] Asynchronous callback
received for exchangeId: 23D0A193D5CDDE3-0000000000000002
{noformat}
As you can see, the asynchronous callback which causes routing to continue is
never invoked.
> Conflict with Netty TCP + Resilience4J circuit breaker
> ------------------------------------------------------
>
> Key: CAMEL-16718
> URL: https://issues.apache.org/jira/browse/CAMEL-16718
> Project: Camel
> Issue Type: Bug
> Components: camel-netty
> Affects Versions: 3.7.4, 3.10.0
> Reporter: Morgan L
> Assignee: Claus Ibsen
> Priority: Major
> Fix For: 3.11.0
>
> Attachments: sample-camel - broketcpserver.log.txt, sample-camel -
> nettytest.log.txt, sample-camel.zip
>
>
> My team has found what we believe is a conflict between the Netty TCP
> producer and the Resilience4J circuit breaker, under specific circumstances.
> When the Netty TCP client encounters an error while writing to the server
> (for us, usually a broken pipe exception), if it is inside a circuit breaker,
> the route will hang indefinitely.
> Discussion on Zulip: [Conflict with Netty TCP + Resilience4J circuit
> breaker|https://camel.zulipchat.com/#narrow/stream/257298-camel/topic/Conflict.20with.20Netty.20TCP.20.2B.20Resilience4J.20circuit.20breaker]
> A zipped version of the complete test project is attached. It should allow
> you to reproduce the issue.
> By running BrokeTCPServer.main(), and then invoking
> NettyTest.testNettyCircuitBreaker(), you should see that of the two messages
> we push into the queue, only one is processed. Only one connection is
> initiated to the BrokeTCPServer.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
