Hi,
Of late we are facing Memory issues in our application. We have therfore enabled logs pertaining to Garbage Collection.We seem to have some heap memory issues. This is what we see in the GC logs :
<GC(2): GC cycle started Thu Sep<b> 21 02:03:01 2006</b>
<GC(2): freed 197316040 bytes, <b>87% free (233948016/268433920)</b>, in 247 ms>
<GC(2): mark: 45 ms, sweep: 11 ms, compact: 191 ms>
<GC(2): refs: soft 0 (age >= 32), weak 2, final 1222, phantom 0>
<GC(2): moved 579187 objects, 32745528 bytes, reason=4, used 13400 more bytes>
<AF[2]: Allocation Failure. need 65072 bytes, 29103 ms since last AF>
<AF[2]: managing allocation failure, action=1 (160408/265288192) (3145728/3145728)>
<GC(43): GC cycle started Thu Sep <b>21 02:03:21</b> 2006
<GC(43): freed 162749952 bytes,<b> 61% free </b>(166056088/268433920), in 126 ms>
<GC(43): mark: 110 ms, sweep: 16 ms, compact: 0 ms>
<GC(43): refs: soft 0 (age >= 32), weak 0, final 40, phantom 0>
<AF[2]: completed in 126 ms>
<AF[3]: Allocation Failure. need 32 bytes, 15490 ms since last AF>
<AF[3]: managing allocation failure, action=1 (0/265288192) (3145728/3145728)>
<GC(44): GC cycle started Thu Sep <b>21 02:03:37 </b>2006
<GC(44): freed 126280056 bytes, <b>48% free </b>(129425784/268433920), in 171 ms>
<GC(44): mark: 153 ms, sweep: 18 ms, compact: 0 ms>
<GC(44): refs: soft 0 (age >= 32), weak 2, final 144, phantom 0>
<AF[3]: completed in 172 ms>
<AF[6]: Allocation Failure. need 65072 bytes, 2313 ms since last AF>
<AF[6]: managing allocation failure, action=2 (49851136/268433920)>
<GC(47): GC cycle started Thu Sep <b>21 02:03:49 </b>2006
<GC(47): freed 60613344 bytes, <b>41% free</b> (110464480/268433920), in 200 ms>
<GC(47): mark: 176 ms, sweep: 24 ms, compact: 0 ms>
<GC(47): refs: soft 0 (age >= 32), weak 0, final 398, phantom 0>
<AF[6]: managing allocation failure, action=3 (110464480/268433920)>
<GC(47): need to expand mark bits for 315423232-byte heap>
<GC(47): expanded mark bits by 737280 to 4931584 bytes>
<GC(47): need to expand alloc bits for 315423232-byte heap>
<GC(47): expanded alloc bits by 737280 to 4931584 bytes>
<GC(47): need to expand FR bits for 315423232-byte heap>
<GC(47): expanded FR bits by 1470464 to 9859072 bytes>
<GC(47): expanded heap by 46989312 to 315423232 bytes, 49% free, ratio:0.211>
<AF[12]: Allocation Failure. need 98320 bytes, 984 ms since last AF>
<AF[12]: managing allocation failure, action=2 (106268536/370670080)>
<GC(53): GC cycle started Thu Sep <b>21 02:03:58 </b>2006
<GC(53): freed 39422592 bytes, <b>39% free </b>(145691128/370670080), in 214 ms>
<GC(53): mark: 191 ms, sweep: 23 ms, compact: 0 ms>
<GC(53): refs: soft 0 (age >= 6), weak 0, final 1, phantom 0>
<AF[12]: managing allocation failure, action=3 (145691128/370670080)>
<GC(53): need to expand mark bits for 435550720-byte heap>
<GC(53): expanded mark bits by 1015808 to 6807552 bytes>
<GC(53): need to expand alloc bits for 435550720-byte heap>
<GC(53): expanded alloc bits by 1015808 to 6807552 bytes>
<GC(53): need to expand FR bits for 435550720-byte heap>
<GC(53): expanded FR bits by 2027520 to 13611008 bytes>
<GC(53): expanded heap by 64880640 to 435550720 bytes, <b>48% free<b>, ratio:2.054>
<AF[12]: completed in 285 ms>
I am more of a Java Webservices Developer rather than system's guy but I need to ascertain some facts.
1. Why does the GC run so often ?
2. What we are seeing right now is just at server startup our Application has yet NOT started consuming memory. So, do we think our startup Heap memory should be more ?
3. We see such logs all over in our logs. What does that indicate, should we target the application code (that Developers have written) or it maybe related to Settings in the server , memory in the box etc?
While we are debugging the application code to see that most of the objects are released as soon as possible, what are the other steps to be taken ?
Thanks for all help,
Regards,
Milan