Still getting STOMP Client connect error in AMQ 5.1.0 Release

• Key: AMQ-1715
• Type: Bug
• Status: Open
• Priority: Major
• Assignee: Unassigned
• Reporter: vik dhawan
• Component/s: Broker
• Affects Version/s: 5.1.0
• Fix Version/s: 5.4.0

Description

I started getting this following error again in AMQ 5.1.0 stable release. I used to get this error on 4.1.0 and 5.0.0. This error disapeard for a while in AMQ 4.1.2 but came back again in 5.1.0.

My client also gets this exception. at the AMQ side it shows up as a WARN but to the C STOMP client it goes an ugly java stacktrace.

AMQ Log:

javax.jms.InvalidClientIDException: Broker: localhost - Client: WRK_batch01_9121 already connected from /xx.xxx.xxx.xx:51577
at org.apache.activemq.broker.region.RegionBroker.addConnection(RegionBroker.java:211)
at org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:81)
at org.apache.activemq.advisory.AdvisoryBroker.addConnection(AdvisoryBroker.java:75)
at org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:81)
at org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:88)
at org.apache.activemq.broker.TransportConnection.processAddConnection(TransportConnection.java:662)
at org.apache.activemq.broker.jmx.ManagedTransportConnection.processAddConnection(ManagedTransportConnection.java:86)
at org.apache.activemq.command.ConnectionInfo.visit(ConnectionInfo.java:125)
at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292)
at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180)
at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
at org.apache.activemq.transport.stomp.StompTransportFilter.sendToActiveMQ(StompTransportFilter.java:80)
at org.apache.activemq.transport.stomp.ProtocolConverter.sendToActiveMQ(ProtocolConverter.java:134)
at org.apache.activemq.transport.stomp.ProtocolConverter.onStompConnect(ProtocolConverter.java:461)
at org.apache.activemq.transport.stomp.ProtocolConverter.onStompCommad(ProtocolConverter.java:186)
at org.apache.activemq.transport.stomp.StompTransportFilter.onCommand(StompTransportFilter.java:70)
at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:196)
at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:183)
at java.lang.Thread.run(Thread.java:619)

C STOMP Client END:

Response: ERROR, javax.jms.InvalidClientIDException: Broker: localhost - Client: WRK_batch01_9121 already connected from /xx.xxx.xxx.xx:51577
at org.apache.activemq.broker.region.RegionBroker.addConnection(RegionBroker.java:211)
at org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:81)
at org.apache.activemq.advisory.AdvisoryBroker.addConnection(AdvisoryBroker.java:75)
at org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:81)
at org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:88)
at org.apache.activemq.broker.TransportConnection.processAddConnection(TransportConnection.java:662)
at org.apache.activemq.broker.jmx.ManagedTransportConnection.processAddConnection(ManagedTransportConnection.java:86)
at org.apache.activemq.command.ConnectionInfo.visit(ConnectionInfo.java:125)
at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292)
at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180)
at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
at org.apache.activemq.transport.stomp.StompTransportFilter.sendToActiveMQ(StompTransportFilter.java:80)
at org.apache.activemq.transport.stomp.ProtocolConverter.sendToActiveMQ(ProtocolConverter.java:134)
at org.apache.activemq.transport.stomp.ProtocolConverter.onStompConnect(ProtocolConverter.java:461)
at org.apache.activemq.transport.stomp.ProtocolConverter.onStompCommad(ProtocolConverter.java:186)
at org.apache.activemq.transport.stomp.StompTransportFilter.onCommand(StompTransportFilter.java:70)
at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:196)
at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:183)
at java.lang.Thread.run(Thread.java:619)
, SessionId=unknown

Please help!

Comments

hi, i am encountering the same issue:

i am using a .Net client which connects to the broker fine. on a reconnect from the client (network issue or if broker restarts) , also when reconnection happens the old connection does not close on the linux side at all, netstat shows no of connections to 10.1.30.176 is increasing linearly..

stacktrace :-

javax.jms.InvalidClientIDException: Broker: localhost - Client: 694bd87b-2941-462a-9e7a-33860fb491bf already connected from /10.1.30.176:1318
at org.apache.activemq.broker.region.RegionBroker.addConnection(RegionBroker.java:211)
at org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:81)
at org.apache.activemq.advisory.AdvisoryBroker.addConnection(AdvisoryBroker.java:75)
at org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:81)
at org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:88)
at org.apache.activemq.broker.TransportConnection.processAddConnection(TransportConnection.java:662)
at org.apache.activemq.broker.jmx.ManagedTransportConnection.processAddConnection(ManagedTransportConnection.java:86)
at org.apache.activemq.command.ConnectionInfo.visit(ConnectionInfo.java:125)
at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292)
at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:180)
at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:143)
at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:206)
at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:196)
at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:183)
at java.lang.Thread.run(Thread.java:595)

Now in RegionBroker.java i see -
synchronized (clientIdSet) {
ConnectionContext oldContext = clientIdSet.get(clientId);
if (oldContext != null) {
System.out.println( "heyyyy" + context.isFaultTolerant() + "||" + context.isNetworkConnection() );
if (context.isFaultTolerant() || context.isNetworkConnection()){
//remove the old connection
try{ removeConnection(oldContext, info, new Exception("remove stale client")); }catch(Exception e){ LOG.warn("Failed to remove stale connection ",e); }
}else{ throw new InvalidClientIDException("Broker: " + getBrokerName() + " - Client: " + clientId + " already connected from " + oldContext.getConnection().getRemoteAddress()); }
} else { clientIdSet.put(clientId, context); }
}

It seems like isnetworkconnection and isfaulttolerant are false and hence goes into the else throwing the exception.
On setting the faulttolerant as true in TransportConnection.java (lines 650-655)
context.setConnector(connector);
context.setMessageAuthorizationPolicy(getMessageAuthorizationPolicy());
context.setNetworkConnection(networkConnection);
//context.setFaultTolerant(faultTolerantConnection);
context.setFaultTolerant(true);

the exception does not happen anymore and also the network connections being open problem is solved, which makes sense considering it goes into the if condition and the oldcontext is removed from the clienthashset.

Is this a fix ? or am i doing something wrong setting the flag as true when it gets set false by itself ??
By default RegionBroker seems to return faulttolerantconfig as false.

[Hari]

On upgrading the apache.NMS.net client to the latest there is no exception on the server side. The latest NMS client creates a new clientid for a reconnect and hence it makes sense that i dont see the exception on the server side.
There is a problem with the no of connections. The NMS client is connected first with the server(running on 51616) on port 3000. On a reconnect its connected on 3002, but the old connection is also alive ??. On invoking the stop method from the jconsole on the connection(3000) the connection is killed (monitoring using netstat on the machine). Should the activemq server automatically know that a connection is stale and disconnect/kill the old connection ?

on the client side a netstat shows only one connection(3002) , we did a reconnect by disabling and enabling the lan connection in the windows tray.