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

Anuj Khandelwal updated AMQ-5357:
---------------------------------
    Description: 
Hi,

Broker version : 5.10.0

Problem : 
I am using ActiveMQv5.10.0 broker in my setup. In my broker I am facing a weird 
problem where a durable subscriber is not able to connect to the broker because 
of stale subscription shown by the broker with the same client id. Please note 
that this issue is not reproducible, I tried but not able to reproduce. It 
happens sometimes. 


Details: 
In my application I am creating 3 durable subscriptions on different topics. I 
am using PooledConnectionFactory with maxConnection=3 to create connections for 
each listener. I am using separate Spring Default message listener container 
for creation of the each listener. 

Sometime when I start my client, I get below exception :  
-----------
listener.DefaultMessageListenerContainer.refreshConnectionUntilSuccessful():907 
ERROR]: Could not refresh JMS Connection for destination 
'topic://test.newPnlSpn' - retrying in 5000 ms. Cause: Broker: mqbrokerdev - 
Client: new_pnl_spn_test_client already connected from tcp://a.b.c.d:2338 
-----------
But when I check connections from "a.b.c.d". I don;t see any connections from 
the IP. Even on JConsole, it does not show any clients connecting to the same 
topic with this client_id. 
In some cases i observed that this is the IP address where my client was 
previously running. 
Because of this issue my current client which is running from some other IP 
address is not able to connect to the broker. 
I suspect that there is some race condition in ActiveMQ connection pooling. 
This is a serious issue I am facing in my setup, My clients are not able to 
connect to the broker.


When I face this issue :
I tried to restart the broker by clearing out the persistent store, but this 
issue was still there. It only got resolved when I changed the client ID of my 
listener. 
Which means broker somewhere keeping stale connection state for this client id. 
As soon as new client id comes, it start working properly and connecting to the 
broker.


Detailed Error logs: 
[20140915 16:23:14:964 IST (jmsContainer-6) 
org.springframework.jms.listener.DefaultMessageListenerContainer#handleListenerSetupFailure
 666 ERROR] - Setup
 of JMS message listener invoker failed - trying to recover 
javax.jms.IllegalStateException: javax.jms.InvalidClientIDException: Broker: 
mqbrokerdev - Client: new_pnl_spn_seed_client already connected from tcp://10
*.*.*.*:3456
        at 
org.apache.activemq.jms.pool.ConnectionPool.createSession(ConnectionPool.java:135)
        at 
org.apache.activemq.jms.pool.PooledConnection.createSession(PooledConnection.java:167)
        at 
org.springframework.jms.support.JmsAccessor.createSession(JmsAccessor.java:200)
        at 
org.springframework.jms.listener.DefaultMessageListenerContainer.access$1000(DefaultMessageListenerContainer.java:116)
        at 
org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.initResourcesIfNecessary(DefaultMessageListenerCon
tainer.java:883)
        at 
org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.jav
a:869)
        at 
org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:810)
        at java.lang.Thread.run(Thread.java:745)
Caused by: javax.jms.InvalidClientIDException: Broker: mqbrokerdev - Client: 
new_pnl_spn_seed_client already connected from tcp://10.79.26.84:2338
        at 
org.apache.activemq.broker.region.RegionBroker.addConnection(RegionBroker.java:246)
        at 
org.apache.activemq.broker.jmx.ManagedRegionBroker.addConnection(ManagedRegionBroker.java:231)
        at 
org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:92)
        at 
org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:92)
        at 
org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:92)
        at 
org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:97)
        at 
org.apache.activemq.broker.util.LoggingBrokerPlugin.addConnection(LoggingBrokerPlugin.java:189)
        at 
org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:97)
        at 
tools.jms.ActiveMQLoggingPlugin.addConnection(ActiveMQLoggingPlugin.java:425)
        at 
org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:97)
        at 
org.apache.activemq.broker.TransportConnection.processAddConnection(TransportConnection.java:764)
        at 
org.apache.activemq.broker.jmx.ManagedTransportConnection.processAddConnection(ManagedTransportConnection.java:79)
        at 
org.apache.activemq.command.ConnectionInfo.visit(ConnectionInfo.java:139)
        at 
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:294)
        at 
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:148)
        at 
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
        at 
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
        at 
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:270)
        at 
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
        at 
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
        at 
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
        ... 1 more








Thanks,
Anuj
















  was:
Hi,

Broker version : 5.10.0

Problem : 
I am using ActiveMQv5.10.0 broker in my setup. In my broker I am facing a weird 
problem where a durable subscriber is not able to connect to the broker because 
of stale subscription shown by the broker with the same client id.

Details: 
In my application I am creating 3 durable subscriptions on different topics. I 
am using PooledConnectionFactory with maxConnection=3 to create connections for 
each listener. I am using separate Spring Default message listener container 
for creation of the each listener. 

Sometime when I start my client, I get below exception :  
-----------
listener.DefaultMessageListenerContainer.refreshConnectionUntilSuccessful():907 
ERROR]: Could not refresh JMS Connection for destination 
'topic://test.newPnlSpn' - retrying in 5000 ms. Cause: Broker: mqbrokerdev - 
Client: new_pnl_spn_test_client already connected from tcp://a.b.c.d:2338 

But when I check connections from "a.b.c.d". I don;t see any connections from 
the IP. Even on JConsole, it does not show any clients connecting to the same 
topic with this client_id. 
In some cases i observed that this is the IP address where my client was 
previously running. 
Because of this issue my current client which is running from some other IP 
address is not able to connect to the broker. 

I suspect that there is some race condition in ActiveMQ connection pooling. 
This is a serious issue I am facing in my setup, My clients are not able to 
connect to the broker.

When I face this issue :
I tried to restart the broker by clearing out the persistent store, but this 
issue was still there. It only got resolved when I changed the client ID of my 
listener. 
Which means broker somewhere keeping stale connection state for this client id. 
As soon as new client id comes, it start working properly and connecting to the 
broker.


Detailed Error logs: 

[20140915 16:23:14:964 IST (jmsContainer-6) 
org.springframework.jms.listener.DefaultMessageListenerContainer#handleListenerSetupFailure
 666 ERROR] - Setup
 of JMS message listener invoker failed - trying to recover 
javax.jms.IllegalStateException: javax.jms.InvalidClientIDException: Broker: 
mqbrokerdev - Client: new_pnl_spn_seed_client already connected from tcp://10
*.*.*.*:3456
        at 
org.apache.activemq.jms.pool.ConnectionPool.createSession(ConnectionPool.java:135)
        at 
org.apache.activemq.jms.pool.PooledConnection.createSession(PooledConnection.java:167)
        at 
org.springframework.jms.support.JmsAccessor.createSession(JmsAccessor.java:200)
        at 
org.springframework.jms.listener.DefaultMessageListenerContainer.access$1000(DefaultMessageListenerContainer.java:116)
        at 
org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.initResourcesIfNecessary(DefaultMessageListenerCon
tainer.java:883)
        at 
org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.jav
a:869)
        at 
org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:810)
        at java.lang.Thread.run(Thread.java:745)
Caused by: javax.jms.InvalidClientIDException: Broker: mqbrokerdev - Client: 
new_pnl_spn_seed_client already connected from tcp://10.79.26.84:2338
        at 
org.apache.activemq.broker.region.RegionBroker.addConnection(RegionBroker.java:246)
        at 
org.apache.activemq.broker.jmx.ManagedRegionBroker.addConnection(ManagedRegionBroker.java:231)
        at 
org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:92)
        at 
org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:92)
        at 
org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:92)
        at 
org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:97)
        at 
org.apache.activemq.broker.util.LoggingBrokerPlugin.addConnection(LoggingBrokerPlugin.java:189)
        at 
org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:97)
        at 
tools.jms.ActiveMQLoggingPlugin.addConnection(ActiveMQLoggingPlugin.java:425)
        at 
org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:97)
        at 
org.apache.activemq.broker.TransportConnection.processAddConnection(TransportConnection.java:764)
        at 
org.apache.activemq.broker.jmx.ManagedTransportConnection.processAddConnection(ManagedTransportConnection.java:79)
        at 
org.apache.activemq.command.ConnectionInfo.visit(ConnectionInfo.java:139)
        at 
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:294)
        at 
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:148)
        at 
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
        at 
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
        at 
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:270)
        at 
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
        at 
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
        at 
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
        ... 1 more








Thanks,
Anuj

















> Race conditions in ActiveMQ Connection Pooling
> ----------------------------------------------
>
>                 Key: AMQ-5357
>                 URL: https://issues.apache.org/jira/browse/AMQ-5357
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: activemq-pool, Broker
>    Affects Versions: 5.10.0
>            Reporter: Anuj Khandelwal
>
> Hi,
> Broker version : 5.10.0
> Problem : 
> I am using ActiveMQv5.10.0 broker in my setup. In my broker I am facing a 
> weird problem where a durable subscriber is not able to connect to the broker 
> because of stale subscription shown by the broker with the same client id. 
> Please note that this issue is not reproducible, I tried but not able to 
> reproduce. It happens sometimes. 
> Details: 
> In my application I am creating 3 durable subscriptions on different topics. 
> I am using PooledConnectionFactory with maxConnection=3 to create connections 
> for each listener. I am using separate Spring Default message listener 
> container for creation of the each listener. 
> Sometime when I start my client, I get below exception :  
> -----------
> listener.DefaultMessageListenerContainer.refreshConnectionUntilSuccessful():907
>  ERROR]: Could not refresh JMS Connection for destination 
> 'topic://test.newPnlSpn' - retrying in 5000 ms. Cause: Broker: mqbrokerdev - 
> Client: new_pnl_spn_test_client already connected from tcp://a.b.c.d:2338 
> -----------
> But when I check connections from "a.b.c.d". I don;t see any connections from 
> the IP. Even on JConsole, it does not show any clients connecting to the same 
> topic with this client_id. 
> In some cases i observed that this is the IP address where my client was 
> previously running. 
> Because of this issue my current client which is running from some other IP 
> address is not able to connect to the broker. 
> I suspect that there is some race condition in ActiveMQ connection pooling. 
> This is a serious issue I am facing in my setup, My clients are not able to 
> connect to the broker.
> When I face this issue :
> I tried to restart the broker by clearing out the persistent store, but this 
> issue was still there. It only got resolved when I changed the client ID of 
> my listener. 
> Which means broker somewhere keeping stale connection state for this client 
> id. As soon as new client id comes, it start working properly and connecting 
> to the broker.
> Detailed Error logs: 
> [20140915 16:23:14:964 IST (jmsContainer-6) 
> org.springframework.jms.listener.DefaultMessageListenerContainer#handleListenerSetupFailure
>  666 ERROR] - Setup
>  of JMS message listener invoker failed - trying to recover 
> javax.jms.IllegalStateException: javax.jms.InvalidClientIDException: Broker: 
> mqbrokerdev - Client: new_pnl_spn_seed_client already connected from tcp://10
> *.*.*.*:3456
>         at 
> org.apache.activemq.jms.pool.ConnectionPool.createSession(ConnectionPool.java:135)
>         at 
> org.apache.activemq.jms.pool.PooledConnection.createSession(PooledConnection.java:167)
>         at 
> org.springframework.jms.support.JmsAccessor.createSession(JmsAccessor.java:200)
>         at 
> org.springframework.jms.listener.DefaultMessageListenerContainer.access$1000(DefaultMessageListenerContainer.java:116)
>         at 
> org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.initResourcesIfNecessary(DefaultMessageListenerCon
> tainer.java:883)
>         at 
> org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.jav
> a:869)
>         at 
> org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:810)
>         at java.lang.Thread.run(Thread.java:745)
> Caused by: javax.jms.InvalidClientIDException: Broker: mqbrokerdev - Client: 
> new_pnl_spn_seed_client already connected from tcp://10.79.26.84:2338
>         at 
> org.apache.activemq.broker.region.RegionBroker.addConnection(RegionBroker.java:246)
>         at 
> org.apache.activemq.broker.jmx.ManagedRegionBroker.addConnection(ManagedRegionBroker.java:231)
>         at 
> org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:92)
>         at 
> org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:92)
>         at 
> org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:92)
>         at 
> org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:97)
>         at 
> org.apache.activemq.broker.util.LoggingBrokerPlugin.addConnection(LoggingBrokerPlugin.java:189)
>         at 
> org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:97)
>         at 
> tools.jms.ActiveMQLoggingPlugin.addConnection(ActiveMQLoggingPlugin.java:425)
>         at 
> org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:97)
>         at 
> org.apache.activemq.broker.TransportConnection.processAddConnection(TransportConnection.java:764)
>         at 
> org.apache.activemq.broker.jmx.ManagedTransportConnection.processAddConnection(ManagedTransportConnection.java:79)
>         at 
> org.apache.activemq.command.ConnectionInfo.visit(ConnectionInfo.java:139)
>         at 
> org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:294)
>         at 
> org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:148)
>         at 
> org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
>         at 
> org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
>         at 
> org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:270)
>         at 
> org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
>         at 
> org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
>         at 
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
>         ... 1 more
> Thanks,
> Anuj



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Reply via email to