Exploring the cause of OOM that occurred in Java from GC logs and heap dumps


Visualize GC logs

Output GC logs.

  • -Xloggc:/tmp/gc.log
  • -XX:+PrintGCDetails
  • -XX:+PrintGCDateStamps
$ cat /tmp/gc.log
2022-08-08T16:35:30.738+0000: [GC (Allocation Failure) [PSYoungGen: 638269K->3108K(665600K)] 2017703K->1382542K(2063872K), 0.0084360 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 
2022-08-08T16:35:31.320+0000: [GC (Allocation Failure) [PSYoungGen: 640548K->2565K(666624K)] 2019982K->1382000K(2064896K), 0.0086070 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 
2022-08-08T16:35:31.878+0000: [GC (Allocation Failure) [PSYoungGen: 640005K->2565K(667136K)] 2019440K->1382000K(2065408K), 0.0086495 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 
2022-08-08T16:35:32.451+0000: [GC (Allocation Failure) [PSYoungGen: 643589K->3301K(668672K)] 2023024K->1382736K(2066944K), 0.0087513 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 

Opening this file with GCViewer, a graph as follows is rendered. The upper part represents the new generation, and the lower part represents the old generation. When the purple line representing the usage of the old generation is full, the black line Full GC runs, and the blue line representing the total heap usage also decreases. In this example, the decrement of GC gradually decreases, and since the second half is almost completely black, it can be seen that full GC is always occurring.

About JVM Heap space and Full GC - sambaiz-net

As measures against Full GC, change the size of the new generation with -XX:NewRatio, -XX:+UseG1GC to use G1GC with a good performance GC algorithm, and -XX:InitiatingHeapOccupancyPercent to lower the GC start threshold can be set, but this time it looks like memory is insufficient in the first place. Maybe a memory leak occurs.

Analyze heap dumps

Therefore, took heap dumps at the timing OOM occurred and saw it with Eclipse Memory Analyzer (MAT).

  • -XX:+HeapDumpOnOutOfMemoryError
  • -XX:HeapDumpPath=/tmp

If there is no object that clearly has problems in the leak suspects, it seems that there is no choice but to increase the heap memory with -Xms, -Xmx.


まじめにJVMチューニング: 第2回 GCログをみる