Client: XXX already connected exception when connection started after consumers added

• Key: AMQ-696
• Type: Bug
• Status: Resolved
• Resolution: Fixed
• Priority: Major
• Assignee: Unassigned
• Reporter: Craig Day
• Component/s: Broker
• Affects Version/s: 4.0 RC2, 4.0 RC3
• Fix Version/s: 4.0

Description

While using the new Spring-2.0 DefaultMessageListenerContainer I can reliably reproduce the following exception on the broker side which usually results in a hang on the client side:

The broker logs the following exception:

INFO Service - Sync error occurred: javax.jms.InvalidClientIDException: Broker: localhost - Client: ID:inspiron-1410-114619274
7453-2:1 already connected
javax.jms.InvalidClientIDException: Broker: localhost - Client: ID:inspiron-1410-1146192747453-2:1 already connected
at org.apache.activemq.broker.region.RegionBroker.addConnection(RegionBroker.java:154)
at org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:65)
at org.apache.activemq.advisory.AdvisoryBroker.addConnection(AdvisoryBroker.java:69)
at org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:65)
at org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:77)
at org.apache.activemq.broker.AbstractConnection.processAddConnection(AbstractConnection.java:500)
at org.apache.activemq.broker.jmx.ManagedTransportConnection.processAddConnection(ManagedTransportConnection.java:82)
at org.apache.activemq.command.ConnectionInfo.visit(ConnectionInfo.java:106)
at org.apache.activemq.broker.AbstractConnection.service(AbstractConnection.java:196)
at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:62)
at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:93)
at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:70)
at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:114)
at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:122)
at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:87)
at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:139)
at java.lang.Thread.run(Thread.java:595)

I have extrapolated the sequence of calls that DefaultMessageListenerContainer is making and managed to produce a simple test case that reproduces the problem:

import junit.framework.TestCase;
import org.apache.activemq.ActiveMQConnectionFactory;
import org.apache.activemq.command.ActiveMQQueue;

import javax.jms.*;

public class TestActiveMQ extends TestCase {

public void testConnectionFactory() throws Exception {
final ActiveMQConnectionFactory cf = new ActiveMQConnectionFactory("tcp://localhost:61616");
final ActiveMQQueue queue = new ActiveMQQueue("testqueue");
final Connection conn = cf.createConnection();

Runnable r = new Runnable() {
public void run() {
try { Session session = conn.createSession(false, 1); MessageConsumer consumer = session.createConsumer(queue, null); Message msg = consumer.receive(1000); } catch (JMSException e) { e.printStackTrace(); }
}
};
new Thread(r).start();
conn.start();

try {
synchronized (this) { wait(3000); }
} catch (InterruptedException e) { e.printStackTrace(); }
}
}

Let us know if you need anymore information. Dont want to scrub ActiveMQ from my list of candidates If I can help it.

cheers
craig