Hi Yeah that may seem a bit weird too. Lets create a JIRA and investigate
On Fri, Jun 12, 2020 at 10:07 AM Zheng Feng <zf...@redhat.com> wrote: > > It seems related to https://issues.apache.org/jira/browse/CAMEL-14363. I > just checked the PR [1] > and it looks a little bit strange to delete the codes which remove the > timeout handler after receiving a response. > > [1] https://github.com/apache/camel/pull/3460 > > On Fri, Jun 12, 2020 at 3:38 PM Claus Ibsen <claus.ib...@gmail.com> wrote: > > > Hi > > > > It smells like a bug, you are welcome to create a JIRA and if you can > > work on an unit test we can use as reproducer. > > Also check the existing timeout tests in camel-netty. > > > > > > On Wed, Jun 10, 2020 at 7:54 PM Vincenzo Galluccio > > <vincenzo.gallucci...@gmail.com> wrote: > > > > > > Hello, > > > > > > I'm having a problem with Camel-Netty component version 3.3.0 when > > > using the requestTimeout option, which is causing the request to > > > always timeout even when a response is received on time. > > > The ReadTimeoutException should only be triggered if a response is not > > > received on time. > > > > > > I have a Netty Producer Endpoint, in a Route, configured with > > > requestTimeout set to 10000 ms, as follows: > > > > > > ``` > > > @Component > > > public class TransactionsRoute extends RouteBuilder { > > > > > > @Override > > > public void configure() { > > > > > > from("direct:startRoute") > > > > > .to(netty:tcp://localhost:9999?sync=true&encoders=#encoders&decoders=#decoders&requestTimeout=10000); > > > } > > > } > > > ``` > > > > > > See logs below which show that a request is sent at 15:20:10.996 and > > > response is received at 15:20:11.256, and the exception is triggered > > > at 15:20:21.260, which is 10 seconds after the response is received > > > (note: requestTimeout set to 10000 ms): > > > > > > ``` > > > 2020-06-10 15:20:10.996 TRACE 29616 --- [ClientTCPWorker] > > > o.a.camel.component.netty.NettyProducer : Channel open finished with > > > AbstractBootstrap$PendingRegistrationPromise@347574(success) > > > 2020-06-10 15:20:10.996 DEBUG 29616 --- [ClientTCPWorker] > > > o.a.camel.component.netty.NettyProducer : Creating connector to > > > address: localhost:9999 > > > 2020-06-10 15:20:10.996 DEBUG 29616 --- [ClientTCPWorker] > > > o.a.camel.component.netty.NettyProducer : Channel: [id: 0x4fd36b4a, > > > L:/127.0.0.1:63714 - R:localhost/127.0.0.1:9999] writing body: [...] > > > 2020-06-10 15:20:11.000 TRACE 29616 --- [ClientTCPWorker] > > > o.a.camel.component.netty.NettyProducer : Channel open: [id: > > > 0x4fd36b4a, L:/127.0.0.1:63714 - R:localhost/127.0.0.1:9999] > > > 2020-06-10 15:20:11.252 TRACE 29616 --- [ClientTCPWorker] > > > o.a.camel.component.netty.NettyProducer : Operation complete > > > DefaultChannelPromise@1f64970(success) > > > 2020-06-10 15:20:11.256 TRACE 29616 --- [ClientTCPWorker] > > > o.a.camel.component.netty.NettyProducer : Message received: [ ... ] > > > 2020-06-10 15:20:11.256 DEBUG 29616 --- [ClientTCPWorker] > > > o.a.camel.component.netty.NettyProducer : Channel: [id: 0x4fd36b4a, > > > L:/127.0.0.1:63714 - R:localhost/127.0.0.1:9999] received body: [...] > > > 2020-06-10 15:20:11.256 TRACE 29616 --- [ClientTCPWorker] > > > o.a.camel.component.netty.NettyProducer : Putting channel back to > > > pool [id: 0x4fd36b4a, L:/127.0.0.1:63714 - R:localhost/127.0.0.1:9999] > > > 2020-06-10 15:20:11.256 TRACE 29616 --- [ClientTCPWorker] > > > o.a.camel.component.netty.NettyProducer : passivateObject channel > > > request: AbstractBootstrap$PendingRegistrationPromise@347574(success) > > > > > > 2020-06-10 15:20:21.260 TRACE 29616 --- [ClientTCPWorker] > > > o.a.camel.component.netty.NettyProducer : Exception caught at > > > Channel: [id: 0x4fd36b4a, L:/127.0.0.1:63714 - > > > R:localhost/127.0.0.1:9999] > > > > > > io.netty.handler.timeout.ReadTimeoutException: null > > > > > > 2020-06-10 15:20:21.260 DEBUG 29616 --- [ClientTCPWorker] > > > o.a.camel.component.netty.NettyProducer : Closing channel as an > > > exception was thrown from Netty > > > > > > io.netty.handler.timeout.ReadTimeoutException: null > > > > > > 2020-06-10 15:20:21.261 TRACE 29616 --- [ClientTCPWorker] > > > o.a.camel.component.netty.NettyHelper : Channel closed: [id: > > > 0x4fd36b4a, L:/127.0.0.1:63714 ! R:localhost/127.0.0.1:9999] > > > 2020-06-10 15:20:21.261 TRACE 29616 --- [ClientTCPWorker] > > > o.a.camel.component.netty.NettyProducer : Invalidating channel from > > > pool [id: 0x4fd36b4a, L:/127.0.0.1:63714 ! R:localhost/127.0.0.1:9999] > > > 2020-06-10 15:20:21.261 TRACE 29616 --- [ClientTCPWorker] > > > o.a.camel.component.netty.NettyProducer : Destroying channel request: > > > AbstractBootstrap$PendingRegistrationPromise@347574(success) > > > 2020-06-10 15:20:21.261 WARN 29616 --- [ClientTCPWorker] > > > o.a.c.p.e.RedeliveryErrorHandler : Cannot determine current > > > route from Exchange with id: ID-WPU8L0058708-1591795167006-0-2, will > > > fallback and use first error handler. > > > 2020-06-10 15:20:21.261 TRACE 29616 --- [ClientTCPWorker] > > > o.a.camel.component.netty.NettyProducer : Channel closed: [id: > > > 0x4fd36b4a, L:/127.0.0.1:63714 ! R:localhost/127.0.0.1:9999] > > > ``` > > > > > > > > > This seems like a bug to me, but I wanted to send an email first to > > > fetch your feedback. > > > > > > Thanks in advance for your support. > > > > > > Kind Regards, > > > Vincenzo Galluccio > > > > > > > > -- > > Claus Ibsen > > ----------------- > > http://davsclaus.com @davsclaus > > Camel in Action 2: https://www.manning.com/ibsen2 > > > > -- Claus Ibsen ----------------- http://davsclaus.com @davsclaus Camel in Action 2: https://www.manning.com/ibsen2
