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

["Leon Barrett (JIRA)" <ji...@apache.org>]

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

Leon Barrett commented on AMQ-4710:
-----------------------------------

Hi, any news? Do you need me to change anything in that patch? I am really quite interested in getting this bug fixed.

> 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
>            Assignee: Timothy Bish
>            Priority: Major
>             Fix For: 5.x
>
>         Attachments: AMQ-4710-double-heartbeat-frequency.patch, 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 was sent by Atlassian JIRA
(v7.6.3#76005)