[
https://issues.apache.org/jira/browse/CAMEL-16718?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17363636#comment-17363636
]
Morgan L commented on CAMEL-16718:
----------------------------------
One additional note: this issue does also occur with the
camel-microprofile-fault-tolerance circuit breaker, at least on 3.10.0.
Claus,
I was not able to pinpoint where a thread was hanging. Attached are logs from
my run of the tests, out of the box and unchanged. Snippets edited for
readability:
[^sample-camel - nettytest.log.txt]
{noformat}
INFO 2021-06-15 09:09:57,617 0 org.apache.camel.test.junit4.CamelTestSupport
[main]
********************************************************************************
INFO 2021-06-15 09:09:57,618 1 org.apache.camel.test.junit4.CamelTestSupport
[main] Testing: testNettyCircuitBreaker(com.peraton.camel.NettyTest)
INFO 2021-06-15 09:09:57,618 1 org.apache.camel.test.junit4.CamelTestSupport
[main]
********************************************************************************
INFO 2021-06-15 09:09:57,665 48 org.apache.camel.support.LRUCacheFactory [main]
Detected and using LRUCacheFactory: camel-caffeine-lrucache
INFO 2021-06-15 09:09:57,932 315 org.apache.camel.component.seda.SedaEndpoint
[main] Endpoint seda://egress is using shared queue: seda://egress with size:
1000
INFO 2021-06-15 09:09:58,026 409
org.apache.camel.impl.engine.AbstractCamelContext [main] Apache Camel 3.7.3
(camel-1) is starting
INFO 2021-06-15 09:09:58,049 432
org.apache.camel.component.netty.NettyComponent [main] Creating shared
NettyConsumerExecutorGroup with 17 threads
INFO 2021-06-15 09:09:58,604 987
org.apache.camel.impl.engine.InternalRouteStartupManager [main] Route: route1
started and consuming from: seda://egress
INFO 2021-06-15 09:09:58,605 988
org.apache.camel.impl.engine.AbstractCamelContext [main] Total 1 routes, of
which 1 are started
INFO 2021-06-15 09:09:58,605 988
org.apache.camel.impl.engine.AbstractCamelContext [main] Apache Camel 3.7.3
(camel-1) started in 579ms
INFO 2021-06-15 09:09:58,624 1007 org.apache.camel.component.mock.MockEndpoint
[main] Asserting: mock://result is satisfied
INFO 2021-06-15 09:09:59,621 2004 route1 [Camel (camel-1) thread #1 -
seda://egress] Sending message: 8ACB67D83234BDE-0000000000000003.
WARN 2021-06-15 09:10:08,627 11010 org.apache.camel.component.mock.MockEndpoint
[main] The latch did not reach 0 within the specified time
INFO 2021-06-15 09:10:08,627 11010
org.apache.camel.test.junit4.CamelTestSupport [main]
********************************************************************************
INFO 2021-06-15 09:10:08,627 11010
org.apache.camel.test.junit4.CamelTestSupport [main] Testing done:
testNettyCircuitBreaker(com.peraton.camel.NettyTest)
INFO 2021-06-15 09:10:08,627 11010
org.apache.camel.test.junit4.CamelTestSupport [main] Took: 10s21ms (10021
millis)
INFO 2021-06-15 09:10:08,627 11010
org.apache.camel.test.junit4.CamelTestSupport [main]
********************************************************************************
INFO 2021-06-15 09:10:08,634 11017
org.apache.camel.impl.engine.AbstractCamelContext [main] Apache Camel 3.7.3
(camel-1) is shutting down
INFO 2021-06-15 09:10:08,634 11017
org.apache.camel.impl.engine.DefaultShutdownStrategy [main] Starting to
graceful shutdown 1 routes (timeout 10 seconds)
INFO 2021-06-15 09:10:08,637 11020
org.apache.camel.impl.engine.DefaultShutdownStrategy [Camel (camel-1) thread #3
- ShutdownTask] Waiting as there are still 2 inflight and pending exchanges to
complete, timeout in 10 seconds. Inflights per route: [route1 = 2]
...
INFO 2021-06-15 09:10:17,643 20026
org.apache.camel.impl.engine.DefaultShutdownStrategy [Camel (camel-1) thread #3
- ShutdownTask] Waiting as there are still 2 inflight and pending exchanges to
complete, timeout in 1 seconds. Inflights per route: [route1 = 2]
WARN 2021-06-15 09:10:18,638 21021
org.apache.camel.impl.engine.DefaultShutdownStrategy [main] Timeout occurred
during graceful shutdown. Forcing the routes to be shutdown now. Notice: some
resources may still be running as graceful shutdown did not complete
successfully.
WARN 2021-06-15 09:10:18,638 21021
org.apache.camel.impl.engine.DefaultShutdownStrategy [Camel (camel-1) thread #3
- ShutdownTask] Interrupted while waiting during graceful shutdown, will force
shutdown now.
WARN 2021-06-15 09:10:18,658 21041 org.apache.camel.component.seda.SedaConsumer
[Camel (camel-1) thread #1 - seda://egress] Error processing exchange.
Exchange[]. Caused by: [java.util.concurrent.RejectedExecutionException - Run
not allowed as ShutdownStrategy is forcing shutting down, will reject
executing exchange: Exchange[8ACB67D83234BDE-0000000000000002]]
java.util.concurrent.RejectedExecutionException: Run not allowed as
ShutdownStrategy is forcing shutting down, will reject executing exchange:
Exchange[8ACB67D83234BDE-0000000000000002]
at
org.apache.camel.impl.engine.CamelInternalProcessor.process(CamelInternalProcessor.java:249)
...
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
INFO 2021-06-15 09:10:18,660 21043
org.apache.camel.impl.engine.DefaultShutdownStrategy [Camel (camel-1) thread #3
- ShutdownTask] Route: route1 shutdown complete, was consuming from:
seda://egress
INFO 2021-06-15 09:10:18,660 21043
org.apache.camel.impl.engine.DefaultShutdownStrategy [main] Graceful shutdown
of 1 routes completed in 10s26ms
INFO 2021-06-15 09:10:18,679 21062
org.apache.camel.impl.engine.AbstractCamelContext [main] Apache Camel 3.7.3
(camel-1) uptime 20s653ms
INFO 2021-06-15 09:10:18,679 21062
org.apache.camel.impl.engine.AbstractCamelContext [main] Apache Camel 3.7.3
(camel-1) is shutdown in 10s45ms
java.lang.AssertionError: mock://result Received message count. Expected: <1>
but was: <0>
Expected :<1>
Actual :<0>
<Click to see difference>
at
org.apache.camel.component.mock.MockEndpoint.fail(MockEndpoint.java:1762)
...
at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:58)Process
finished with exit code -1{noformat}
[^sample-camel - broketcpserver.log.txt]
{noformat}
INFO 2021-06-15 09:09:51,777 0 com.peraton.camel.BrokeTCPServer [main] Starting
broken server on port 6666
INFO 2021-06-15 09:10:00,405 8628 com.peraton.camel.BrokeTCPServer [Thread-0]
Connection #1 accepted. Closing...{noformat}
Analyzing the trace-level logs on the actual application showed that some
asynchronous callbacks were not being released, which is needed to continue
routing. I will post more information on this as soon as I can.
> 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)
