You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@ofbiz.apache.org by sharad bhushan <sh...@yahoo.co.in> on 2010/05/06 20:14:22 UTC
Is there a possible memory issue causing objects to stay in old generation for long - ofbiz and javolution
Hello Everyone,
I have been trying to get the understanding of memory allocation when debugging the load and memory issue in our ofbiz instance
Here is the snap shot of our gc log after three days of running and this had been continuing for next two days and went low
eventually not responding. This Full GC run as below was continuous with tenured memory not clearing and Full GC kept running all
together for 2 days with breaks for few hours, it still survived "out of memory" as young generation was releasing on Full GC.
328821.354: [Full GC 328821.354: [Tenured: 1048576K->1048575K(1048576K), 2.9016030 secs] 1520444K->1087815K(1520448K), [Perm : 49067K->49050K(49152K)], 2.9017140 secs] [Times: user=2.90 sys=0.00, real=2.90 secs]
328825.334: [Full GC 328825.334: [Tenured: 1048575K->1048575K(1048576K), 2.4392020 secs] 1520447K->1097197K(1520448K), [Perm : 49054K->49054K(49152K)], 2.4393150 secs] [Times: user=2.43 sys=0.00, real=2.44 secs]
328828.673: [Full GC 328828.673: [Tenured: 1048575K->1048575K(1048576K), 2.4696630 secs] 1520447K->1107798K(1520448K), [Perm : 49063K->49063K(49152K)], 2.4697760 secs] [Times: user=2.46 sys=0.00, real=2.46 secs]
403173.352: [Full GC 403173.352: [Tenured: 1048576K->1048576K(1048576K), 2.7718690 secs] 1520447K->1252656K(1520448K), [Perm : 49417K->49417K(49664K)], 2.7719880 secs] [Times: user=2.77 sys=0.00, real=2.77 secs]
403176.958: [Full GC 403176.958: [Tenured: 1048576K->1048576K(1048576K), 2.7772930 secs] 1520448K->1264672K(1520448K), [Perm : 49421K->49421K(49664K)], 2.7774020 secs] [Times: user=2.78 sys=0.00, real=2.77 secs]
403180.713: [Full GC 403180.713: [Tenured: 1048576K->1048576K(1048576K), 2.7374900 secs] 1520447K->1267832K(1520448K), [Perm : 49426K->49426K(49664K)], 2.7376110 secs] [Times: user=2.73 sys=0.00, real=2.74 secs]
With above said i would like to give the top classes on doing jmap -histo
javolution FastMap$Entry - ~240MB - nearly 4,900,000 objects
javolution FastMap$Entry[] - ~120MB
javolution HashMap$Entry - ~90MB
The java max heap (-Xmx) is 1.5GB.
the tenured - old gen is ~1000MB and the above three elements are 50% occupied, certainly after drilling through few heap dumps it describes of above three classes.
The tenured space does not get cleared, I am looking to suspect the FastMap, specifically, we have been using ofbiz cache too.
Can there be any inputs or observation about the possible issue in memory or javolution, any directions for the above description would certainly help me.
Regards
Sharad
Re: Is there a possible memory issue causing objects to stay in old generation for long - ofbiz and javolution
Posted by Jacques Le Roux <ja...@les7arts.com>.
Looks like Oracle is not very worried about this :/
Please vote!
Jacques
From: "Jacques Le Roux" <ja...@les7arts.com>
> From: "Adam Heath" <do...@brainfood.com>
>> sharad bhushan wrote:
>>> to keep this updated
>>>
>>> The Issue was cache - SoftReference.
>>> http://bugs.sun.com/bugdatabase/view_bug.do;jsessionid=cfd518f51afc7780e5188276b5f9?bug_id=6912889
>>>
>>> The monitoring ran for month now and the application is stable. we changed the SoftRefLRUPolicyMSPerMB.
>>
>> That's a bummer. And if true, it explains alot.
>
> Looks like it's true since it's 3-Accepted, in the reference above, why do you doubt?
> Also is it only on Linux/Debian 64 AMD with 1.6.0_16, is I guess a good question
>
> Jacques
>
>>
>>>
>>> Sharad
>>>
>>>
>>> ________________________________
>>> From: Adam Heath <do...@brainfood.com>
>>> To: dev@ofbiz.apache.org
>>> Sent: Fri, 7 May, 2010 1:28:08 AM
>>> Subject: Re: Is there a possible memory issue causing objects to stay in old generation for long - ofbiz and javolution
>>>
>>> sharad bhushan wrote:
>>>> Hello Everyone,
>>>>
>>>> I have been trying to get the understanding of memory allocation when debugging the load and memory issue in our ofbiz
>>>> instance
>>>>
>>>> Here is the snap shot of our gc log after three days of running and this had been continuing for next two days and went low
>>>> eventually not responding. This Full GC run as below was continuous with tenured memory not clearing and Full GC kept running
>>>> all
>>>> together for 2 days with breaks for few hours, it still survived "out of memory" as young generation was releasing on Full GC.
>>>>
>>>> 328821.354: [Full GC 328821.354: [Tenured: 1048576K->1048575K(1048576K), 2.9016030 secs] 1520444K->1087815K(1520448K), [Perm :
>>>> 49067K->49050K(49152K)], 2.9017140 secs] [Times: user=2.90 sys=0.00, real=2.90 secs]
>>>> 328825.334: [Full GC 328825.334: [Tenured: 1048575K->1048575K(1048576K), 2.4392020 secs] 1520447K->1097197K(1520448K), [Perm :
>>>> 49054K->49054K(49152K)], 2.4393150 secs] [Times: user=2.43 sys=0.00, real=2.44 secs]
>>>> 328828.673: [Full GC 328828.673: [Tenured: 1048575K->1048575K(1048576K), 2.4696630 secs] 1520447K->1107798K(1520448K), [Perm :
>>>> 49063K->49063K(49152K)], 2.4697760 secs] [Times: user=2.46 sys=0.00, real=2.46 secs]
>>>>
>>>> 403173.352: [Full GC 403173.352: [Tenured: 1048576K->1048576K(1048576K), 2.7718690 secs] 1520447K->1252656K(1520448K), [Perm :
>>>> 49417K->49417K(49664K)], 2.7719880 secs] [Times: user=2.77 sys=0.00, real=2.77 secs]
>>>> 403176.958: [Full GC 403176.958: [Tenured: 1048576K->1048576K(1048576K), 2.7772930 secs] 1520448K->1264672K(1520448K), [Perm :
>>>> 49421K->49421K(49664K)], 2.7774020 secs] [Times: user=2.78 sys=0.00, real=2.77 secs]
>>>> 403180.713: [Full GC 403180.713: [Tenured: 1048576K->1048576K(1048576K), 2.7374900 secs] 1520447K->1267832K(1520448K), [Perm :
>>>> 49426K->49426K(49664K)], 2.7376110 secs] [Times: user=2.73 sys=0.00, real=2.74 secs]
>>>>
>>>> With above said i would like to give the top classes on doing jmap -histo
>>>> javolution FastMap$Entry - ~240MB - nearly 4,900,000 objects
>>>> javolution FastMap$Entry[] - ~120MB
>>>> javolution HashMap$Entry - ~90MB
>>>
>>> You have to be very very careful. All FastMap instances, and all
>>> their keys/values, and everything else they point to, including
>>> various chained classloaders, then the classes loaded by those
>>> classloaders, and all the static references in *those* classes, etc.
>>>
>>> I've found that the various memory graph walking tools don't really
>>> handle finding the *correct* top-level items to show.
>>>
>>>
>>>> The java max heap (-Xmx) is 1.5GB.
>>>>
>>>> the tenured - old gen is ~1000MB and the above three elements are 50% occupied, certainly after drilling through few heap dumps
>>>> it describes of above three classes.
>>>>
>>>> The tenured space does not get cleared, I am looking to suspect the FastMap, specifically, we have been using ofbiz cache too.
>>>>
>>>> Can there be any inputs or observation about the possible issue in memory or javolution, any directions for the above
>>>> description would certainly help me.
>>>>
>>>> Regards
>>>> Sharad
>>>>
>>>>
>>>>
>>>
>>>
>>
>
>
Re: Is there a possible memory issue causing objects to stay in old generation for long - ofbiz and javolution
Posted by Jacques Le Roux <ja...@les7arts.com>.
From: "Adam Heath" <do...@brainfood.com>
> sharad bhushan wrote:
>> to keep this updated
>>
>> The Issue was cache - SoftReference.
>> http://bugs.sun.com/bugdatabase/view_bug.do;jsessionid=cfd518f51afc7780e5188276b5f9?bug_id=6912889
>>
>> The monitoring ran for month now and the application is stable. we changed the SoftRefLRUPolicyMSPerMB.
>
> That's a bummer. And if true, it explains alot.
Looks like it's true since it's 3-Accepted, in the reference above, why do you doubt?
Also is it only on Linux/Debian 64 AMD with 1.6.0_16, is I guess a good question
Jacques
>
>>
>> Sharad
>>
>>
>> ________________________________
>> From: Adam Heath <do...@brainfood.com>
>> To: dev@ofbiz.apache.org
>> Sent: Fri, 7 May, 2010 1:28:08 AM
>> Subject: Re: Is there a possible memory issue causing objects to stay in old generation for long - ofbiz and javolution
>>
>> sharad bhushan wrote:
>>> Hello Everyone,
>>>
>>> I have been trying to get the understanding of memory allocation when debugging the load and memory issue in our ofbiz instance
>>>
>>> Here is the snap shot of our gc log after three days of running and this had been continuing for next two days and went low
>>> eventually not responding. This Full GC run as below was continuous with tenured memory not clearing and Full GC kept running
>>> all
>>> together for 2 days with breaks for few hours, it still survived "out of memory" as young generation was releasing on Full GC.
>>>
>>> 328821.354: [Full GC 328821.354: [Tenured: 1048576K->1048575K(1048576K), 2.9016030 secs] 1520444K->1087815K(1520448K), [Perm :
>>> 49067K->49050K(49152K)], 2.9017140 secs] [Times: user=2.90 sys=0.00, real=2.90 secs]
>>> 328825.334: [Full GC 328825.334: [Tenured: 1048575K->1048575K(1048576K), 2.4392020 secs] 1520447K->1097197K(1520448K), [Perm :
>>> 49054K->49054K(49152K)], 2.4393150 secs] [Times: user=2.43 sys=0.00, real=2.44 secs]
>>> 328828.673: [Full GC 328828.673: [Tenured: 1048575K->1048575K(1048576K), 2.4696630 secs] 1520447K->1107798K(1520448K), [Perm :
>>> 49063K->49063K(49152K)], 2.4697760 secs] [Times: user=2.46 sys=0.00, real=2.46 secs]
>>>
>>> 403173.352: [Full GC 403173.352: [Tenured: 1048576K->1048576K(1048576K), 2.7718690 secs] 1520447K->1252656K(1520448K), [Perm :
>>> 49417K->49417K(49664K)], 2.7719880 secs] [Times: user=2.77 sys=0.00, real=2.77 secs]
>>> 403176.958: [Full GC 403176.958: [Tenured: 1048576K->1048576K(1048576K), 2.7772930 secs] 1520448K->1264672K(1520448K), [Perm :
>>> 49421K->49421K(49664K)], 2.7774020 secs] [Times: user=2.78 sys=0.00, real=2.77 secs]
>>> 403180.713: [Full GC 403180.713: [Tenured: 1048576K->1048576K(1048576K), 2.7374900 secs] 1520447K->1267832K(1520448K), [Perm :
>>> 49426K->49426K(49664K)], 2.7376110 secs] [Times: user=2.73 sys=0.00, real=2.74 secs]
>>>
>>> With above said i would like to give the top classes on doing jmap -histo
>>> javolution FastMap$Entry - ~240MB - nearly 4,900,000 objects
>>> javolution FastMap$Entry[] - ~120MB
>>> javolution HashMap$Entry - ~90MB
>>
>> You have to be very very careful. All FastMap instances, and all
>> their keys/values, and everything else they point to, including
>> various chained classloaders, then the classes loaded by those
>> classloaders, and all the static references in *those* classes, etc.
>>
>> I've found that the various memory graph walking tools don't really
>> handle finding the *correct* top-level items to show.
>>
>>
>>> The java max heap (-Xmx) is 1.5GB.
>>>
>>> the tenured - old gen is ~1000MB and the above three elements are 50% occupied, certainly after drilling through few heap dumps
>>> it describes of above three classes.
>>>
>>> The tenured space does not get cleared, I am looking to suspect the FastMap, specifically, we have been using ofbiz cache too.
>>>
>>> Can there be any inputs or observation about the possible issue in memory or javolution, any directions for the above
>>> description would certainly help me.
>>>
>>> Regards
>>> Sharad
>>>
>>>
>>>
>>
>>
>
Re: Is there a possible memory issue causing objects to stay in old
generation for long - ofbiz and javolution
Posted by Adam Heath <do...@brainfood.com>.
sharad bhushan wrote:
> to keep this updated
>
> The Issue was cache - SoftReference.
> http://bugs.sun.com/bugdatabase/view_bug.do;jsessionid=cfd518f51afc7780e5188276b5f9?bug_id=6912889
>
> The monitoring ran for month now and the application is stable. we changed the SoftRefLRUPolicyMSPerMB.
That's a bummer. And if true, it explains alot.
>
> Sharad
>
>
> ________________________________
> From: Adam Heath <do...@brainfood.com>
> To: dev@ofbiz.apache.org
> Sent: Fri, 7 May, 2010 1:28:08 AM
> Subject: Re: Is there a possible memory issue causing objects to stay in old generation for long - ofbiz and javolution
>
> sharad bhushan wrote:
>> Hello Everyone,
>>
>> I have been trying to get the understanding of memory allocation when debugging the load and memory issue in our ofbiz instance
>>
>> Here is the snap shot of our gc log after three days of running and this had been continuing for next two days and went low
>> eventually not responding. This Full GC run as below was continuous with tenured memory not clearing and Full GC kept running all
>> together for 2 days with breaks for few hours, it still survived "out of memory" as young generation was releasing on Full GC.
>>
>> 328821.354: [Full GC 328821.354: [Tenured: 1048576K->1048575K(1048576K), 2.9016030 secs] 1520444K->1087815K(1520448K), [Perm : 49067K->49050K(49152K)], 2.9017140 secs] [Times: user=2.90 sys=0.00, real=2.90 secs]
>> 328825.334: [Full GC 328825.334: [Tenured: 1048575K->1048575K(1048576K), 2.4392020 secs] 1520447K->1097197K(1520448K), [Perm : 49054K->49054K(49152K)], 2.4393150 secs] [Times: user=2.43 sys=0.00, real=2.44 secs]
>> 328828.673: [Full GC 328828.673: [Tenured: 1048575K->1048575K(1048576K), 2.4696630 secs] 1520447K->1107798K(1520448K), [Perm : 49063K->49063K(49152K)], 2.4697760 secs] [Times: user=2.46 sys=0.00, real=2.46 secs]
>>
>> 403173.352: [Full GC 403173.352: [Tenured: 1048576K->1048576K(1048576K), 2.7718690 secs] 1520447K->1252656K(1520448K), [Perm : 49417K->49417K(49664K)], 2.7719880 secs] [Times: user=2.77 sys=0.00, real=2.77 secs]
>> 403176.958: [Full GC 403176.958: [Tenured: 1048576K->1048576K(1048576K), 2.7772930 secs] 1520448K->1264672K(1520448K), [Perm : 49421K->49421K(49664K)], 2.7774020 secs] [Times: user=2.78 sys=0.00, real=2.77 secs]
>> 403180.713: [Full GC 403180.713: [Tenured: 1048576K->1048576K(1048576K), 2.7374900 secs] 1520447K->1267832K(1520448K), [Perm : 49426K->49426K(49664K)], 2.7376110 secs] [Times: user=2.73 sys=0.00, real=2.74 secs]
>>
>> With above said i would like to give the top classes on doing jmap -histo
>> javolution FastMap$Entry - ~240MB - nearly 4,900,000 objects
>> javolution FastMap$Entry[] - ~120MB
>> javolution HashMap$Entry - ~90MB
>
> You have to be very very careful. All FastMap instances, and all
> their keys/values, and everything else they point to, including
> various chained classloaders, then the classes loaded by those
> classloaders, and all the static references in *those* classes, etc.
>
> I've found that the various memory graph walking tools don't really
> handle finding the *correct* top-level items to show.
>
>
>> The java max heap (-Xmx) is 1.5GB.
>>
>> the tenured - old gen is ~1000MB and the above three elements are 50% occupied, certainly after drilling through few heap dumps it describes of above three classes.
>>
>> The tenured space does not get cleared, I am looking to suspect the FastMap, specifically, we have been using ofbiz cache too.
>>
>> Can there be any inputs or observation about the possible issue in memory or javolution, any directions for the above description would certainly help me.
>>
>> Regards
>> Sharad
>>
>>
>>
>
>
Re: Is there a possible memory issue causing objects to stay in old generation for long - ofbiz and javolution
Posted by sharad bhushan <sh...@yahoo.co.in>.
to keep this updated
The Issue was cache - SoftReference.
http://bugs.sun.com/bugdatabase/view_bug.do;jsessionid=cfd518f51afc7780e5188276b5f9?bug_id=6912889
The monitoring ran for month now and the application is stable. we changed the SoftRefLRUPolicyMSPerMB.
Sharad
________________________________
From: Adam Heath <do...@brainfood.com>
To: dev@ofbiz.apache.org
Sent: Fri, 7 May, 2010 1:28:08 AM
Subject: Re: Is there a possible memory issue causing objects to stay in old generation for long - ofbiz and javolution
sharad bhushan wrote:
> Hello Everyone,
>
> I have been trying to get the understanding of memory allocation when debugging the load and memory issue in our ofbiz instance
>
> Here is the snap shot of our gc log after three days of running and this had been continuing for next two days and went low
> eventually not responding. This Full GC run as below was continuous with tenured memory not clearing and Full GC kept running all
> together for 2 days with breaks for few hours, it still survived "out of memory" as young generation was releasing on Full GC.
>
> 328821.354: [Full GC 328821.354: [Tenured: 1048576K->1048575K(1048576K), 2.9016030 secs] 1520444K->1087815K(1520448K), [Perm : 49067K->49050K(49152K)], 2.9017140 secs] [Times: user=2.90 sys=0.00, real=2.90 secs]
> 328825.334: [Full GC 328825.334: [Tenured: 1048575K->1048575K(1048576K), 2.4392020 secs] 1520447K->1097197K(1520448K), [Perm : 49054K->49054K(49152K)], 2.4393150 secs] [Times: user=2.43 sys=0.00, real=2.44 secs]
> 328828.673: [Full GC 328828.673: [Tenured: 1048575K->1048575K(1048576K), 2.4696630 secs] 1520447K->1107798K(1520448K), [Perm : 49063K->49063K(49152K)], 2.4697760 secs] [Times: user=2.46 sys=0.00, real=2.46 secs]
>
> 403173.352: [Full GC 403173.352: [Tenured: 1048576K->1048576K(1048576K), 2.7718690 secs] 1520447K->1252656K(1520448K), [Perm : 49417K->49417K(49664K)], 2.7719880 secs] [Times: user=2.77 sys=0.00, real=2.77 secs]
> 403176.958: [Full GC 403176.958: [Tenured: 1048576K->1048576K(1048576K), 2.7772930 secs] 1520448K->1264672K(1520448K), [Perm : 49421K->49421K(49664K)], 2.7774020 secs] [Times: user=2.78 sys=0.00, real=2.77 secs]
> 403180.713: [Full GC 403180.713: [Tenured: 1048576K->1048576K(1048576K), 2.7374900 secs] 1520447K->1267832K(1520448K), [Perm : 49426K->49426K(49664K)], 2.7376110 secs] [Times: user=2.73 sys=0.00, real=2.74 secs]
>
> With above said i would like to give the top classes on doing jmap -histo
> javolution FastMap$Entry - ~240MB - nearly 4,900,000 objects
> javolution FastMap$Entry[] - ~120MB
> javolution HashMap$Entry - ~90MB
You have to be very very careful. All FastMap instances, and all
their keys/values, and everything else they point to, including
various chained classloaders, then the classes loaded by those
classloaders, and all the static references in *those* classes, etc.
I've found that the various memory graph walking tools don't really
handle finding the *correct* top-level items to show.
>
> The java max heap (-Xmx) is 1.5GB.
>
> the tenured - old gen is ~1000MB and the above three elements are 50% occupied, certainly after drilling through few heap dumps it describes of above three classes.
>
> The tenured space does not get cleared, I am looking to suspect the FastMap, specifically, we have been using ofbiz cache too.
>
> Can there be any inputs or observation about the possible issue in memory or javolution, any directions for the above description would certainly help me.
>
> Regards
> Sharad
>
>
>
Re: Is there a possible memory issue causing objects to stay in old
generation for long - ofbiz and javolution
Posted by Adam Heath <do...@brainfood.com>.
sharad bhushan wrote:
> Hello Everyone,
>
> I have been trying to get the understanding of memory allocation when debugging the load and memory issue in our ofbiz instance
>
> Here is the snap shot of our gc log after three days of running and this had been continuing for next two days and went low
> eventually not responding. This Full GC run as below was continuous with tenured memory not clearing and Full GC kept running all
> together for 2 days with breaks for few hours, it still survived "out of memory" as young generation was releasing on Full GC.
>
> 328821.354: [Full GC 328821.354: [Tenured: 1048576K->1048575K(1048576K), 2.9016030 secs] 1520444K->1087815K(1520448K), [Perm : 49067K->49050K(49152K)], 2.9017140 secs] [Times: user=2.90 sys=0.00, real=2.90 secs]
> 328825.334: [Full GC 328825.334: [Tenured: 1048575K->1048575K(1048576K), 2.4392020 secs] 1520447K->1097197K(1520448K), [Perm : 49054K->49054K(49152K)], 2.4393150 secs] [Times: user=2.43 sys=0.00, real=2.44 secs]
> 328828.673: [Full GC 328828.673: [Tenured: 1048575K->1048575K(1048576K), 2.4696630 secs] 1520447K->1107798K(1520448K), [Perm : 49063K->49063K(49152K)], 2.4697760 secs] [Times: user=2.46 sys=0.00, real=2.46 secs]
>
> 403173.352: [Full GC 403173.352: [Tenured: 1048576K->1048576K(1048576K), 2.7718690 secs] 1520447K->1252656K(1520448K), [Perm : 49417K->49417K(49664K)], 2.7719880 secs] [Times: user=2.77 sys=0.00, real=2.77 secs]
> 403176.958: [Full GC 403176.958: [Tenured: 1048576K->1048576K(1048576K), 2.7772930 secs] 1520448K->1264672K(1520448K), [Perm : 49421K->49421K(49664K)], 2.7774020 secs] [Times: user=2.78 sys=0.00, real=2.77 secs]
> 403180.713: [Full GC 403180.713: [Tenured: 1048576K->1048576K(1048576K), 2.7374900 secs] 1520447K->1267832K(1520448K), [Perm : 49426K->49426K(49664K)], 2.7376110 secs] [Times: user=2.73 sys=0.00, real=2.74 secs]
>
> With above said i would like to give the top classes on doing jmap -histo
> javolution FastMap$Entry - ~240MB - nearly 4,900,000 objects
> javolution FastMap$Entry[] - ~120MB
> javolution HashMap$Entry - ~90MB
You have to be very very careful. All FastMap instances, and all
their keys/values, and everything else they point to, including
various chained classloaders, then the classes loaded by those
classloaders, and all the static references in *those* classes, etc.
I've found that the various memory graph walking tools don't really
handle finding the *correct* top-level items to show.
>
> The java max heap (-Xmx) is 1.5GB.
>
> the tenured - old gen is ~1000MB and the above three elements are 50% occupied, certainly after drilling through few heap dumps it describes of above three classes.
>
> The tenured space does not get cleared, I am looking to suspect the FastMap, specifically, we have been using ofbiz cache too.
>
> Can there be any inputs or observation about the possible issue in memory or javolution, any directions for the above description would certainly help me.
>
> Regards
> Sharad
>
>
>