[jira] [Commented] (AMQ-5313) ActiveMq consumer intermittently hanging after reconnect

["Wayne Irwin (JIRA)" <ji...@apache.org>]

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

Wayne Irwin commented on AMQ-5313:
----------------------------------

Narrowed problem down to the use a LinkedHashMap as a MessageCache in the ConsumerStateTracker class in ActiveMQ.  
The LinkedHashMap has a special method called removeEldestEntry that is called whenever a new entry is put into the HashMap.  In IBM JRE, this is called every time an entry is added to the HashMap, regardless if the key already exists or not.  In Oracle JRE, this method is only invoked if the key value being added is new (which in a polling config is always the same key for polling command).
When the removeEldestEntry is invoked and the external field currentCacheSize exceeds 128K, it would automatically remove the oldest entry in the list.  In ActiveMQ 5.9.0, the field currentCacheSize was being grown by 400 bytes for every polling call to a queue (so 1 per second) regardless of whether adding a new entry to the queue or not.  Once the currentCacheSize exceeded 128K (after about 6 mins), the removeEldestEntry method in the IBM JRE would start to remove the eldest entry which in a polling state was the entry just inserted (so the message cache would be 0 entries in size and when a disconnect occurs, it wouldn't replay the PullCommands that were needed to resume the polling).  In the Oracle JRE, the removeEldestEntry was not being invoked because the pullMessage command was not a new entry.
Regardless of the scenario above, a change was made in ActiveMQ 5.9.1 in that the currentCacheSize only grows by 400 bytes on the first poll, so, now the currentCache size only grows with additional polling consumers instead of after each poll.  Moving the ActiveMQ client to 5.9.1 will longer exhibit the issue with the Polling Consumer not resuming polling, as the removeEldestEntry will not remove the eldest entry until we exceed 320 polling consumers (as opposed to before, where it would remove the entry with just 1 entry in the cache after 6 mins of time).

> ActiveMq consumer intermittently hanging after reconnect
> --------------------------------------------------------
>
>                 Key: AMQ-5313
>                 URL: https://issues.apache.org/jira/browse/AMQ-5313
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: JMS client
>    Affects Versions: 5.9.0
>         Environment: AIX 6.1, AIX 7.1, IBM Java 6, IBM Java 7
>            Reporter: Wayne Irwin
>         Attachments: fail.log
>
>
> I have run into an intermittent problem with ActiveMQ V5.9.0. The intermittent was tracked down to being a connection error that does not get properly recovered. 
> I have recreated the problem in a very small example by creating a Camel 
> consumer route that retrieves messages from a JMS queue and writes the text message to a log.   
>         from(TEST_QUEUE).routeId(TEST_QUEUE).convertBodyTo(String.class) 
>              .log(LoggingLevel.INFO, loggerName, "Request Received ");
>  
>   The connection string used is 
>   failover:(tcp://serverd05.company.com:26093?keepAlive=true)?jms.prefetchPolicy.all=0
>    
> Please note that polling is being used when the prefetch size is set to 0. 
> I then use Hawtio on the ActiveMQ broker to add some text messages to the queue. It works fine.
>  
> I then stop the Client Connector on the ActiveMQ broker side to simulate a 
> broken connection on the consumer side. (The broker must be remote to the consumer or the error will not occur.)  The client logs show that an 
> EOFException is caught and the connection is reestablished. The connection also appears on the ActiveMQ broker. it only looks good though. Sending new text messages to the queue will not be processed. They will just sit there.  There are no errors or warnings logged on either the consumer or broker servers. Restarting the consumer will cause the messages to get processed. The reconnection only intermittently fails. I find is much more like to occur if 10 minutes pass from the previous message being processed. 
> I turned on trace=yes in the connection string and found the root cause is the PullMessage commands are occasionally not being issued after a reconnect.  On cases where it works, the log shows that the PullMessage commands do reinstate. 
> I am wondering if this might be a race condition, as this problem only showed up when the consumer was on fast servers 



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