Details
-
Bug
-
Status: Open
-
Critical
-
Resolution: Unresolved
-
5.15.9, 5.15.10
-
None
-
None
-
ActiveMQ version: 5.15.10 or 5.15.9
ActiveMQ configuration: default
Client: C# running in Docker container
Transport: nio+ssl
Description
Problem Overview
We recently encountered an issue where a significant delay (often up to 20 seconds) occurs between the time a message is acknowledged by a consumer and the time the next message is received from the broker. This issue only manifests itself until fairly specific conditions, but we do have a reproducible case. The problem occurs when the broker transport `nio+ssl` is used and clients are running in Docker containers. ActiveMQ versions tested are 5.15.9 and 5.15.10. Default ActiveMQ broker configuration can be used (with the exception of the nio+ssl transport). Disabling either nio or ssl in the broker configuration prevents this issue from occurring. Producing messages to the broker is not impacted whatsoever, this is strictly an issue for consumers.
Using Wireshark, we analyzed all ingress and egress traffic from the Docker network while the consumer was running. This analysis revealed that there are in fact long periods of no activity on the network, despite the fact that the client immediately acknowledges the message and is ready to receive a new one.
In addition to a long delay between a message being acknowledged and the next message being received, the initial connection to the broker takes upwards of 15 seconds. This is not the case if either nio or ssl is disabled (e.g. transport is just 'nio' or just 'ssl' works fine). Enabling verbose logging on the broker has not yet yielded any useful information, but we are continuing our investigation.
Expected results (can be achieved by disabling nio transport):
Sending 500 messages to the broker and then consuming them all is completed in ~2.5 seconds
Receive timestamps (see currentTime):
Received Queue 1 0 - currentTime: 972 msgId: 67ddfe5f-023c-4090-9d1c-ac60160947cc, msgTimeStamp: 11/14/2019 20:10:29
Received Queue 1 1 - currentTime: 981 msgId: 803fdea7-546f-4a80-ad3b-ad6c89669fbc, msgTimeStamp: 11/14/2019 20:10:29
Received Queue 1 2 - currentTime: 983 msgId: dbccb3c6-4f3f-4ce5-97d8-d77a41e46561, msgTimeStamp: 11/14/2019 20:10:29
Received Queue 1 3 - currentTime: 984 msgId: 65c550aa-1260-4e3f-9d7c-d51a62f4a3d0, msgTimeStamp: 11/14/2019 20:10:29
Received Queue 1 4 - currentTime: 986 msgId: 725064b8-c796-429c-bd98-a48a15913d81, msgTimeStamp: 11/14/2019 20:10:29
Received Queue 1 5 - currentTime: 988 msgId: a7335557-c564-4bb0-984e-7d87fde6646e, msgTimeStamp: 11/14/2019 20:10:29
Actual results:
Connection takes ~15 seconds
Producing 500 messages takes < 1 second, as expected
Consumption of messages is delayed, alternates back and forth between ~10 seconds and ~20 seconds between ack time and next message being received.
Receive timestamps (see currentTime):
Received Queue 1 0 - currentTime: 60961 msgId: 370d03c9-8f00-4e49-b38d-3fa1ec4a0b3e, msgTimeStamp: 11/14/2019 20:13:06
Received Queue 1 1 - currentTime: 80741 msgId: 93f1f217-7be4-4a8e-a7a6-7edde541d260, msgTimeStamp: 11/14/2019 20:13:26
Received Queue 1 2 - currentTime: 90886 msgId: 23919310-a1f3-4891-98c3-886e64639eb4, msgTimeStamp: 11/14/2019 20:13:36
Received Queue 1 3 - currentTime: 110731 msgId: cb2bdc40-a146-4f47-8ad9-efd15e411ce5, msgTimeStamp: 11/14/2019 20:13:56
Received Queue 1 4 - currentTime: 120933 msgId: b241ac14-3573-40ef-a611-5dac34ea0ab4, msgTimeStamp: 11/14/2019 20:14:06
Received Queue 1 5 - currentTime: 140734 msgId: 0f7eda18-8998-41c2-aa8b-5cacfc791597, msgTimeStamp: 11/14/2019 20:14:25
To reproduce using the attached example:
Run ActiveMQ with default configuration, with `nio+ssl` as transport mode on port 61616.
User creds in this example are as follows. You will need to create a user with these creds or modify these to existing ActiveMQ creds:
username:admin
password:password1234
From within a Docker container, the address 'host.docker.internal' points to your machine's localhost.
Make sure you have Docker installed and running, and run the following commands:
docker build -f ActiveMqTest/Dockerfile-ActiveMqTest -t 'activemqtest' ActiveMqTest/
docker run activemqtest