Slow broker response time in ActiveMQ 5.6
We have a setup where user generates report using SOAP over ActiveMQ with Jboss 5.1.0 as the AS. Our project is migrating from ActiveMQ 4 to ActiveMQ 5.6 and we have noticed with the default configuration, the time of generation of one of the reports has increased by 50 secs. This particular report consists of the maximum amount of data among all others, and the other reports are all showing response times close to our earlier setup. So we are suspecting it has to do with some setting wherein the message queue is not able to handle larger data. We have checked and the time from database to return the query result is identical, and this extra 50 sec is coming in ActiveMQ. Here is the log file extract (DEBUG enabled) for our older implementation (ActiveMQ 4.0):


    2012-06-13 05:21:18,909 [iveMQ Scheduler] DEBUG InactivityMonitor              - No message sent since last write check, sending a KeepAliveInfo
    2012-06-13 05:21:18,909 [iveMQ Scheduler] DEBUG InactivityMonitor              - Message received since last read check, resetting flag: 
    2012-06-13 05:21:33,909 [iveMQ Scheduler] DEBUG InactivityMonitor              - No message sent since last write check, sending a KeepAliveInfo
    2012-06-13 05:21:48,909 [iveMQ Scheduler] DEBUG InactivityMonitor              - No message sent since last write check, sending a KeepAliveInfo
    2012-06-13 05:21:48,909 [iveMQ Scheduler] DEBUG InactivityMonitor              - Message received since last read check, resetting flag: 
    2012-06-13 05:21:58,561 [127.0.0.1:52937] DEBUG UsageManager                   - Memory usage change.  from: 0, to: 9
    2012-06-13 05:21:58,698 [127.0.0.1:52937] DEBUG JournalMessageStore            - Journalled transacted message add for: ID:dayrhevidq001.enterprisenet.org-48380-1339578768566-1:0:5:1:1, at: 917:5857443
    2012-06-13 05:21:58,733 [127.0.0.1:52937] DEBUG JournalMessageStore            - Transacted message add commit for: ID:dayrhevidq001.enterprisenet.org-48380-1339578768566-1:0:5:1:1, at: 917:5857443
    2012-06-13 05:21:58,738 [127.0.0.1:52937] DEBUG JournalMessageStore            - Journalled transacted message remove for: ID:dayrhevidq001.enterprisenet.org-48380-1339578768566-1:0:12:1:1, at: 917:6886127
    2012-06-13 05:21:59,126 [127.0.0.1:52937] DEBUG JournalMessageStore            - Transacted message remove commit for: ID:dayrhevidq001.enterprisenet.org-48380-1339578768566-1:0:12:1:1, at: 917:6886127
    2012-06-13 05:22:01,034 [127.0.0.1:52937] DEBUG JournalMessageStore            - Journalled transacted message remove for: ID:dayrhevidq001.enterprisenet.org-48380-1339578768566-1:0:5:1:1, at: 917:6886676
    2012-06-13 05:22:01,233 [127.0.0.1:52937] DEBUG JournalMessageStore            - Transacted message remove commit for: ID:dayrhevidq001.enterprisenet.org-48380-1339578768566-1:0:5:1:1, at: 917:6886676
    2012-06-13 05:22:01,233 [127.0.0.1:52937] DEBUG UsageManager                   - Memory usage change.  from: 9, to: 0
    2012-06-13 05:22:03,907 [iveMQ Scheduler] DEBUG InactivityMonitor              - Message sent since last write check, resetting flag
    2012-06-13 05:22:18,909 [iveMQ Scheduler] DEBUG InactivityMonitor              - No message sent since last write check, sending a KeepAliveInf

and here is the one from the migrated implementation (ActiveMQ 5.6):

    2012-06-11 02:04:18,755 | DEBUG | commit: TX:ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:4 syncCount: 2 | org.apache.activemq.transaction.LocalTransaction | ActiveMQ Transport: tcp:///127.0.0.1:60907
    2012-06-11 02:04:18,759 | TRACE | ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:19:1 dispatched: ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:5:1:1 - queue://dav/synchronizer, dispatched: 1, inflight: 1 | org.apache.activemq.broker.region.PrefetchSubscription | BrokerService[localhost] Task-6
    2012-06-11 02:04:19,105 | TRACE | ack:MessageAck {commandId = 75, responseRequired = false, ackType = 2, consumerId = ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:19:1, firstMessageId = ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:5:1:1, lastMessageId = ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:5:1:1, destination = queue://dav/synchronizer, transactionId = TX:ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:6, messageCount = 1, poisonCause = null} | org.apache.activemq.broker.region.PrefetchSubscription | ActiveMQ Transport: tcp:///127.0.0.1:60907
    2012-06-11 02:04:19,108 | DEBUG | commit: TX:ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:6 syncCount: 2 | org.apache.activemq.transaction.LocalTransaction | ActiveMQ Transport: tcp:///127.0.0.1:60907
    2012-06-11 02:04:19,110 | DEBUG | Main:memory:queue://dav/synchronizer:memory: usage change from: 1% of available memory, to: 0% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///127.0.0.1:60907
    2012-06-11 02:04:19,110 | DEBUG | Main:memory: usage change from: 1% of available memory, to: 0% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///127.0.0.1:60907
    2012-06-11 02:04:20,592 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:20,700 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:25,725 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:25,734 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:30,755 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:30,762 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:35,785 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:35,795 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:38,523 | DEBUG | queue://dav/validator expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:38,524 | DEBUG | dav/validator toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:38,524 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@e0420b:dav/validator,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:38,524 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@e0420b:dav/validator,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:38,524 | DEBUG | queue://dav/validator expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | DEBUG | queue://dav/logger expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | DEBUG | dav/logger toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 1, dequeueCount: 1 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1c64ed8:dav/logger,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1c64ed8:dav/logger,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | DEBUG | queue://dav/logger expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | DEBUG | queue://dav/synchronizer expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | DEBUG | dav/synchronizer toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 1, dequeueCount: 1 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1549ceb:dav/synchronizer,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1549ceb:dav/synchronizer,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | DEBUG | queue://dav/synchronizer expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | DEBUG | queue://dav/executor expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | DEBUG | dav/executor toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 1, dequeueCount: 1 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@9b777a:dav/executor,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@9b777a:dav/executor,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | DEBUG | queue://dav/executor expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | DEBUG | queue://dav/synchronizer expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | DEBUG | dav/synchronizer toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 1, dequeueCount: 1 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1549ceb:dav/synchronizer,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1549ceb:dav/synchronizer,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | DEBUG | queue://dav/synchronizer expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | queue://dav/validator expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | dav/validator toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@e0420b:dav/validator,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@e0420b:dav/validator,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | queue://dav/validator expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | queue://dav/cacher expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | dav/cacher toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@626fd2:dav/cacher,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@626fd2:dav/cacher,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | queue://dav/cacher expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | queue://dav/executor expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | dav/executor toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 1, dequeueCount: 1 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@9b777a:dav/executor,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@9b777a:dav/executor,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | DEBUG | queue://dav/executor expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | DEBUG | queue://dav/logger expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | DEBUG | dav/logger toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 1, dequeueCount: 1 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1c64ed8:dav/logger,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1c64ed8:dav/logger,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | DEBUG | queue://dav/logger expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | DEBUG | queue://dav/cacher expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | DEBUG | dav/cacher toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@626fd2:dav/cacher,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,828 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@626fd2:dav/cacher,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,828 | DEBUG | queue://dav/cacher expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:40,814 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:40,831 | TRACE | Last update: 2:2257550, full gc candidates set: [2] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:40,831 | TRACE | gc candidates after first tx:2:2257550, [] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:40,831 | TRACE | gc candidates: [] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:40,831 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:45,851 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:45,860 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:50,880 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:50,890 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:55,910 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:55,924 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:00,943 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:00,957 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:05,979 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:05,988 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:08,524 | DEBUG | queue://dav/validator expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:08,525 | DEBUG | dav/validator toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:08,525 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@e0420b:dav/validator,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:08,525 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@e0420b:dav/validator,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:08,525 | DEBUG | queue://dav/validator expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:09,825 | DEBUG | queue://dav/logger expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:09,825 | DEBUG | dav/logger toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 1, dequeueCount: 1 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    <some lines removed to save space>
    2012-06-11 02:05:09,828 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@626fd2:dav/cacher,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:09,828 | DEBUG | queue://dav/cacher expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:11,008 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:11,017 | TRACE | Last update: 2:2279306, full gc candidates set: [2] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:11,017 | TRACE | gc candidates after first tx:2:2279306, [] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:11,017 | TRACE | gc candidates: [] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:11,017 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:14,368 | DEBUG | Cleaning up expired web clients. | org.apache.activemq.web.MessageListenerServlet | Timer-0
    2012-06-11 02:05:14,783 | DEBUG | Cleaning up expired web clients. | org.apache.activemq.web.MessageListenerServlet | Timer-1

Here is my ActiveMQ.xml file:

    <!--
        Licensed to the Apache Software Foundation (ASF) under one or more
        contributor license agreements.  See the NOTICE file distributed with
        this work for additional information regarding copyright ownership.
        The ASF licenses this file to You under the Apache License, Version 2.0
        (the "License"); you may not use this file except in compliance with
        the License.  You may obtain a copy of the License at
    
        http://www.apache.org/licenses/LICENSE-2.0
    
        Unless required by applicable law or agreed to in writing, software
        distributed under the License is distributed on an "AS IS" BASIS,
        WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
        See the License for the specific language governing permissions and
        limitations under the License.
    -->
    <!-- START SNIPPET: example -->
    <beans
      xmlns="http://www.springframework.org/schema/beans"
      xmlns:amq="http://activemq.apache.org/schema/core"
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
      xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-2.0.xsd
      http://activemq.apache.org/schema/core http://activemq.apache.org/schema/core/activemq-core.xsd">
    
        <!-- Allows us to use system properties as variables in this configuration file -->
        <bean class="org.springframework.beans.factory.config.PropertyPlaceholderConfigurer">
            <property name="locations">
                <value>file:${activemq.conf}/credentials.properties</value>
            </property>
        </bean>
    
        <!--
            The <broker> element is used to configure the ActiveMQ broker.
        -->
        <broker xmlns="http://activemq.apache.org/schema/core" brokerName="localhost" dataDirectory="${activemq.data}" 
    		useShutdownHook="false" useJmx="true" persistent="false">
    
            <!--
                For better performances use VM cursor and small memory limit.
                For more information, see:
    
                http://activemq.apache.org/message-cursors.html
    
                Also, if your producer is "hanging", it's probably due to producer flow control.
                For more information, see:
                http://activemq.apache.org/producer-flow-control.html
            -->
      <!--
            <destinationPolicy>
          <policyMap><policyEntries>
            
              <policyEntry topic="FOO.>">
                <dispatchPolicy>
                  <strictOrderDispatchPolicy />
                </dispatchPolicy>
                <subscriptionRecoveryPolicy>
                  <lastImageSubscriptionRecoveryPolicy />
                </subscriptionRecoveryPolicy>
              </policyEntry>
    
          </policyEntries></policyMap>
        </destinationPolicy>
      -->
    
    <destinationPolicy>
                <policyMap>
                  <policyEntries>
                    <policyEntry topic=">" producerFlowControl="false" memoryLimit="1mb">
                      <pendingSubscriberPolicy>
                        <vmCursor />
                      </pendingSubscriberPolicy>
                    </policyEntry>
                    <policyEntry queue=">" producerFlowControl="false" memoryLimit="1mb">
                      <!-- Use VM cursor for better latency
                           For more information, see:
    
                           http://activemq.apache.org/message-cursors.html
    
                      <pendingQueuePolicy>
                        <vmQueueCursor/>
                      </pendingQueuePolicy>
                      -->
                    </policyEntry>
                  </policyEntries>
                </policyMap>
            </destinationPolicy>
            <!--
                The managementContext is used to configure how ActiveMQ is exposed in
                JMX. By default, ActiveMQ uses the MBean server that is started by
                the JVM. For more information, see:
    
                http://activemq.apache.org/jmx.html
            -->
            <managementContext>
                <managementContext createConnector="false"/>
            </managementContext>
    
            <!--
                Configure message persistence for the broker. The default persistence
                mechanism is the KahaDB store (identified by the kahaDB tag).
                For more information, see:
    
                http://activemq.apache.org/persistence.html
            -->
            <persistenceAdapter>
                <kahaDB directory="${activemq.data}/kahadb"/>
            </persistenceAdapter>
    
    
              <!--
                The systemUsage controls the maximum amount of space the broker will
                use before slowing down producers. For more information, see:
                http://activemq.apache.org/producer-flow-control.html
                If using ActiveMQ embedded - the following limits could safely be used:
    
            <systemUsage>
                <systemUsage>
                    <memoryUsage>
                        <memoryUsage limit="20 mb"/>
                    </memoryUsage>
                    <storeUsage>
                        <storeUsage limit="1 gb"/>
                    </storeUsage>
                    <tempUsage>
                        <tempUsage limit="100 mb"/>
                    </tempUsage>
                </systemUsage>
            </systemUsage>
            
              <systemUsage>
                <systemUsage>
                    <memoryUsage>
                        <memoryUsage limit="64 mb"/>
                    </memoryUsage>
                    <storeUsage>
                        <storeUsage limit="100 gb"/>
                    </storeUsage>
                    <tempUsage>
                        <tempUsage limit="50 gb"/>
                    </tempUsage>
                </systemUsage>
            </systemUsage>-->
    
            <!--
                The transport connectors expose ActiveMQ over a given protocol to
                clients and other brokers. For more information, see:
    
                http://activemq.apache.org/configuring-transports.html
            -->
            <transportConnectors>
                <transportConnector name="default" uri="tcp://localhost:61616?jms.useAsyncSend=true&amp;jms.prefetchPolicy.all=10&amp;wireFormat.maxInactivityDuration=0" discoveryUri="multicast://default"/>
            </transportConnectors>
    
        <
Slow broker response time in ActiveMQ 5.6
===

We have a setup where user generates report using SOAP over ActiveMQ with Jboss 5.1.0 as the AS. Our project is migrating from ActiveMQ 4 to ActiveMQ 5.6 and we have noticed with the default configuration, the time of generation of one of the reports has increased by 50 secs. This particular report consists of the maximum amount of data among all others, and the other reports are all showing response times close to our earlier setup. So we are suspecting it has to do with some setting wherein the message queue is not able to handle larger data. We have checked and the time from database to return the query result is identical, and this extra 50 sec is coming in ActiveMQ. Here is the log file extract (DEBUG enabled) for our older implementation (ActiveMQ 4.0):


    2012-06-13 05:21:18,909 [iveMQ Scheduler] DEBUG InactivityMonitor              - No message sent since last write check, sending a KeepAliveInfo
    2012-06-13 05:21:18,909 [iveMQ Scheduler] DEBUG InactivityMonitor              - Message received since last read check, resetting flag: 
    2012-06-13 05:21:33,909 [iveMQ Scheduler] DEBUG InactivityMonitor              - No message sent since last write check, sending a KeepAliveInfo
    2012-06-13 05:21:48,909 [iveMQ Scheduler] DEBUG InactivityMonitor              - No message sent since last write check, sending a KeepAliveInfo
    2012-06-13 05:21:48,909 [iveMQ Scheduler] DEBUG InactivityMonitor              - Message received since last read check, resetting flag: 
    2012-06-13 05:21:58,561 [127.0.0.1:52937] DEBUG UsageManager                   - Memory usage change.  from: 0, to: 9
    2012-06-13 05:21:58,698 [127.0.0.1:52937] DEBUG JournalMessageStore            - Journalled transacted message add for: ID:dayrhevidq001.enterprisenet.org-48380-1339578768566-1:0:5:1:1, at: 917:5857443
    2012-06-13 05:21:58,733 [127.0.0.1:52937] DEBUG JournalMessageStore            - Transacted message add commit for: ID:dayrhevidq001.enterprisenet.org-48380-1339578768566-1:0:5:1:1, at: 917:5857443
    2012-06-13 05:21:58,738 [127.0.0.1:52937] DEBUG JournalMessageStore            - Journalled transacted message remove for: ID:dayrhevidq001.enterprisenet.org-48380-1339578768566-1:0:12:1:1, at: 917:6886127
    2012-06-13 05:21:59,126 [127.0.0.1:52937] DEBUG JournalMessageStore            - Transacted message remove commit for: ID:dayrhevidq001.enterprisenet.org-48380-1339578768566-1:0:12:1:1, at: 917:6886127
    2012-06-13 05:22:01,034 [127.0.0.1:52937] DEBUG JournalMessageStore            - Journalled transacted message remove for: ID:dayrhevidq001.enterprisenet.org-48380-1339578768566-1:0:5:1:1, at: 917:6886676
    2012-06-13 05:22:01,233 [127.0.0.1:52937] DEBUG JournalMessageStore            - Transacted message remove commit for: ID:dayrhevidq001.enterprisenet.org-48380-1339578768566-1:0:5:1:1, at: 917:6886676
    2012-06-13 05:22:01,233 [127.0.0.1:52937] DEBUG UsageManager                   - Memory usage change.  from: 9, to: 0
    2012-06-13 05:22:03,907 [iveMQ Scheduler] DEBUG InactivityMonitor              - Message sent since last write check, resetting flag
    2012-06-13 05:22:18,909 [iveMQ Scheduler] DEBUG InactivityMonitor              - No message sent since last write check, sending a KeepAliveInf

and here is the one from the migrated implementation (ActiveMQ 5.6):

    2012-06-11 02:04:18,755 | DEBUG | commit: TX:ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:4 syncCount: 2 | org.apache.activemq.transaction.LocalTransaction | ActiveMQ Transport: tcp:///127.0.0.1:60907
    2012-06-11 02:04:18,759 | TRACE | ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:19:1 dispatched: ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:5:1:1 - queue://dav/synchronizer, dispatched: 1, inflight: 1 | org.apache.activemq.broker.region.PrefetchSubscription | BrokerService[localhost] Task-6
    2012-06-11 02:04:19,105 | TRACE | ack:MessageAck {commandId = 75, responseRequired = false, ackType = 2, consumerId = ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:19:1, firstMessageId = ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:5:1:1, lastMessageId = ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:5:1:1, destination = queue://dav/synchronizer, transactionId = TX:ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:6, messageCount = 1, poisonCause = null} | org.apache.activemq.broker.region.PrefetchSubscription | ActiveMQ Transport: tcp:///127.0.0.1:60907
    2012-06-11 02:04:19,108 | DEBUG | commit: TX:ID:nrisjctls01.dev.netratings.com-60906-1339405160583-1:1:6 syncCount: 2 | org.apache.activemq.transaction.LocalTransaction | ActiveMQ Transport: tcp:///127.0.0.1:60907
    2012-06-11 02:04:19,110 | DEBUG | Main:memory:queue://dav/synchronizer:memory: usage change from: 1% of available memory, to: 0% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///127.0.0.1:60907
    2012-06-11 02:04:19,110 | DEBUG | Main:memory: usage change from: 1% of available memory, to: 0% of available memory | org.apache.activemq.usage.Usage | ActiveMQ Transport: tcp:///127.0.0.1:60907
    2012-06-11 02:04:20,592 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:20,700 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:25,725 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:25,734 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:30,755 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:30,762 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:35,785 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:35,795 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:38,523 | DEBUG | queue://dav/validator expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:38,524 | DEBUG | dav/validator toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:38,524 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@e0420b:dav/validator,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:38,524 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@e0420b:dav/validator,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:38,524 | DEBUG | queue://dav/validator expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | DEBUG | queue://dav/logger expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | DEBUG | dav/logger toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 1, dequeueCount: 1 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1c64ed8:dav/logger,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1c64ed8:dav/logger,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | DEBUG | queue://dav/logger expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | DEBUG | queue://dav/synchronizer expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | DEBUG | dav/synchronizer toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 1, dequeueCount: 1 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,824 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1549ceb:dav/synchronizer,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1549ceb:dav/synchronizer,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | DEBUG | queue://dav/synchronizer expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | DEBUG | queue://dav/executor expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | DEBUG | dav/executor toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 1, dequeueCount: 1 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@9b777a:dav/executor,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@9b777a:dav/executor,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | DEBUG | queue://dav/executor expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | DEBUG | queue://dav/synchronizer expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | DEBUG | dav/synchronizer toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 1, dequeueCount: 1 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1549ceb:dav/synchronizer,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1549ceb:dav/synchronizer,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,825 | DEBUG | queue://dav/synchronizer expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | queue://dav/validator expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | dav/validator toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@e0420b:dav/validator,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@e0420b:dav/validator,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | queue://dav/validator expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | queue://dav/cacher expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | dav/cacher toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@626fd2:dav/cacher,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@626fd2:dav/cacher,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | queue://dav/cacher expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | queue://dav/executor expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,826 | DEBUG | dav/executor toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 1, dequeueCount: 1 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@9b777a:dav/executor,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@9b777a:dav/executor,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | DEBUG | queue://dav/executor expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | DEBUG | queue://dav/logger expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | DEBUG | dav/logger toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 1, dequeueCount: 1 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1c64ed8:dav/logger,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1c64ed8:dav/logger,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | DEBUG | queue://dav/logger expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | DEBUG | queue://dav/cacher expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | DEBUG | dav/cacher toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,827 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@626fd2:dav/cacher,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,828 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@626fd2:dav/cacher,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:39,828 | DEBUG | queue://dav/cacher expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:04:40,814 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:40,831 | TRACE | Last update: 2:2257550, full gc candidates set: [2] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:40,831 | TRACE | gc candidates after first tx:2:2257550, [] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:40,831 | TRACE | gc candidates: [] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:40,831 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:45,851 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:45,860 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:50,880 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:50,890 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:55,910 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:04:55,924 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:00,943 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:00,957 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:05,979 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:05,988 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:08,524 | DEBUG | queue://dav/validator expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:08,525 | DEBUG | dav/validator toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:08,525 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@e0420b:dav/validator,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:08,525 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@e0420b:dav/validator,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:08,525 | DEBUG | queue://dav/validator expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:09,825 | DEBUG | queue://dav/logger expiring messages .. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:09,825 | DEBUG | dav/logger toPageIn: 0, Inflight: 0, pagedInMessages.size 0, enqueueCount: 1, dequeueCount: 1 | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    <some lines removed to save space>
    2012-06-11 02:05:09,828 | TRACE | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@626fd2:dav/cacher,batchResetNeeded=false,storeHasMessages=false,size=0,cacheEnabled=true - fillBatch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:09,828 | DEBUG | queue://dav/cacher expiring messages done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[localhost] Scheduler
    2012-06-11 02:05:11,008 | DEBUG | Checkpoint started. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:11,017 | TRACE | Last update: 2:2279306, full gc candidates set: [2] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:11,017 | TRACE | gc candidates after first tx:2:2279306, [] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:11,017 | TRACE | gc candidates: [] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:11,017 | DEBUG | Checkpoint done. | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker
    2012-06-11 02:05:14,368 | DEBUG | Cleaning up expired web clients. | org.apache.activemq.web.MessageListenerServlet | Timer-0
    2012-06-11 02:05:14,783 | DEBUG | Cleaning up expired web clients. | org.apache.activemq.web.MessageListenerServlet | Timer-1

Here is my ActiveMQ.xml file:

    <!--
        Licensed to the Apache Software Foundation (ASF) under one or more
        contributor license agreements.  See the NOTICE file distributed with
        this work for additional information regarding copyright ownership.
        The ASF licenses this file to You under the Apache License, Version 2.0
        (the "License"); you may not use this file except in compliance with
        the License.  You may obtain a copy of the License at
    
        http://www.apache.org/licenses/LICENSE-2.0
    
        Unless required by applicable law or agreed to in writing, software
        distributed under the License is distributed on an "AS IS" BASIS,
        WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
        See the License for the specific language governing permissions and
        limitations under the License.
    -->
    <!-- START SNIPPET: example -->
    <beans
      xmlns="http://www.springframework.org/schema/beans"
      xmlns:amq="http://activemq.apache.org/schema/core"
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
      xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-2.0.xsd
      http://activemq.apache.org/schema/core http://activemq.apache.org/schema/core/activemq-core.xsd">
    
        <!-- Allows us to use system properties as variables in this configuration file -->
        <bean class="org.springframework.beans.factory.config.PropertyPlaceholderConfigurer">
            <property name="locations">
                <value>file:${activemq.conf}/credentials.properties</value>
            </property>
        </bean>
    
        <!--
            The <broker> element is used to configure the ActiveMQ broker.
        -->
        <broker xmlns="http://activemq.apache.org/schema/core" brokerName="localhost" dataDirectory="${activemq.data}" 
    		useShutdownHook="false" useJmx="true" persistent="false">
    
            <!--
                For better performances use VM cursor and small memory limit.
                For more information, see:
    
                http://activemq.apache.org/message-cursors.html
    
                Also, if your producer is "hanging", it's probably due to producer flow control.
                For more information, see:
                http://activemq.apache.org/producer-flow-control.html
            -->
      <!--
            <destinationPolicy>
          <policyMap><policyEntries>
            
              <policyEntry topic="FOO.>">
                <dispatchPolicy>
                  <strictOrderDispatchPolicy />
                </dispatchPolicy>
                <subscriptionRecoveryPolicy>
                  <lastImageSubscriptionRecoveryPolicy />
                </subscriptionRecoveryPolicy>
              </policyEntry>
    
          </policyEntries></policyMap>
        </destinationPolicy>
      -->
    
    <destinationPolicy>
                <policyMap>
                  <policyEntries>
                    <policyEntry topic=">" producerFlowControl="false" memoryLimit="1mb">
                      <pendingSubscriberPolicy>
                        <vmCursor />
                      </pendingSubscriberPolicy>
                    </policyEntry>
                    <policyEntry queue=">" producerFlowControl="false" memoryLimit="1mb">
                      <!-- Use VM cursor for better latency
                           For more information, see:
    
                           http://activemq.apache.org/message-cursors.html
    
                      <pendingQueuePolicy>
                        <vmQueueCursor/>
                      </pendingQueuePolicy>
                      -->
                    </policyEntry>
                  </policyEntries>
                </policyMap>
            </destinationPolicy>
            <!--
                The managementContext is used to configure how ActiveMQ is exposed in
                JMX. By default, ActiveMQ uses the MBean server that is started by
                the JVM. For more information, see:
    
                http://activemq.apache.org/jmx.html
            -->
            <managementContext>
                <managementContext createConnector="false"/>
            </managementContext>
    
            <!--
                Configure message persistence for the broker. The default persistence
                mechanism is the KahaDB store (identified by the kahaDB tag).
                For more information, see:
    
                http://activemq.apache.org/persistence.html
            -->
            <persistenceAdapter>
                <kahaDB directory="${activemq.data}/kahadb"/>
            </persistenceAdapter>
    
    
              <!--
                The systemUsage controls the maximum amount of space the broker will
                use before slowing down producers. For more information, see:
                http://activemq.apache.org/producer-flow-control.html
                If using ActiveMQ embedded - the following limits could safely be used:
    
            <systemUsage>
                <systemUsage>
                    <memoryUsage>
                        <memoryUsage limit="20 mb"/>
                    </memoryUsage>
                    <storeUsage>
                        <storeUsage limit="1 gb"/>
                    </storeUsage>
                    <tempUsage>
                        <tempUsage limit="100 mb"/>
                    </tempUsage>
                </systemUsage>
            </systemUsage>
            
              <systemUsage>
                <systemUsage>
                    <memoryUsage>
                        <memoryUsage limit="64 mb"/>
                    </memoryUsage>
                    <storeUsage>
                        <storeUsage limit="100 gb"/>
                    </storeUsage>
                    <tempUsage>
                        <tempUsage limit="50 gb"/>
                    </tempUsage>
                </systemUsage>
            </systemUsage>-->
    
            <!--
                The transport connectors expose ActiveMQ over a given protocol to
                clients and other brokers. For more information, see:
    
                http://activemq.apache.org/configuring-transports.html
            -->
            <transportConnectors>
                <transportConnector name="default" uri="tcp://localhost:61616?jms.useAsyncSend=true&amp;jms.prefetchPolicy.all=10&amp;wireFormat.maxInactivityDuration=0" discoveryUri="multicast://default"/>
            </transportConnectors>
    
        <