[ 
https://issues.apache.org/jira/browse/PROTON-2900?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18008057#comment-18008057
 ] 

Marco Geri commented on PROTON-2900:
------------------------------------

After enabling the log level to {{{}TRACE{}}}, I noticed that as soon as the 
application starts and begins using ProtonJ2, the first idle check is scheduled 
after 10 seconds.

Immediately after, the application opens the connection and receives an 
{{idleTimeout}} of 5 seconds from the server. However, the idle check is not 
rescheduled accordingly, so it still triggers after 10 seconds.
As a result, the client doesn't detect the server's idle timeout in time, and 
Broker-J disconnects the client due to inactivity.

Below is a relevant excerpt from the logs:

2025-07-18 14:11:53 [ClientConnection 
:(ID:17d61cf3-2af8-41fa-9ae1-97482ae06863:1:1): I/O Thread] TRACE 
org.apache.qpid.protonj2.engine.impl.ProtonEngine - Auto Idle Timeout Check 
being initiated
2025-07-18 *14:11:53* [ClientConnection 
:(ID:17d61cf3-2af8-41fa-9ae1-97482ae06863:1:1): I/O Thread] TRACE 
org.apache.qpid.protonj2.engine.impl.ProtonEngine - IdleTimeoutCheck 
rescheduling with delay: *10000*

... (after opening the connection, we receive the AMPQ Open frame response from 
BrokerJ)
2025-07-18 *14:11:53* [ClientConnection 
:(ID:17d61cf3-2af8-41fa-9ae1-97482ae06863:1:1): I/O Thread] TRACE 
org.apache.qpid.protonj2.engine.impl.ProtonFrameLoggingHandler - <- 
AMQP:[1160649162:0] Open{ containerId='21a05bf2-0953-4317-9095-d8b77408472a', 
hostname='null', maxFrameSize=65536, channelMax=255, idleTimeOut={*}5000{*}, 
outgoingLocales=null, incomingLocales=null, 
offeredCapabilities=[ANONYMOUS-RELAY, SHARED-SUBS, 
sole-connection-for-container], desiredCapabilities=null, 
properties=\{product=Apache Qpid Broker-J Core, version=9.2.1, 
qpid.build=63289b4d1cf001e1fc3d4b0e2e4dce64d8997241, qpid.instance_name=Broker, 
qpid.virtualhost_properties_supported=true}}

... (the Idle check runs after 10 seconds, and try to reschedule it considering 
the IdleTimeOut received by BrokerJ, but it's too late and BrokerJ disconnects 
it for inactivity)
2025-07-18 *14:12:03* [ClientConnection 
:(ID:17d61cf3-2af8-41fa-9ae1-97482ae06863:1:1): I/O Thread] TRACE 
org.apache.qpid.protonj2.engine.impl.ProtonEngine - IdleTimeoutCheck 
rescheduling with delay: *1250*
2025-07-18 14:12:03 [ClientConnection 
:(ID:17d61cf3-2af8-41fa-9ae1-97482ae06863:1:1): I/O Thread] TRACE 
org.apache.qpid.protonj2.client.transport.netty4.TcpTransport - Transport 
indicates connection failure! Channel is [id: 0x1ba3d764, L:/127.0.0.1:41548 ! 
R:localhost/127.0.0.1:5672]
2025-07-18 *14:12:03* [ClientConnection 
:(ID:17d61cf3-2af8-41fa-9ae1-97482ae06863:1:1): I/O Thread] DEBUG 
org.apache.qpid.protonj2.client.impl.ClientTransportListener - *Transport 
failed: Remote closed connection unexpectedly*


Hope this helps.

> `IdleTimeoutCheck` not rescheduled after broker's AMQP Open frame, causing 
> premature connection closure
> -------------------------------------------------------------------------------------------------------
>
>                 Key: PROTON-2900
>                 URL: https://issues.apache.org/jira/browse/PROTON-2900
>             Project: Qpid Proton
>          Issue Type: Bug
>          Components: protonj2
>    Affects Versions: protonj2-1.0.0-M23
>            Reporter: Marco Geri
>            Assignee: Timothy A. Bish
>            Priority: Major
>
> While testing with BrokerJ 9.2.1 with AMQP 1.0 protocol, I configured the 
> broker to request heartbeats every 5 seconds using the setting 
> {{{}qpid.port.heartbeatDelay=5{}}}.
> However, even with a simple login test (without sending any other messages), 
> the connection is closed by the broker after 10 seconds due to inactivity. It 
> appears that the client library does not send any idle (heartbeat) frames 
> during this time.
> After a quick debugging session, it seems that the {{IdleTimeoutCheck}} in 
> the {{ProtonEngine}} is scheduled immediately with a timeout of 10 seconds, 
> before the AMQP Open frame from the broker is received. The Open frame from 
> the broker specifies a 5-second idle timeout, but the {{IdleTimeoutCheck}} is 
> *not* rescheduled after this frame is processed.
> As a result, the client does not send heartbeat frames within the expected 
> timeframe, and the broker closes the connection due to inactivity.
> *Note:* I ran the test using BrokerJ version 9.2.1, which includes a fix for 
> the {{heartbeatDelay}} parameter (see QPID-8680).



--
This message was sent by Atlassian Jira
(v8.20.10#820010)

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@qpid.apache.org
For additional commands, e-mail: dev-h...@qpid.apache.org

Reply via email to