OFBiz › OFBiz - Dev

Is there a possible memory issue causing objects to stay in old generation for long - ofbiz and javolution

_‹ Previous Topic Next Topic _›

Classic

List

Threaded

6 messages Options

sharad bhushan

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

Adam Heath-2

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
>
>
>

sharad bhushan

Re: Is there a possible memory issue causing objects to stay in old generation for long - ofbiz and javolution

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 <[hidden email]>
To: [hidden email]
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:

Adam Heath-2

Re: Is there a possible memory issue causing objects to stay in old generation for long - ofbiz and javolution

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 <[hidden email]>
> To: [hidden email]
> 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
>>
>>
>>
>
>

Jacques Le Roux

Re: Is there a possible memory issue causing objects to stay in old generation for long - ofbiz and javolution

Administrator

From: "Adam Heath" <[hidden email]>
> 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 <[hidden email]>
>> To: [hidden email]
>> 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
>>>
>>>
>>>
>>
>>
>

Jacques Le Roux

Re: Is there a possible memory issue causing objects to stay in old generation for long - ofbiz and javolution

Administrator

Looks like Oracle is not very worried about this :/
Please vote!

Jacques

From: "Jacques Le Roux" <[hidden email]>

> From: "Adam Heath" <[hidden email]>
>> 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 <[hidden email]>
>>> To: [hidden email]
>>> 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
>>>>
>>>>
>>>>
>>>
>>>
>>
>
>