confused about Usage Manager Memory Limit reached

classic Classic list List threaded Threaded
4 messages Options
Reply | Threaded
Open this post in threaded view
|

confused about Usage Manager Memory Limit reached

brian
Using ActiveMQ 5.9.1

Our setup: A Spring/JMS producer places many (sometimes quite large)
messages on one queue (hf.request), which are being picked up by a PHP
Stomp client. PHP processes the data and sends a message to a second
queue (hf.response) to let it know how things went.

Occasionally, we're seeing the PHP producer being blocked.

Starting with both IDs known ...

php (stomp): ID:pan-51744-1418069977147-2:2
tcp://127.0.0.1:34916

java (openwire): ID:pan-36709-1418086070781-1:1
tcp://127.0.0.1:46827


2014-12-08 20:17:26,535 | INFO  |
Usage(default:memory:queue://hf.response:memory) percentUsage=0%,
usage=0, limit=720791142,
percentUsageMinDelta=1%;Parent:Usage(default:memory) percentUsage=104%,
usage=752535801, limit=720791142, percentUsageMinDelta=1%: Usage Manager
Memory Limit reached. Producer (ID:pan-51744-1418069977147-2:2:-1:1)
stopped to prevent flooding queue://hf.response. See
http://activemq.apache.org/producer-flow-control.html for more info
(blocking for: 1352s) | org.apache.activemq.broker.region.Queue |
ActiveMQ Transport: tcp:///127.0.0.1:34916@61613


The log message is confusing as it appears to be telling me that the
response queue is being flooded. However, the amount of data sent to
response is trivial:

2014-12-08 19:55:01 Info: Array
(
     [synchronizationId] => 6676ab36-f6cf-402d-9045-b58e210fcd3e
     [type] => INVENTORY_ITEM
     [command] => CREATE
     [status] => OK
     [statusMessage] =>
)


... compared to request, which can amount to several MB per msg. And it
can't possibly be that PHP is hitting the queue too fast as it has a
fair bit of data to process before it sends to hf.response.

The browser client shows that all messages enqueued to response have
been successfully dequeued, but there are several hundred pending in
hf.request.

Can anyone tell me what might be going on here? If anything, i'd expect
the java producer to be blocked to prevent hf.request from being
flooded. That is, i would have thought that the place where we'd run
into trouble would be constantPendingMessageLimitStrategy. Here's the
config for that:

<pendingMessageLimitStrategy>
   <constantPendingMessageLimitStrategy limit="1000"/>
</pendingMessageLimitStrategy>

System usage is:

<systemUsage>
   <systemUsage>
       <memoryUsage>
           <memoryUsage percentOfJvmHeap="70" />
       </memoryUsage>
       <storeUsage>
           <storeUsage limit="100 gb"/>
       </storeUsage>
       <tempUsage>
           <tempUsage limit="50 gb"/>
       </tempUsage>
   </systemUsage>
</systemUsage>


The only thing i can think of is that the log message, "stopped to
prevent flooding queue://hahnfarms.response" is getting its queue name
from the hf.request messages' reply-to headers, but that the real
problem is with hf.request. But then, i'd presume that it would be the
java client that would be blocked.


Reply | Threaded
Open this post in threaded view
|

Re: confused about Usage Manager Memory Limit reached

Tim Bain
The log line tells you how you're doing against two different limits: the
per-destination limit and the entire-broker limit.  The per-destination
limit is first, and the log line says you're using 0% of what you've
allocated per destination, so you're right that you're fine there.  The
full-broker limit is second, and the log line says you're using 104% of the
available memory, which is why you're getting flow controlled: although the
individual destination is empty, the broker as a whole is full, and this
one message just happens to be the straw that breaks the camel's back.  So
figure out what other destination has lots of messages (or large messages)
to be using 70GB(!) of memory...

On Mon, Dec 8, 2014 at 6:46 PM, brian <[hidden email]> wrote:

> Using ActiveMQ 5.9.1
>
> Our setup: A Spring/JMS producer places many (sometimes quite large)
> messages on one queue (hf.request), which are being picked up by a PHP
> Stomp client. PHP processes the data and sends a message to a second queue
> (hf.response) to let it know how things went.
>
> Occasionally, we're seeing the PHP producer being blocked.
>
> Starting with both IDs known ...
>
> php (stomp): ID:pan-51744-1418069977147-2:2
> tcp://127.0.0.1:34916
>
> java (openwire): ID:pan-36709-1418086070781-1:1
> tcp://127.0.0.1:46827
>
>
> 2014-12-08 20:17:26,535 | INFO  | Usage(default:memory:queue://hf.response:memory)
> percentUsage=0%, usage=0, limit=720791142, percentUsageMinDelta=1%;Parent:Usage(default:memory)
> percentUsage=104%, usage=752535801, limit=720791142,
> percentUsageMinDelta=1%: Usage Manager Memory Limit reached. Producer
> (ID:pan-51744-1418069977147-2:2:-1:1) stopped to prevent flooding
> queue://hf.response. See http://activemq.apache.org/
> producer-flow-control.html for more info (blocking for: 1352s) |
> org.apache.activemq.broker.region.Queue | ActiveMQ Transport:
> tcp:///127.0.0.1:34916@61613
>
>
> The log message is confusing as it appears to be telling me that the
> response queue is being flooded. However, the amount of data sent to
> response is trivial:
>
> 2014-12-08 19:55:01 Info: Array
> (
>     [synchronizationId] => 6676ab36-f6cf-402d-9045-b58e210fcd3e
>     [type] => INVENTORY_ITEM
>     [command] => CREATE
>     [status] => OK
>     [statusMessage] =>
> )
>
>
> ... compared to request, which can amount to several MB per msg. And it
> can't possibly be that PHP is hitting the queue too fast as it has a fair
> bit of data to process before it sends to hf.response.
>
> The browser client shows that all messages enqueued to response have been
> successfully dequeued, but there are several hundred pending in hf.request.
>
> Can anyone tell me what might be going on here? If anything, i'd expect
> the java producer to be blocked to prevent hf.request from being flooded.
> That is, i would have thought that the place where we'd run into trouble
> would be constantPendingMessageLimitStrategy. Here's the config for that:
>
> <pendingMessageLimitStrategy>
>   <constantPendingMessageLimitStrategy limit="1000"/>
> </pendingMessageLimitStrategy>
>
> System usage is:
>
> <systemUsage>
>   <systemUsage>
>       <memoryUsage>
>           <memoryUsage percentOfJvmHeap="70" />
>       </memoryUsage>
>       <storeUsage>
>           <storeUsage limit="100 gb"/>
>       </storeUsage>
>       <tempUsage>
>           <tempUsage limit="50 gb"/>
>       </tempUsage>
>   </systemUsage>
> </systemUsage>
>
>
> The only thing i can think of is that the log message, "stopped to prevent
> flooding queue://hahnfarms.response" is getting its queue name from the
> hf.request messages' reply-to headers, but that the real problem is with
> hf.request. But then, i'd presume that it would be the java client that
> would be blocked.
>
>
>
Reply | Threaded
Open this post in threaded view
|

Re: confused about Usage Manager Memory Limit reached

brian
On 14-12-08 08:57 PM, Tim Bain wrote:

> The log line tells you how you're doing against two different limits: the
> per-destination limit and the entire-broker limit.  The per-destination
> limit is first, and the log line says you're using 0% of what you've
> allocated per destination, so you're right that you're fine there.  The
> full-broker limit is second, and the log line says you're using 104% of the
> available memory, which is why you're getting flow controlled: although the
> individual destination is empty, the broker as a whole is full, and this
> one message just happens to be the straw that breaks the camel's back.  So
> figure out what other destination has lots of messages (or large messages)
> to be using 70GB(!) of memory...


Thanks for the response. I've spent some time digging into it further
and your remarks helped to clarify some things. The following links
helped a bunch, also:

http://www.christianposta.com/blog/?p=273
http://open-source-adventures.blogspot.ca/2009/01/limiting-disk-store-usage-with-active.html 
(contains some deprecated info)
https://access.redhat.com/documentation/en-US/Fuse_Message_Broker/5.4/html/Using_Persistent_Messages/files/FuseMBPersistIntro.html

I've since adjusted my config in the following way:

<persistenceAdapter>
   <kahaDB
     directory="${activemq.data}/kahadb"
     journalMaxFileLength="100mb"
     enableJournalDiskSyncs="true"
     checksumJournalFiles="true"
     checkForCorruptJournalFiles="true"
     indexCacheSize="10000"
     cleanupInterval="30000"
     checkpointInterval="5000"
   />
</persistenceAdapter>

<systemUsage>
   <systemUsage>
     <memoryUsage>
       <memoryUsage percentOfJvmHeap="70" />
     </memoryUsage>
     <storeUsage>
       <storeUsage limit="50 gb" />
     </storeUsage>
     <tempUsage>
       <tempUsage limit="50 gb"/>
     </tempUsage>
   </systemUsage>
</systemUsage>


I'd noticed that the log messages mentioned the delay time in increasing
intervals of 30 seconds. Could this be related to cleanupInterval?

I should point out that these message numbers are an infrequent event
with this application. The norm is to pass significantly fewer messages
at a time. With the above changes, i've run this maximal sync several
times without further trouble, save for the last run, in which a single
message refused to leave the queue, and without any suggestion in the
log that AMQ was flow controlling the consumer. I'll keep playing with it.

And did you mean ~700MB? That's much closer to what i'm seeing of the
actual data being sent over the wire.
Reply | Threaded
Open this post in threaded view
|

Re: confused about Usage Manager Memory Limit reached

Tim Bain
Sorry for the delay getting back to you.

I'm not clear what delay error messages you're referring to; if you're
still having problems related to them, can you include a sample to help
clarify what you mean?

I got the 70GB by multiplying your 70% JVM percentage by your 100GB store
limit instead of your JVM heap size, which of course doesn't make any
sense.  Sorry for the confusion.
On Dec 9, 2014 8:40 PM, "brian" <[hidden email]> wrote:

On 14-12-08 08:57 PM, Tim Bain wrote:

> The log line tells you how you're doing against two different limits: the
> per-destination limit and the entire-broker limit.  The per-destination
> limit is first, and the log line says you're using 0% of what you've
> allocated per destination, so you're right that you're fine there.  The
> full-broker limit is second, and the log line says you're using 104% of the
> available memory, which is why you're getting flow controlled: although the
> individual destination is empty, the broker as a whole is full, and this
> one message just happens to be the straw that breaks the camel's back.  So
> figure out what other destination has lots of messages (or large messages)
> to be using 70GB(!) of memory...
>


Thanks for the response. I've spent some time digging into it further and
your remarks helped to clarify some things. The following links helped a
bunch, also:

http://www.christianposta.com/blog/?p=273
http://open-source-adventures.blogspot.ca/2009/01/limiting-
disk-store-usage-with-active.html (contains some deprecated info)
https://access.redhat.com/documentation/en-US/Fuse_
Message_Broker/5.4/html/Using_Persistent_Messages/files/
FuseMBPersistIntro.html

I've since adjusted my config in the following way:

<persistenceAdapter>
  <kahaDB
    directory="${activemq.data}/kahadb"
    journalMaxFileLength="100mb"
    enableJournalDiskSyncs="true"
    checksumJournalFiles="true"
    checkForCorruptJournalFiles="true"
    indexCacheSize="10000"
    cleanupInterval="30000"
    checkpointInterval="5000"
  />
</persistenceAdapter>


<systemUsage>
  <systemUsage>
    <memoryUsage>
      <memoryUsage percentOfJvmHeap="70" />
    </memoryUsage>
    <storeUsage>
      <storeUsage limit="50 gb" />

    </storeUsage>
    <tempUsage>
      <tempUsage limit="50 gb"/>
    </tempUsage>
  </systemUsage>
</systemUsage>


I'd noticed that the log messages mentioned the delay time in increasing
intervals of 30 seconds. Could this be related to cleanupInterval?

I should point out that these message numbers are an infrequent event with
this application. The norm is to pass significantly fewer messages at a
time. With the above changes, i've run this maximal sync several times
without further trouble, save for the last run, in which a single message
refused to leave the queue, and without any suggestion in the log that AMQ
was flow controlling the consumer. I'll keep playing with it.

And did you mean ~700MB? That's much closer to what i'm seeing of the
actual data being sent over the wire.