[jira] [Updated] (AMQ-4710) The first heart-beat after a connection becomes idle isn't sent as quickly as it should be

classic Classic list List threaded Threaded
1 message Options
Reply | Threaded
Open this post in threaded view
|

[jira] [Updated] (AMQ-4710) The first heart-beat after a connection becomes idle isn't sent as quickly as it should be

JIRA jira@apache.org

     [ https://issues.apache.org/jira/browse/AMQ-4710?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Paul Gale updated AMQ-4710:
---------------------------

    Attachment: amq-4710.diff

Unit test and patch to fix this issue.
               

> The first heart-beat after a connection becomes idle isn't sent as quickly as it should be
> ------------------------------------------------------------------------------------------
>
>                 Key: AMQ-4710
>                 URL: https://issues.apache.org/jira/browse/AMQ-4710
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: stomp
>    Affects Versions: 5.8.0
>            Reporter: Andy Wilkinson
>         Attachments: amq-4710.diff
>
>
> After ActiveMQ sends a stomp frame, it may not send a heart-beat for up to almost 2x the negotiated interval.
> The following test should illustrate the problem:
> {code}
> import org.junit.Test;
> import static org.junit.Assert.*;
> public class ActiveMqHeartbeatTests {
> @Test
> public void heartbeats() throws Exception {
> BrokerService broker = createAndStartBroker();
> Socket socket = null;
> try {
> socket = new Socket("localhost", 61613);
> byte[] connectFrame = "CONNECT\nheart-beat:0,10000\naccept-version:1.2\n\n\0".getBytes();
> socket.getOutputStream().write(connectFrame);
> byte[] buffer = new byte[4096];
> long lastReadTime = System.currentTimeMillis();
> while (true) {
> int read = socket.getInputStream().read(buffer);
> byte[] frame = Arrays.copyOf(buffer, read);
> long now = System.currentTimeMillis();
> long timeSinceLastRead = now - lastReadTime;
> lastReadTime = now;
> System.out.println(new String(frame));
> System.out.println("Time since last read: " + timeSinceLastRead + "ms");
> if (timeSinceLastRead > 15000) {
> fail("Data not received for " + timeSinceLastRead + "ms");
> }
> }
> } finally {
> if (socket != null) {
> socket.close();
> }
> broker.stop();
> }
> }
> private BrokerService createAndStartBroker() throws Exception {
> BrokerService broker = new BrokerService();
> broker.addConnector("stomp://localhost:61613");
> broker.setStartAsync(false);
> broker.setDeleteAllMessagesOnStartup(true);
> broker.start();
> return broker;
> }
> }
> {code}
> For the initial read of the CONNECTED frame I see:
> {noformat}
> Time since last read: 49ms
> {noformat}
> However, it's then almost 20 seconds before a heart-beat's sent:
> {noformat}
> Time since last read: 19994ms
> {noformat}
> If I comment out the fail(…) line in the test, after the first heartbeat taking almost 20000ms to be sent, things settle down and a heartbeat's received every 10000ms.
> It looks like the write checker wakes up every 10000ms. The first time it wakes up, it notices that the CONNECTED frame was sent and does nothing. It then sleeps for a further 10000ms before checking again. As the CONNECTED frame was sent very early in the first 10000ms window, this leads to it taking almost 20000ms for the first heart-beat to be sent. From this point, as no further data frames are sent, the write checker wakes up and sends a heart-beat every 10000ms.
> In short, I don't think ActiveMQ is adhering to the requirement that "the sender MUST send new data over the network connection at least every <n> milliseconds".

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira