今天a服务顺利的跑了一天,晚上打开服务器一看内存使用率低于平时,非常异常。top一看,原来是mysql挂掉了。。。
但是这样也好,至少拿到了一天的GC log。download到本地后打开,查看最后的一条:
{Heap before GC invocations=1405 (full 3):
def new generation total 15936K, used 15617K [0x00000000ed400000, 0x00000000ee540000, 0x00000000f3800000)
eden space 14208K, 99% used [0x00000000ed400000, 0x00000000ee1df8a8, 0x00000000ee1e0000)
from space 1728K, 81% used [0x00000000ee390000, 0x00000000ee4f0d80, 0x00000000ee540000)
to space 1728K, 0% used [0x00000000ee1e0000, 0x00000000ee1e0000, 0x00000000ee390000)
tenured generation total 35188K, used 23302K [0x00000000f3800000, 0x00000000f5a5d000, 0x0000000100000000)
the space 35188K, 66% used [0x00000000f3800000, 0x00000000f4ec1900, 0x00000000f4ec1a00, 0x00000000f5a5d000)
Metaspace used 50126K, capacity 53260K, committed 53504K, reserved 1095680K
class space used 7028K, capacity 7576K, committed 7680K, reserved 1048576K
2021-03-15T21:57:51.287+0800: 118701.261: [GC (Allocation Failure) 38919K->25177K(51124K), 0.0070226 secs]
Heap after GC invocations=1406 (full 3):
def new generation total 15936K, used 845K [0x00000000ed400000, 0x00000000ee540000, 0x00000000f3800000)
eden space 14208K, 0% used [0x00000000ed400000, 0x00000000ed400000, 0x00000000ee1e0000)
from space 1728K, 48% used [0x00000000ee1e0000, 0x00000000ee2b3500, 0x00000000ee390000)
to space 1728K, 0% used [0x00000000ee390000, 0x00000000ee390000, 0x00000000ee540000)
tenured generation total 35188K, used 24332K [0x00000000f3800000, 0x00000000f5a5d000, 0x0000000100000000)
the space 35188K, 69% used [0x00000000f3800000, 0x00000000f4fc30e8, 0x00000000f4fc3200, 0x00000000f5a5d000)
Metaspace used 50126K, capacity 53260K, committed 53504K, reserved 1095680K
class space used 7028K, capacity 7576K, committed 7680K, reserved 1048576K
}
可以看到full gc了三次,本次gc又有1000k的对象进入老年代,新老年带的比例是1:2,整个日志文件非常大,从invocations这个数据看,昨天中午到现在以及进行了1406次gc,可见普通gc非常频繁(在gc日志中,只有2种gc)这里可以想到的调优方式是:调大新生代,可以有效的减少普通gc次数,也让每次晋升更难一点。
接下来关注几次full gc的节点:
第一次:
{Heap before GC invocations=35 (full 0):
def new generation total 9792K, used 1591K [0x00000000ed400000, 0x00000000edea0000, 0x00000000f3800000)
eden space 8704K, 14% used [0x00000000ed400000, 0x00000000ed5318a0, 0x00000000edc80000)
from space 1088K, 33% used [0x00000000edd90000, 0x00000000eddec5e8, 0x00000000edea0000)
to space 1088K, 0% used [0x00000000edc80000, 0x00000000edc80000, 0x00000000edd90000)
tenured generation total 21888K, used 10494K [0x00000000f3800000, 0x00000000f4d60000, 0x0000000100000000)
the space 21888K, 47% used [0x00000000f3800000, 0x00000000f423f8f0, 0x00000000f423fa00, 0x00000000f4d60000)
Metaspace used 20088K, capacity 21106K, committed 21248K, reserved 1067008K
class space used 2750K, capacity 2979K, committed 3072K, reserved 1048576K
2021-03-14T12:59:40.970+0800: 10.944: [Full GC (Metadata GC Threshold) 12085K->9545K(31680K), 0.0370012 secs]
Heap after GC invocations=36 (full 1):
def new generation total 9920K, used 0K [0x00000000ed400000, 0x00000000edec0000, 0x00000000f3800000)
eden space 8832K, 0% used [0x00000000ed400000, 0x00000000ed400000, 0x00000000edca0000)
from space 1088K, 0% used [0x00000000edca0000, 0x00000000edca0000, 0x00000000eddb0000)
to space 1088K, 0% used [0x00000000eddb0000, 0x00000000eddb0000, 0x00000000edec0000)
tenured generation total 21888K, used 9545K [0x00000000f3800000, 0x00000000f4d60000, 0x0000000100000000)
the space 21888K, 43% used [0x00000000f3800000, 0x00000000f4152788, 0x00000000f4152800, 0x00000000f4d60000)
Metaspace used 20088K, capacity 21106K, committed 21248K, reserved 1067008K
class space used 2750K, capacity 2979K, committed 3072K, reserved 1048576K
}
第二次
{Heap before GC invocations=62 (full 1):
def new generation total 9920K, used 5711K [0x00000000ed400000, 0x00000000edec0000, 0x00000000f3800000)
eden space 8832K, 59% used [0x00000000ed400000, 0x00000000ed919bc0, 0x00000000edca0000)
from space 1088K, 44% used [0x00000000edca0000, 0x00000000edd1a360, 0x00000000eddb0000)
to space 1088K, 0% used [0x00000000eddb0000, 0x00000000eddb0000, 0x00000000edec0000)
tenured generation total 21888K, used 15942K [0x00000000f3800000, 0x00000000f4d60000, 0x0000000100000000)
the space 21888K, 72% used [0x00000000f3800000, 0x00000000f4791a68, 0x00000000f4791c00, 0x00000000f4d60000)
Metaspace used 33145K, capacity 35304K, committed 35416K, reserved 1079296K
class space used 4627K, capacity 5048K, committed 5120K, reserved 1048576K
2021-03-14T12:59:49.955+0800: 19.928: [Full GC (Metadata GC Threshold) 21654K->15501K(31808K), 0.0743291 secs]
Heap after GC invocations=63 (full 2):
def new generation total 11712K, used 0K [0x00000000ed400000, 0x00000000ee0b0000, 0x00000000f3800000)
eden space 10432K, 0% used [0x00000000ed400000, 0x00000000ed400000, 0x00000000ede30000)
from space 1280K, 0% used [0x00000000ede30000, 0x00000000ede30000, 0x00000000edf70000)
to space 1280K, 0% used [0x00000000edf70000, 0x00000000edf70000, 0x00000000ee0b0000)
tenured generation total 25840K, used 15501K [0x00000000f3800000, 0x00000000f513c000, 0x0000000100000000)
the space 25840K, 59% used [0x00000000f3800000, 0x00000000f47236f8, 0x00000000f4723800, 0x00000000f513c000)
Metaspace used 33145K, capacity 35304K, committed 35416K, reserved 1079296K
class space used 4627K, capacity 5048K, committed 5120K, reserved 1048576K
}
第三次
{Heap before GC invocations=1399 (full 2):
def new generation total 11712K, used 11709K [0x00000000ed400000, 0x00000000ee0b0000, 0x00000000f3800000)
eden space 10432K, 100% used [0x00000000ed400000, 0x00000000ede30000, 0x00000000ede30000)
from space 1280K, 99% used [0x00000000ede30000, 0x00000000edf6f520, 0x00000000edf70000)
to space 1280K, 0% used [0x00000000edf70000, 0x00000000edf70000, 0x00000000ee0b0000)
tenured generation total 25840K, used 24915K [0x00000000f3800000, 0x00000000f513c000, 0x0000000100000000)
the space 25840K, 96% used [0x00000000f3800000, 0x00000000f5054e50, 0x00000000f5055000, 0x00000000f513c000)
Metaspace used 47117K, capacity 50234K, committed 50432K, reserved 1093632K
class space used 6558K, capacity 7137K, committed 7168K, reserved 1048576K
2021-03-15T21:57:04.135+0800: 118654.108: [GC (Allocation Failure) 36624K->26401K(37936K), 0.0091020 secs]
2021-03-15T21:57:04.144+0800: 118654.118: [Full GC (Allocation Failure) 26401K->21112K(37936K), 0.1259435 secs]
Heap after GC invocations=1400 (full 3):
def new generation total 15936K, used 0K [0x00000000ed400000, 0x00000000ee540000, 0x00000000f3800000)
eden space 14208K, 0% used [0x00000000ed400000, 0x00000000ed400000, 0x00000000ee1e0000)
from space 1728K, 0% used [0x00000000ee1e0000, 0x00000000ee1e0000, 0x00000000ee390000)
to space 1728K, 0% used [0x00000000ee390000, 0x00000000ee390000, 0x00000000ee540000)
tenured generation total 35188K, used 21112K [0x00000000f3800000, 0x00000000f5a5d000, 0x0000000100000000)
the space 35188K, 59% used [0x00000000f3800000, 0x00000000f4c9e298, 0x00000000f4c9e400, 0x00000000f5a5d000)
Metaspace used 46970K, capacity 49994K, committed 50432K, reserved 1093632K
class space used 6532K, capacity 7089K, committed 7168K, reserved 1048576K
}
前2次是由于元空间不足导致的,最后一次是正经的堆空间不足进行回收。从几次full gc看来,总有55%左右的对象无法回收,应该是一直要使用的对象(太难了)。这样看如果按之前的想法去调整堆比例也既有可能造成老年代空间不足。
目前还是要看dump文件,看看能不能尽量减少老年代对象以及之前回收耗时过久的原因。以目前的进度来看,明天晚上应该可以拿到一个不错的dump文件。拭目以待~