You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by Joe Smith <jo...@yahoo.com> on 2011/07/30 05:09:54 UTC

Load testing 5.5 - broker pauses between sends

Hi,

We are testing 5.5.0 for an upgrade from 5.4 - hoping for a performance boost.

In our testing, we notice brokers stop delivering messages on a regular interval.  The cpu graph clearly showing a slowing down of the broker at regular interval.  With some investigation by changing the kahaDb's cleanupInterval and DEBUG trace, we think we have identify where the "pause" occurs.      

For simplicity, we reverted our activemq.xml to minimal config.  Our test client is sending at approximately 39k msgs/sec to a test.queue.

With debug trace, the pause is between timestamp 2011-07-29 22:07:38,617 through 2011-07-29 22:08:03,214.  During that period, no message were delivered for test.queue and broker's cpu usage drops to 0 (jconsole).  The trace is in the attachment.  

It looked like the pauses corresponding to kahaDB's cleanupInterval.  The trace showed the following activities during the pause interval:
- Main:memory: usage change from: 36% of available memory .... at interval of 1% points
- org.apache.activemq.transport.InactivityMonitor$2@7aaea288 10000 ms elapsed since last write check
- Multiple Checkpoint started.done.
- expiring queue messages.  We saw the same queued were checked multiple times w/in the interval.

Any help to eliminate the pauses is greatly appreciated.

Thanks

Re: Load testing 5.5 - broker pauses between sends

Posted by Joe Smith <jo...@yahoo.com>.
Hi,

Just another note on our test run w/5.4.2 version which was done earlier.  The broker does not exhibit the "pausing" behavior.  In fact, it actually achieve speed of 40k msg/sec on some occasions.

However, on a close examination of log and system stats.  We notice the following:

We were using the fileQueueCursor

1. Test producer sending at approx. 40k msg/sec non-persisted.

2. We saw many paging error messages in the broker log.


2011-07-28 20:44:40,270 | ERROR | Failed to page in more queue messages  | org.apache.activemq.broker.region.Queue | Queue:test.queue
java.lang.RuntimeException: java.lang.NullPointerException
        at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.getDiskList(FilePendingMessageCursor.java:444)
        at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.flushToDisk(FilePendingMessageCursor.java:423)
        at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.release(FilePendingMessageCursor.java:140)
        at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1696)
        at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1898)
        at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1425)
        at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:98)
        at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:36)
Caused by: java.lang.NullPointerException
        at org.apache.activemq.broker.region.cursors.FilePendingMessageCursor.getDiskList(FilePendingMessageCursor.java:441)
        ... 7 more


3. After variable number of above error messages - the memory usage shot up and the throughput increased to 40k msg/sec.  The page in exception stopped showing up in the log.

4. It maintain the throughput  until the next broker reboot.

5. The behavior is not consistent.  Most of the times the broker just repeats the page in exception and does not achieve the throughput.  The memory did not jump as before.

I believe there is a fix in 5.5 that maybe related to this issues.   Does the fix causing the "pausing" behavior?

Anyone can provide some insight?

Regards.

Re: Load testing 5.5 - broker pauses between sends

Posted by Joe Smith <jo...@yahoo.com>.
Hi Dejan,

Thanks for the reply.  We use the vmQueueCursor - for based on our benchmark - it give us better throughput than store and file cursors.  We've tried the systemUsage configs, giving spaces to memory, store, and temp space.  Seem to get the save results.  Do you have any recommendation that can keep the performance and be able recover from a temporary resource bottleneck?  This scenario is to simulate the link between our west coast and east cost was down - and msgs are continuing coming in.

Much Thanks


________________________________
From: Dejan Bosanac <de...@nighttale.net>
To: users@activemq.apache.org
Sent: Monday, August 1, 2011 11:27 AM
Subject: Re: Load testing 5.5 - broker pauses between sends

Hi,

what I noticed is that you are using VM Cursor for the test.queue.

That means that messages will be queued until there's enough memory for the
broker. You should use default store based cursor for your use case to work
properly.


Regards
-- 
Dejan Bosanac - http://twitter.com/dejanb
-----------------
The experts in open source integration and messaging - http://fusesource.com
ActiveMQ in Action - http://www.manning.com/snyder/
Blog - http://www.nighttale.net

Re: Load testing 5.5 - broker pauses between sends

Posted by Dejan Bosanac <de...@nighttale.net>.
Hi,

what I noticed is that you are using VM Cursor for the test.queue.

That means that messages will be queued until there's enough memory for the
broker. You should use default store based cursor for your use case to work
properly.


Regards
-- 
Dejan Bosanac - http://twitter.com/dejanb
-----------------
The experts in open source integration and messaging - http://fusesource.com
ActiveMQ in Action - http://www.manning.com/snyder/
Blog - http://www.nighttale.net


On Mon, Aug 1, 2011 at 2:46 PM, Joe Smith <jo...@yahoo.com> wrote:

> Another follow-up.  We let the job ran over the weekend.  We kill the
> consumers.  The messages eventually filled up the buffer.  The systemUsage
> is the default (commented out).   Assuming the msg will flow to disk until
> limit.   After we stopped the consumer for 24 hrs, we tried to connect the
> consumers.  The consumers keep getting time out error.  Jconsole and http
> admin won't connect as well.   The broker basically stopped functioning and
> won't accept any connections.  The only thing we could do was to stop and
> re-start the server.
>
> Anyone can provide tips on working around this issue?
>
> Regards

Re: Load testing 5.5 - broker pauses between sends

Posted by Joe Smith <jo...@yahoo.com>.
Another follow-up.  We let the job ran over the weekend.  We kill the consumers.  The messages eventually filled up the buffer.  The systemUsage is the default (commented out).   Assuming the msg will flow to disk until limit.   After we stopped the consumer for 24 hrs, we tried to connect the consumers.  The consumers keep getting time out error.  Jconsole and http admin won't connect as well.   The broker basically stopped functioning and won't accept any connections.  The only thing we could do was to stop and re-start the server.

Anyone can provide tips on working around this issue?

Regards

Re: Load testing 5.5 - broker pauses between sends

Posted by Joe Smith <jo...@yahoo.com>.
Sorry. Could not see the attachment.  Pasting it below.  Sorry for the long trace.


      
ActiveMQ - 5.5.0
JVM - 1.6
OS - Linux


        <destinationPolicy>
            <policyMap>
              <policyEntries>
                <policyEntry topic=">" producerFlowControl="true" memoryLimit="1mb">
                  <pendingSubscriberPolicy>
                    <vmCursor />
                  </pendingSubscriberPolicy>
                </policyEntry>
                  <!-- Use VM cursor for better latency
                       For more information, see:

                       http://activemq.apache.org/message-cursors.htmlß
                  -->
                <policyEntry queue="test.queue" producerFlowControl="false" memoryLimit="400 mb">
                  <pendingQueuePolicy>
                    <vmQueueCursor/>
                  </pendingQueuePolicy>
                </policyEntry>
              </policyEntries>
            </policyMap>
        </destinationPolicy>


        <persistenceAdapter>
            <kahaDB directory="${activemq.base}/data/kahadb"
                        concurrentStoreAndDispatchQueues="true"
                        concurrentStoreAndDispatchTopics="true"
                        cleanupInterval="60000"
                        checkpointInterval="5000"
                />
        </persistenceAdapter>


2011-07-29 22:07:38,603 | DEBUG | test.queue toPageIn: 200, Inflight: 12000, pagedInMessages.size 25160, enqueueCount: 6797729, dequeueCount: 6772328 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:07:38,603 | DEBUG | test.queue toPageIn: 200, Inflight: 11815, pagedInMessages.size 24974, enqueueCount: 6797729, dequeueCount: 6772513 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:07:38,604 | DEBUG | test.queue toPageIn: 200, Inflight: 11626, pagedInMessages.size 24786, enqueueCount: 6797729, dequeueCount: 6772702 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:07:38,604 | DEBUG | test.queue toPageIn: 200, Inflight: 11577, pagedInMessages.size 24736, enqueueCount: 6797729, dequeueCount: 6772751 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:07:38,608 | DEBUG | Main:memory: usage change from: 40% of available memory, to: 39% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,612 | DEBUG | Main:memory: usage change from: 39% of available memory, to: 38% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,613 | DEBUG | test.queue toPageIn: 200, Inflight: 11030, pagedInMessages.size 23758, enqueueCount: 6797729, dequeueCount: 6773729 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:07:38,617 | DEBUG | Main:memory: usage change from: 38% of available memory, to: 37% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,617 | DEBUG | test.queue toPageIn: 42, Inflight: 10779, pagedInMessages.size 23501, enqueueCount: 6797729, dequeueCount: 6774187 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:07:38,621 | DEBUG | Main:memory:queue://test.queue:memory: usage change from: 6% of available memory, to: 5% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,629 | DEBUG | Main:memory: usage change from: 37% of available memory, to: 36% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031 
2011-07-29 22:07:38,646 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
2011-07-29 22:07:38,658 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
2011-07-29 22:07:38,699 | DEBUG | Main:memory: usage change from: 36% of available memory, to: 35% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,708 | DEBUG | Main:memory: usage change from: 35% of available memory, to: 34% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,728 | DEBUG | Main:memory: usage change from: 34% of available memory, to: 33% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,747 | DEBUG | Main:memory: usage change from: 33% of available memory, to: 32% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,754 | DEBUG | Main:memory: usage change from: 32% of available memory, to: 31% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,757 | DEBUG | Main:memory:queue://test.queue:memory: usage change from: 5% of available memory, to: 4% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,760 | DEBUG | Main:memory: usage change from: 31% of available memory, to: 30% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031 
2011-07-29 22:07:38,800 | DEBUG | Main:memory: usage change from: 30% of available memory, to: 29% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,833 | DEBUG | Main:memory: usage change from: 29% of available memory, to: 28% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,839 | DEBUG | Main:memory: usage change from: 28% of available memory, to: 27% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,845 | DEBUG | Main:memory: usage change from: 27% of available memory, to: 26% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,852 | DEBUG | Main:memory: usage change from: 26% of available memory, to: 25% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,857 | DEBUG | Main:memory:queue://test.queue:memory: usage change from: 4% of available memory, to: 3% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,857 | DEBUG | Main:memory: usage change from: 25% of available memory, to: 24% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031 
2011-07-29 22:07:38,862 | DEBUG | Main:memory: usage change from: 24% of available memory, to: 23% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,867 | DEBUG | Main:memory: usage change from: 23% of available memory, to: 22% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,874 | DEBUG | Main:memory: usage change from: 22% of available memory, to: 21% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,887 | DEBUG | Main:memory: usage change from: 21% of available memory, to: 20% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:38,892 | DEBUG | Main:memory: usage change from: 20% of available memory, to: 19% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:07:40,535 | DEBUG | org.apache.activemq.transport.InactivityMonitor$2@7aaea288 10000 ms elapsed since last write check. | org.apache.activemq.transport.InactivityMonitor | InactivityMonitor WriteCheck
2011-07-29 22:07:40,723 | DEBUG | org.apache.activemq.transport.InactivityMonitor$2@66ae0840 10000 ms elapsed since last write check. | org.apache.activemq.transport.InactivityMonitor | InactivityMonitor WriteCheck
2011-07-29 22:07:40,724 | DEBUG | 29999 ms elapsed since last read check. | org.apache.activemq.transport.InactivityMonitor | InactivityMonitor ReadCheck
2011-07-29 22:07:43,338 | DEBUG | 29999 ms elapsed since last read check. | org.apache.activemq.transport.InactivityMonitor | InactivityMonitor ReadCheck
2011-07-29 22:07:43,338 | DEBUG | org.apache.activemq.transport.InactivityMonitor$2@6d657803 10001 ms elapsed since last write check. | org.apache.activemq.transport.InactivityMonitor | InactivityMonitor WriteCheck
2011-07-29 22:07:43,680 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
2011-07-29 22:07:43,684 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
2011-07-29 22:07:45,650 | DEBUG | queue://calculate.queue expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,650 | DEBUG | calculate.queue toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,650 | DEBUG | queue://calculate.queue expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,677 | DEBUG | queue://test.queue expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,677 | DEBUG | test.queue toPageIn: 0, Inflight: 11808, pagedInMessages.size 11808, enqueueCount: 6797729, dequeueCount: 6785921 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,683 | DEBUG | queue://test.queue expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,687 | DEBUG | queue://example.A expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,687 | DEBUG | example.A toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,687 | DEBUG | queue://example.A expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,704 | DEBUG | queue://test.queue expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,704 | DEBUG | test.queue toPageIn: 0, Inflight: 11808, pagedInMessages.size 11808, enqueueCount: 6797729, dequeueCount: 6785921 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,709 | DEBUG | queue://test.queue expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,709 | DEBUG | queue://results.queue expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,709 | DEBUG | results.queue toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,710 | DEBUG | queue://results.queue expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,710 | DEBUG | queue://example.A expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,710 | DEBUG | example.A toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,710 | DEBUG | queue://example.A expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,710 | DEBUG | queue://calculate.queue expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,710 | DEBUG | calculate.queue toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,710 | DEBUG | queue://calculate.queue expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,710 | DEBUG | queue://results.queue expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,710 | DEBUG | results.queue toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,710 | DEBUG | queue://results.queue expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[dev1.host] Scheduler
2011-07-29 22:07:45,819 | DEBUG | org.apache.activemq.transport.InactivityMonitor$2@76eb1327 10000 ms elapsed since last write check. | org.apache.activemq.transport.InactivityMonitor | InactivityMonitor WriteCheck
2011-07-29 22:07:48,705 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
2011-07-29 22:07:48,710 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
2011-07-29 22:07:50,534 | DEBUG | 29999 ms elapsed since last read check. | org.apache.activemq.transport.InactivityMonitor | InactivityMonitor ReadCheck
2011-07-29 22:07:50,534 | DEBUG | org.apache.activemq.transport.InactivityMonitor$2@7aaea288 9999 ms elapsed since last write check. | org.apache.activemq.transport.InactivityMonitor | InactivityMonitor WriteCheck
2011-07-29 22:07:50,722 | DEBUG | org.apache.activemq.transport.InactivityMonitor$2@66ae0840 9999 ms elapsed since last write check. | org.apache.activemq.transport.InactivityMonitor | InactivityMonitor WriteCheck
2011-07-29 22:07:53,338 | DEBUG | org.apache.activemq.transport.InactivityMonitor$2@6d657803 10000 ms elapsed since last write check. | org.apache.activemq.transport.InactivityMonitor | InactivityMonitor WriteCheck
2011-07-29 22:07:53,731 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
2011-07-29 22:07:53,736 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
2011-07-29 22:07:55,818 | DEBUG | 29999 ms elapsed since last read check. | org.apache.activemq.transport.InactivityMonitor | InactivityMonitor ReadCheck
2011-07-29 22:07:55,819 | DEBUG | org.apache.activemq.transport.InactivityMonitor$2@76eb1327 10000 ms elapsed since last write check. | org.apache.activemq.transport.InactivityMonitor | InactivityMonitor WriteCheck
2011-07-29 22:07:58,756 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
2011-07-29 22:07:58,762 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
2011-07-29 22:08:00,534 | DEBUG | org.apache.activemq.transport.InactivityMonitor$2@7aaea288 10000 ms elapsed since last write check. | org.apache.activemq.transport.InactivityMonitor | InactivityMonitor WriteCheck
2011-07-29 22:08:00,723 | DEBUG | org.apache.activemq.transport.InactivityMonitor$2@66ae0840 10001 ms elapsed since last write check. | org.apache.activemq.transport.InactivityMonitor | InactivityMonitor WriteCheck
2011-07-29 22:08:03,214 | DEBUG | test.queue toPageIn: 1, Inflight: 11808, pagedInMessages.size 11808, enqueueCount: 6797730, dequeueCount: 6785921 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:08:03,216 | DEBUG | Main:memory: usage change from: 19% of available memory, to: 18% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:08:03,217 | DEBUG | Main:memory:queue://test.queue:memory: usage change from: 3% of available memory, to: 2% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:08:03,217 | DEBUG | test.queue toPageIn: 1, Inflight: 11591, pagedInMessages.size 11592, enqueueCount: 6797732, dequeueCount: 6786139 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:08:03,217 | DEBUG | test.queue toPageIn: 1, Inflight: 11561, pagedInMessages.size 11562, enqueueCount: 6797732, dequeueCount: 6786169 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:08:03,218 | DEBUG | test.queue toPageIn: 2, Inflight: 11356, pagedInMessages.size 11356, enqueueCount: 6797734, dequeueCount: 6786376 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:08:03,218 | DEBUG | test.queue toPageIn: 6, Inflight: 11356, pagedInMessages.size 11358, enqueueCount: 6797740, dequeueCount: 6786376 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:08:03,218 | DEBUG | test.queue toPageIn: 7, Inflight: 11359, pagedInMessages.size 11364, enqueueCount: 6797747, dequeueCount: 6786376 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:08:03,218 | DEBUG | test.queue toPageIn: 5, Inflight: 11369, pagedInMessages.size 11371, enqueueCount: 6797752, dequeueCount: 6786376 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:08:03,219 | DEBUG | test.queue toPageIn: 2, Inflight: 11376, pagedInMessages.size 11376, enqueueCount: 6797753, dequeueCount: 6786376 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:08:03,221 | DEBUG | Main:memory: usage change from: 18% of available memory, to: 17% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:08:03,221 | DEBUG | test.queue toPageIn: 79, Inflight: 11020, pagedInMessages.size 11020, enqueueCount: 6797833, dequeueCount: 6786735 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:08:03,229 | DEBUG | Main:memory: usage change from: 17% of available memory, to: 16% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:08:03,238 | DEBUG | Main:memory: usage change from: 16% of available memory, to: 15% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:08:03,244 | DEBUG | Main:memory: usage change from: 15% of available memory, to: 14% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:08:03,245 | DEBUG | Main:memory: usage change from: 14% of available memory, to: 15% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.39:49454
2011-07-29 22:08:03,246 | DEBUG | test.queue toPageIn: 200, Inflight: 8217, pagedInMessages.size 8235, enqueueCount: 6798907, dequeueCount: 6789598 | org.apache.activemq.broker.region.Queue | Queue:test.queue
2011-07-29 22:08:03,247 | DEBUG | Main:memory: usage change from: 15% of available memory, to: 14% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:08:03,252 | DEBUG | Main:memory: usage change from: 14% of available memory, to: 13% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031
2011-07-29 22:08:03,259 | DEBUG | Main:memory: usage change from: 13% of available memory, to: 12% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///94.14.59.38:55031