You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by Cybexion <cy...@email.de> on 2009/02/13 09:11:45 UTC
Memoryleak when consuming messages from KahaDBStore
Hello,
I'm working with the lastest 5.3 trunk and using the new KahaDBStore.
Last night I made a test:
I have a queue that contained >30 Mio messages. I started 20 consumers to
empty the queue.
The consumers are running in their own VM. While retrieving messages from
AMW the memory consumption of AMQ was constantly increasing.
Currently the logs look like this:
2009-02-13 09:08:33,461 [nitor ReadCheck] DEBUG
.transport.InactivityMonitor$1 - 24404 ms elapsed since last read check.
2009-02-13 09:08:33,462 [itor WriteCheck] DEBUG
.transport.InactivityMonitor$2 - 7049 ms elapsed since last write check.
2009-02-13 09:08:33,462 [nitor ReadCheck] DEBUG
.transport.InactivityMonitor$1 - Aborting read check.. Not enough time
elapsed since last read check.
2009-02-13 09:08:39,213 [itor WriteCheck] DEBUG
.transport.InactivityMonitor$2 - 12800 ms elapsed since last write check.
2009-02-13 09:08:44,971 [itor WriteCheck] DEBUG
.transport.InactivityMonitor$2 - 11510 ms elapsed since last write check.
2009-02-13 09:08:44,971 [itor WriteCheck] DEBUG
.transport.InactivityMonitor$2 - 11509 ms elapsed since last write check.
2009-02-13 09:08:44,971 [itor WriteCheck] DEBUG
.transport.InactivityMonitor$2 - 5758 ms elapsed since last write check.
2009-02-13 09:08:57,766 [nitor ReadCheck] DEBUG
.transport.InactivityMonitor$1 - 31354 ms elapsed since last read check.
The GC says:
INFO | jvm 1 | 2009/02/13 09:09:28 | 70626.930: [Full GC
INFO | jvm 1 | 2009/02/13 09:09:33 | [PSYoungGen:
67968K->22723K(84416K)] [PSOldGen: 2519039K->2519039K(2519040K)]
2587007K->2541763K(2603456K) [PSP
ermGen: 28288K->28288K(28352K)] GC time is exceeding GCTimeLimit of
98%
INFO | jvm 1 | 2009/02/13 09:09:33 | , 5.8210250 secs] [Times:
user=5.80 sys=0.01, real=5.82 secs]
INFO | jvm 1 | 2009/02/13 09:09:33 | 70632.812: [Full GC
INFO | jvm 1 | 2009/02/13 09:09:39 | [PSYoungGen:
67968K->22941K(84416K)] [PSOldGen: 2519039K->2519039K(2519040K)]
2587007K->2541981K(2603456K) [PSP
ermGen: 28294K->28294K(28352K)] GC time would exceed GCTimeLimit of
98%
INFO | jvm 1 | 2009/02/13 09:09:39 | , 5.8349920 secs] [Times:
user=5.82 sys=0.01, real=5.83 secs]
INFO | jvm 1 | 2009/02/13 09:09:39 | 70638.708: [Full GC
INFO | jvm 1 | 2009/02/13 09:09:46 | [PSYoungGen:
67968K->20009K(84416K)] [PSOldGen: 2519039K->2519039K(2519040K)]
2587007K->2539049K(2603456K) [PSP
ermGen: 28299K->28277K(28352K)] GC time would exceed GCTimeLimit of
98%
Here are my AMQ settings:
<bean id="store"
class="org.apache.activemq.store.kahadb.KahaDBStore">
<property name="directory" value="${activemq.base}/data"/>
<property name="checkpointInterval" value="5000"/>
<property name="cleanupInterval" value="5000"/>
<property name="journalMaxFileLength" value="10000000"/>
<property name="indexWriteBatchSize" value="100" />
<property name="enableIndexWriteAsync" value="true" />
</bean>
Is there anything I can additionally check?
Regards
Jörg
--
View this message in context: http://www.nabble.com/Memoryleak-when-consuming-messages-from-KahaDBStore-tp21991929p21991929.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: Memoryleak when consuming messages from KahaDBStore
Posted by Gary Tully <ga...@gmail.com>.
Jörg,
I finally did some analysis with yourkit today and indeed there is a
memory leak, I captured the issue and resolution with reference to
this thread in the issue:
https://issues.apache.org/activemq/browse/AMQ-2143
I think the resolution of the leak should help with more stable
enqueue rates. I will leave a steady state test running over night to
validate.
thanks for the analysis,
Gary.
2009/2/21 Cybexion <cy...@email.de>:
>
> Hi Gary,
>
> we just made a new test which startet yesterday.
> JVM settings of AMQ where 3 GB heap size.
> We send about 800 msg / sec into the queue, the size was limited to 3 GB.
> During that time sending messages to the queue got slower and slower. Even
> after the queue was full and new messages have been thrown away. Futhermore,
> the memory consimption was increasing and increasing. I checked with
> visualvm and the heap was totally used. A full GC did not change anything.
> I tried to get a memdump with jmap but the jvm crashed :-(
> My current state is, that at least in my case AMQ is not usable for two
> reasons:
> 1. Obiously a mem leak
> 2. Sending messages to the queue takes more and more time the more messages
> have been send already.
>
> Best regards
>
> Jörg
>
>
>
>
> Gary Tully wrote:
>>
>> Hi Jörg,
>> I did some analysis of the per message allocations from your email. It
>> is clear that each store write allocates a bunch of objects, however,
>> from code inspection, I cannot see a point where they are leaked
>> through a reference.
>> There are two relevant points that may make static analysis a little
>> difficult. First is the fact that writes are asynchronous, so there
>> will be a small delay until write allocations are free for GC. This
>> should be very small in reality though.
>> Second is that store pages remain in memory until they are pushed out
>> of a LRU cache, a page has the possibility of referencing batch writes
>> and indexes with location information, ie: most of the per write
>> allocated objects.
>>
>> In short, we need to repeat your experiment with some more depth by
>> taking caching issues into consideration. This is on my to do list.
>>
>> From a more high level view point, is it the case that a long running
>> test, with say 2000m/s in and out of the broker will eventually run
>> out of memory?
>>
>> I ask this because there are two sequential questions: 1) is there
>> really a memory leak (long running test gets into trouble) 2) if there
>> is a leak, where is it?
>>
>> Gary.
>>
>> 2009/2/13 Cybexion <cy...@email.de>:
>>>
>>> Hello,
>>>
>>> I just tried something with the Netbeans memory profiler.
>>> My assumption is:
>>> If nothing hass been added to an application then after 2 full runs of
>>> the
>>> Garbace Collector the memory should be the same.
>>> In the past we have seen that memory was increasing while messages have
>>> been
>>> processed by AMQ. For me that means that something stays in memory even
>>> after those messages have been dequeued.
>>>
>>> My test looks like this:
>>> 1. start a fresh AMQ instance, send some messages to a queue for
>>> initialisation
>>> 2. do a full GC
>>> 3. Take a memory snapshot
>>> 4. send exactly 1000 message to the queue
>>> 5. consume all 1000 messages from the queue
>>> 6. do a full GC
>>> 7. Take a another memory snapshot
>>>
>>> Assumption:
>>> I would expect that no references to messages do exist any more in the
>>> AMQ
>>> JVM because they have all been processed. The memory should look more or
>>> less like it was before the test.
>>> Now I did a memory comparision of my two snapshots.
>>> The result looks like this:
>>> http://www.nabble.com/file/p22003872/AMQClasses.jpg
>>> From within the "org.apache.activemq" package there are exactly 1000
>>> MessageKeys, 1000 RemoveMessageCommands and 1000 AdMessageCommands left
>>> over.
>>> Shouldn't those have disappeared because the queue is empty???
>>>
>>> Additionaly, if we look at the "org.apache.kaha" package:
>>> http://www.nabble.com/file/p22003872/KahaClasses.jpg
>>> There are 2000 DataByteArrayOutputstreams, 2000 Location objects and 2000
>>> WriteCommands still inside the memory. I would also have expected that
>>> those
>>> do not exist after the queue is empty.
>>>
>>> Well, personally this does not help me, but maybe one of the developers
>>> can
>>> convert this information into a possible bug inside the code?
>>>
>>> Help would really be appreciated.
>>>
>>> Thanks
>>>
>>> Jörg
>>>
>>>
>>>
>>> --
>>> View this message in context:
>>> http://www.nabble.com/Memoryleak-when-consuming-messages-from-KahaDBStore-tp21991929p22003872.html
>>> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>>>
>>>
>>
>>
>>
>> --
>> http://blog.garytully.com
>>
>> Open Source SOA
>> http://FUSESource.com
>>
>>
>
> --
> View this message in context: http://www.nabble.com/Memoryleak-when-consuming-messages-from-KahaDBStore-tp21991929p22141262.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
>
--
http://blog.garytully.com
Open Source SOA
http://FUSESource.com
Re: Memoryleak when consuming messages from KahaDBStore
Posted by Cybexion <cy...@email.de>.
Hi Gary,
we just made a new test which startet yesterday.
JVM settings of AMQ where 3 GB heap size.
We send about 800 msg / sec into the queue, the size was limited to 3 GB.
During that time sending messages to the queue got slower and slower. Even
after the queue was full and new messages have been thrown away. Futhermore,
the memory consimption was increasing and increasing. I checked with
visualvm and the heap was totally used. A full GC did not change anything.
I tried to get a memdump with jmap but the jvm crashed :-(
My current state is, that at least in my case AMQ is not usable for two
reasons:
1. Obiously a mem leak
2. Sending messages to the queue takes more and more time the more messages
have been send already.
Best regards
Jörg
Gary Tully wrote:
>
> Hi Jörg,
> I did some analysis of the per message allocations from your email. It
> is clear that each store write allocates a bunch of objects, however,
> from code inspection, I cannot see a point where they are leaked
> through a reference.
> There are two relevant points that may make static analysis a little
> difficult. First is the fact that writes are asynchronous, so there
> will be a small delay until write allocations are free for GC. This
> should be very small in reality though.
> Second is that store pages remain in memory until they are pushed out
> of a LRU cache, a page has the possibility of referencing batch writes
> and indexes with location information, ie: most of the per write
> allocated objects.
>
> In short, we need to repeat your experiment with some more depth by
> taking caching issues into consideration. This is on my to do list.
>
> From a more high level view point, is it the case that a long running
> test, with say 2000m/s in and out of the broker will eventually run
> out of memory?
>
> I ask this because there are two sequential questions: 1) is there
> really a memory leak (long running test gets into trouble) 2) if there
> is a leak, where is it?
>
> Gary.
>
> 2009/2/13 Cybexion <cy...@email.de>:
>>
>> Hello,
>>
>> I just tried something with the Netbeans memory profiler.
>> My assumption is:
>> If nothing hass been added to an application then after 2 full runs of
>> the
>> Garbace Collector the memory should be the same.
>> In the past we have seen that memory was increasing while messages have
>> been
>> processed by AMQ. For me that means that something stays in memory even
>> after those messages have been dequeued.
>>
>> My test looks like this:
>> 1. start a fresh AMQ instance, send some messages to a queue for
>> initialisation
>> 2. do a full GC
>> 3. Take a memory snapshot
>> 4. send exactly 1000 message to the queue
>> 5. consume all 1000 messages from the queue
>> 6. do a full GC
>> 7. Take a another memory snapshot
>>
>> Assumption:
>> I would expect that no references to messages do exist any more in the
>> AMQ
>> JVM because they have all been processed. The memory should look more or
>> less like it was before the test.
>> Now I did a memory comparision of my two snapshots.
>> The result looks like this:
>> http://www.nabble.com/file/p22003872/AMQClasses.jpg
>> From within the "org.apache.activemq" package there are exactly 1000
>> MessageKeys, 1000 RemoveMessageCommands and 1000 AdMessageCommands left
>> over.
>> Shouldn't those have disappeared because the queue is empty???
>>
>> Additionaly, if we look at the "org.apache.kaha" package:
>> http://www.nabble.com/file/p22003872/KahaClasses.jpg
>> There are 2000 DataByteArrayOutputstreams, 2000 Location objects and 2000
>> WriteCommands still inside the memory. I would also have expected that
>> those
>> do not exist after the queue is empty.
>>
>> Well, personally this does not help me, but maybe one of the developers
>> can
>> convert this information into a possible bug inside the code?
>>
>> Help would really be appreciated.
>>
>> Thanks
>>
>> Jörg
>>
>>
>>
>> --
>> View this message in context:
>> http://www.nabble.com/Memoryleak-when-consuming-messages-from-KahaDBStore-tp21991929p22003872.html
>> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>>
>>
>
>
>
> --
> http://blog.garytully.com
>
> Open Source SOA
> http://FUSESource.com
>
>
--
View this message in context: http://www.nabble.com/Memoryleak-when-consuming-messages-from-KahaDBStore-tp21991929p22141262.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: Memoryleak when consuming messages from KahaDBStore
Posted by Gary Tully <ga...@gmail.com>.
Hi Jörg,
I did some analysis of the per message allocations from your email. It
is clear that each store write allocates a bunch of objects, however,
from code inspection, I cannot see a point where they are leaked
through a reference.
There are two relevant points that may make static analysis a little
difficult. First is the fact that writes are asynchronous, so there
will be a small delay until write allocations are free for GC. This
should be very small in reality though.
Second is that store pages remain in memory until they are pushed out
of a LRU cache, a page has the possibility of referencing batch writes
and indexes with location information, ie: most of the per write
allocated objects.
In short, we need to repeat your experiment with some more depth by
taking caching issues into consideration. This is on my to do list.
>From a more high level view point, is it the case that a long running
test, with say 2000m/s in and out of the broker will eventually run
out of memory?
I ask this because there are two sequential questions: 1) is there
really a memory leak (long running test gets into trouble) 2) if there
is a leak, where is it?
Gary.
2009/2/13 Cybexion <cy...@email.de>:
>
> Hello,
>
> I just tried something with the Netbeans memory profiler.
> My assumption is:
> If nothing hass been added to an application then after 2 full runs of the
> Garbace Collector the memory should be the same.
> In the past we have seen that memory was increasing while messages have been
> processed by AMQ. For me that means that something stays in memory even
> after those messages have been dequeued.
>
> My test looks like this:
> 1. start a fresh AMQ instance, send some messages to a queue for
> initialisation
> 2. do a full GC
> 3. Take a memory snapshot
> 4. send exactly 1000 message to the queue
> 5. consume all 1000 messages from the queue
> 6. do a full GC
> 7. Take a another memory snapshot
>
> Assumption:
> I would expect that no references to messages do exist any more in the AMQ
> JVM because they have all been processed. The memory should look more or
> less like it was before the test.
> Now I did a memory comparision of my two snapshots.
> The result looks like this:
> http://www.nabble.com/file/p22003872/AMQClasses.jpg
> From within the "org.apache.activemq" package there are exactly 1000
> MessageKeys, 1000 RemoveMessageCommands and 1000 AdMessageCommands left
> over.
> Shouldn't those have disappeared because the queue is empty???
>
> Additionaly, if we look at the "org.apache.kaha" package:
> http://www.nabble.com/file/p22003872/KahaClasses.jpg
> There are 2000 DataByteArrayOutputstreams, 2000 Location objects and 2000
> WriteCommands still inside the memory. I would also have expected that those
> do not exist after the queue is empty.
>
> Well, personally this does not help me, but maybe one of the developers can
> convert this information into a possible bug inside the code?
>
> Help would really be appreciated.
>
> Thanks
>
> Jörg
>
>
>
> --
> View this message in context: http://www.nabble.com/Memoryleak-when-consuming-messages-from-KahaDBStore-tp21991929p22003872.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
>
--
http://blog.garytully.com
Open Source SOA
http://FUSESource.com
Re: Memoryleak when consuming messages from KahaDBStore
Posted by Cybexion <cy...@email.de>.
Hello,
I just tried something with the Netbeans memory profiler.
My assumption is:
If nothing hass been added to an application then after 2 full runs of the
Garbace Collector the memory should be the same.
In the past we have seen that memory was increasing while messages have been
processed by AMQ. For me that means that something stays in memory even
after those messages have been dequeued.
My test looks like this:
1. start a fresh AMQ instance, send some messages to a queue for
initialisation
2. do a full GC
3. Take a memory snapshot
4. send exactly 1000 message to the queue
5. consume all 1000 messages from the queue
6. do a full GC
7. Take a another memory snapshot
Assumption:
I would expect that no references to messages do exist any more in the AMQ
JVM because they have all been processed. The memory should look more or
less like it was before the test.
Now I did a memory comparision of my two snapshots.
The result looks like this:
http://www.nabble.com/file/p22003872/AMQClasses.jpg
>From within the "org.apache.activemq" package there are exactly 1000
MessageKeys, 1000 RemoveMessageCommands and 1000 AdMessageCommands left
over.
Shouldn't those have disappeared because the queue is empty???
Additionaly, if we look at the "org.apache.kaha" package:
http://www.nabble.com/file/p22003872/KahaClasses.jpg
There are 2000 DataByteArrayOutputstreams, 2000 Location objects and 2000
WriteCommands still inside the memory. I would also have expected that those
do not exist after the queue is empty.
Well, personally this does not help me, but maybe one of the developers can
convert this information into a possible bug inside the code?
Help would really be appreciated.
Thanks
Jörg
--
View this message in context: http://www.nabble.com/Memoryleak-when-consuming-messages-from-KahaDBStore-tp21991929p22003872.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: Memoryleak when consuming messages from KahaDBStore
Posted by Cybexion <cy...@email.de>.
Btw:
These are my JVM settings (1.6.0_10)
# Java Additional Parameters
# note that n is the parameter number starting from 1.
wrapper.java.additional.1=-Dactivemq.home=%ACTIVEMQ_HOME%
wrapper.java.additional.2=-Dactivemq.base=%ACTIVEMQ_BASE%
wrapper.java.additional.3=-Dcom.sun.management.jmxremote
wrapper.java.additional.4=-Dorg.apache.activemq.UseDedicatedTaskRunner=true
wrapper.java.additional.5=-Dderby.storage.fileSyncTransactionLog=true
# Uncomment to enable jmx
wrapper.java.additional.6=-Dcom.sun.management.jmxremote.port=1099
wrapper.java.additional.7=-Dcom.sun.management.jmxremote.authenticate=false
wrapper.java.additional.8=-Dcom.sun.management.jmxremote.ssl=false
wrapper.java.additional.9=-XX:+UseParallelGC
wrapper.java.additional.10=-Xmn100M
wrapper.java.additional.11=-Xms500M
wrapper.java.additional.12=-verbose:gc
wrapper.java.additional.13=-XX:+PrintGCTimeStamps
wrapper.java.additional.14=-XX:+PrintGCDetails
wrapper.java.additional.15=-Xmx2560M
wrapper.java.additional.16=-server
Cybexion wrote:
>
> Hello,
>
> I'm working with the lastest 5.3 trunk and using the new KahaDBStore.
> Last night I made a test:
> I have a queue that contained >30 Mio messages. I started 20 consumers to
> empty the queue.
> The consumers are running in their own VM. While retrieving messages from
> AMW the memory consumption of AMQ was constantly increasing.
>
> Currently the logs look like this:
>
> 2009-02-13 09:08:33,461 [nitor ReadCheck] DEBUG
> .transport.InactivityMonitor$1 - 24404 ms elapsed since last read check.
> 2009-02-13 09:08:33,462 [itor WriteCheck] DEBUG
> .transport.InactivityMonitor$2 - 7049 ms elapsed since last write check.
> 2009-02-13 09:08:33,462 [nitor ReadCheck] DEBUG
> .transport.InactivityMonitor$1 - Aborting read check.. Not enough time
> elapsed since last read check.
> 2009-02-13 09:08:39,213 [itor WriteCheck] DEBUG
> .transport.InactivityMonitor$2 - 12800 ms elapsed since last write check.
> 2009-02-13 09:08:44,971 [itor WriteCheck] DEBUG
> .transport.InactivityMonitor$2 - 11510 ms elapsed since last write check.
> 2009-02-13 09:08:44,971 [itor WriteCheck] DEBUG
> .transport.InactivityMonitor$2 - 11509 ms elapsed since last write check.
> 2009-02-13 09:08:44,971 [itor WriteCheck] DEBUG
> .transport.InactivityMonitor$2 - 5758 ms elapsed since last write check.
> 2009-02-13 09:08:57,766 [nitor ReadCheck] DEBUG
> .transport.InactivityMonitor$1 - 31354 ms elapsed since last read check.
>
>
> The GC says:
>
> INFO | jvm 1 | 2009/02/13 09:09:28 | 70626.930: [Full GC
> INFO | jvm 1 | 2009/02/13 09:09:33 | [PSYoungGen:
> 67968K->22723K(84416K)] [PSOldGen: 2519039K->2519039K(2519040K)]
> 2587007K->2541763K(2603456K) [PSP
> ermGen: 28288K->28288K(28352K)] GC time is exceeding GCTimeLimit of
> 98%
> INFO | jvm 1 | 2009/02/13 09:09:33 | , 5.8210250 secs] [Times:
> user=5.80 sys=0.01, real=5.82 secs]
> INFO | jvm 1 | 2009/02/13 09:09:33 | 70632.812: [Full GC
> INFO | jvm 1 | 2009/02/13 09:09:39 | [PSYoungGen:
> 67968K->22941K(84416K)] [PSOldGen: 2519039K->2519039K(2519040K)]
> 2587007K->2541981K(2603456K) [PSP
> ermGen: 28294K->28294K(28352K)] GC time would exceed GCTimeLimit of
> 98%
> INFO | jvm 1 | 2009/02/13 09:09:39 | , 5.8349920 secs] [Times:
> user=5.82 sys=0.01, real=5.83 secs]
> INFO | jvm 1 | 2009/02/13 09:09:39 | 70638.708: [Full GC
> INFO | jvm 1 | 2009/02/13 09:09:46 | [PSYoungGen:
> 67968K->20009K(84416K)] [PSOldGen: 2519039K->2519039K(2519040K)]
> 2587007K->2539049K(2603456K) [PSP
> ermGen: 28299K->28277K(28352K)] GC time would exceed GCTimeLimit of
> 98%
>
>
>
> Here are my AMQ settings:
>
> <bean id="store"
> class="org.apache.activemq.store.kahadb.KahaDBStore">
> <property name="directory" value="${activemq.base}/data"/>
> <property name="checkpointInterval" value="5000"/>
> <property name="cleanupInterval" value="5000"/>
>
> <property name="journalMaxFileLength" value="10000000"/>
> <property name="indexWriteBatchSize" value="100" />
> <property name="enableIndexWriteAsync" value="true" />
> </bean>
>
> Is there anything I can additionally check?
>
> Regards
>
> Jörg
>
>
>
--
View this message in context: http://www.nabble.com/Memoryleak-when-consuming-messages-from-KahaDBStore-tp21991929p21996453.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.