netty requestTimeout issue still present

["Shuker, Carl" <Ca...@anz.com.INVALID>]

Hello team

I have trawled through what I could and this Jira appears to be related: https://issues.apache.org/jira/browse/CAMEL-15195

When using the netty producer configuration option requestTimeout, with the latest 3.13.0 version, we are seeing disconnections occur after successful responses have been handled.

Removing the requestTimeout from the options solves the disconnection problem but causes our application to critically degrade when we fail to get responses.

We were originally using camel version 2.23.2 (using the netty4 component at the time) and were not having any issue with the timeout, this only started to occur after upgrading to version 2.25.4, at which point I migrated to the latest 3.13.0 after seeing that above Jira was marked as resolved in a later version.

I enabled trace logging on the NettyProducer and can see that the changes that were related to that Jira are being triggered but an exception is being thrown that appears to still be related to the timeout handling.

This occurs for both our TCP and HTTP netty configurations, our tcp config for example:

.toF("netty:%s?sync=true&decoders=#isoDecoder&encoders=#isoEncoder&ssl=true&sslContextParameters=#sslContextParameters&requestTimeout=%d", remoteAddress, requestTimeout)

Stack trace to follow.

Help appreciated
Carl

Stacktrace:

>>>

T17:19:33,920 DEBUG OrchestratorStation        Sending AS2805 MTI=0800 k=800004001120617193359585705554 DE11=004001 DE70=Logon to remote tcp://localhost:9000
T17:19:33,922 TRACE NettyProducer              Pool[active=0, idle=0]
T17:19:34,007 DEBUG NettyProducer              Created new TCP client bootstrap connecting to localhost:9000 with options: Bootstrap(BootstrapConfig(group: NioEventLoopGroup, channelFactory: ReflectiveChannelFactory(NioSocketChannel.class), options: {SO_KEEPALIVE=true, CONNECT_TIMEOUT_MILLIS=10000, SO_REUSEADDR=true, TCP_NODELAY=true}, handler: org.apache.camel.component.netty.DefaultClientInitializerFactory@5c559d48, resolver: io.netty.resolver.DefaultAddressResolverGroup@5c4735d0))
T17:19:34,009 TRACE NettyProducer              Requested channel: AbstractBootstrap$PendingRegistrationPromise@7572605b(incomplete)
T17:19:34,009 TRACE NettyProducer              activateObject channel request: AbstractBootstrap$PendingRegistrationPromise@7572605b(incomplete)
T17:19:34,009 TRACE NettyProducer              Validating connecting channel request: AbstractBootstrap$PendingRegistrationPromise@7572605b(incomplete) -> true
T17:19:34,010 TRACE NettyProducer              Got channel request from pool AbstractBootstrap$PendingRegistrationPromise@7572605b(incomplete)
T17:19:34,051 TRACE NettyProducer              Channel open finished with AbstractBootstrap$PendingRegistrationPromise@7572605b(success)
T17:19:34,052 DEBUG NettyProducer              Creating connector to address: localhost:9000
T17:19:34,054 DEBUG NettyProducer              Channel: [id: 0xccb5f3f2, L:/127.0.0.1:53272 - R:localhost/127.0.0.1:9000] writing body: AS2805NetworkManagement0800Message[    0800 004001]
T17:19:34,137 TRACE NettyProducer              Channel open: [id: 0xccb5f3f2, L:/127.0.0.1:53272 - R:localhost/127.0.0.1:9000]
T17:19:34,704 TRACE NettyProducer              Operation complete DefaultChannelPromise@200d3948(success)
T17:19:34,716 TRACE NettyProducer              Message received: AS2805NetworkManagement0810Message[    0810 004001]
T17:19:34,717 TRACE NettyProducer              Removing timeout channel as we received message
T17:19:34,717 DEBUG NettyProducer              Channel: [id: 0xccb5f3f2, L:/127.0.0.1:53272 - R:localhost/127.0.0.1:9000] received body: AS2805NetworkManagement0810Message[    0810 004001]
T17:19:34,719 TRACE NettyProducer              Putting channel back to pool [id: 0xccb5f3f2, L:/127.0.0.1:53272 - R:localhost/127.0.0.1:9000]
T17:19:34,719 TRACE NettyProducer              passivateObject channel request: AbstractBootstrap$PendingRegistrationPromise@7572605b(success)
T17:19:34,758 DEBUG OrchestratorStation        Received     0810 004001 response code 00
T17:19:34,762  INFO OrchestratorStation        Station local online
T17:19:59,397 TRACE NettyProducer              activateObject channel request: AbstractBootstrap$PendingRegistrationPromise@7572605b(success)
T17:19:59,397 TRACE NettyProducer              reset the request timeout as we activate the channel
T17:19:59,398 TRACE NettyProducer              Validating channel: [id: 0xccb5f3f2, L:/127.0.0.1:53272 - R:localhost/127.0.0.1:9000] -> true
T17:19:59,398 TRACE NettyProducer              passivateObject channel request: AbstractBootstrap$PendingRegistrationPromise@7572605b(success)
T17:20:06,404 TRACE NettyProducer              Exception caught at Channel: [id: 0xccb5f3f2, L:/127.0.0.1:53272 - R:localhost/127.0.0.1:9000]
io.netty.handler.timeout.ReadTimeoutException: null
T17:20:06,404 DEBUG NettyProducer              Closing channel as an exception was thrown from Netty
io.netty.handler.timeout.ReadTimeoutException: null
T17:20:06,413 TRACE NettyProducer              Channel closed: [id: 0xccb5f3f2, L:/127.0.0.1:53272 ! R:localhost/127.0.0.1:9000]
This e-mail and any attachments to it (the "Communication") is, unless otherwise stated, confidential, may contain copyright material and is for the use only of the intended recipient. If you receive the Communication in error, please notify the sender immediately by return e-mail, delete the Communication and the return e-mail, and do not read, copy, retransmit or otherwise deal with it. Any views expressed in the Communication are those of the individual sender only, unless expressly stated to be those of Australia and New Zealand Banking Group Limited ABN 11 005 357 522, or any of its related entities including ANZ Bank New Zealand Limited (together "ANZ"). ANZ does not accept liability in connection with the integrity of or errors in the Communication, computer virus, data corruption, interference or delay arising from or in respect of the Communication.