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
