[AMQ-6194] Deleting a temporary queue creates a warning message in the broker

• Type: Bug
• Status: Resolved
• Priority: Minor
• Resolution: Fixed
• Affects Version/s: 5.12.1, 5.13.1
• Fix Version/s: 5.13.4, 5.14.0
• Component/s: Broker, JMS client
• Assignee: Christopher L. Shannon
• Reporter: David Dou
• Created: 03/Mar/16 13:02
• Updated: 01/Jul/16 12:28
• Resolved: 07/Mar/16 14:20

Description

When deleting a temporary queue, the ActiveMQ 5.13.1 (and 5.12.2) broker logs the following warning message:

INFO  [ActiveMQ NIO Worker 111] [TempQueue] temp-queue://ID:brokerHostname-57582-1455804170203-8569:1:1 on dispose, purge of 1 pending messages: org.apache.activemq.broker.region.cursors.VMPendingMessageCursor@e0f6196
WARN  [ActiveMQ NIO Worker 111] [Queue] temp-queue://ID:brokerHostname-57582-1455804170203-8569:1:1 after purge of 1 messages, message count stats report: 1

The cause of this warning seems to be the publication of a "ghost" message when sending a single message on the temporary queue from a transacted session, as demonstrated by this test class:

import java.text.SimpleDateFormat;
import java.util.Date;

import javax.jms.Connection;
import javax.jms.JMSException;
import javax.jms.MessageProducer;
import javax.jms.Session;
import javax.jms.TemporaryQueue;
import javax.jms.TextMessage;

import org.apache.activemq.ActiveMQConnectionFactory;

public class GhostMessageOnTempQueueWithTransactedSessionDemo {
    public static void main(final String[] args) throws JMSException {
        final ActiveMQConnectionFactory factory = new ActiveMQConnectionFactory("tcp://localhost:61616");
        Connection connection = null;
        Session session = null;
        MessageProducer producer = null;
        TemporaryQueue temporaryQueue = null;
        try {
            connection = factory.createConnection();
            connection.start();
            // The session has to be transacted for the second "ghost" message to appear (see below).
            session = connection.createSession(true, Session.SESSION_TRANSACTED);
            // And the publication has to be on a temporary queue (if the temporary queue is created by another process, the second "ghost" message still appears).
            temporaryQueue = session.createTemporaryQueue();
            producer = session.createProducer(temporaryQueue);
            final TextMessage textMessage = session.createTextMessage();
            textMessage.setText("GhostMessageDemo@" + new SimpleDateFormat("yyyy-MM-dd'T'HH:mm:ss,SSSZ").format(new Date()));

            producer.send(textMessage);
            // Here, in ActiveMQ 5.13.1 and 5.12.2, the message was sent but cannot be browsed or consumed. It can however be seen in the JMX console with:
            // - EnqueueCount, that was increased by one;
            // - MemoryUsageByteCount (by sending huge messages of different size to ensure that it is indeed the real message).
            // In ActiveMQ 5.10.2 (and 5.4.1), it is not sent (even though SocketOutputStream.socketWrite is still called through TcpFormat.oneway?).

            session.commit();
            // Here, in ActiveMQ 5.13.1, a "ghost" message was sent (EnqueueCount has increased by one again) and the real message is visible and can be consumed.
            // If rollback is called instead, the real message stays (and cannot be consumed since the "ghost" message is not sent).
        } finally {
            if (producer != null)
                producer.close();
            if (temporaryQueue != null)
                // Here, if there was a consumer on the queue, it would have consumed the real message, leaving the "ghost" message that lead to the broker warning.
                temporaryQueue.delete();
            if (session != null)
                session.close();
            if (connection != null) {
                connection.stop();
                connection.close();
            }
        }
    }
}