GC耗时案例
youngGC耗时长
gc日志:
2020-11-13T11:23:46.075+0800: 246511.397: [GC2020-11-13T11:23:49.696+0800: 246515.018: [ParNew
Desired survivor size 107347968 bytes, new threshold 15 (max 15)
- age 1: 37600800 bytes, 37600800 total
- age 2: 644144 bytes, 38244944 total
- age 3: 413776 bytes, 38658720 total
- age 4: 368720 bytes, 39027440 total
- age 5: 111280 bytes, 39138720 total
- age 6: 30144 bytes, 39168864 total
- age 7: 274864 bytes, 39443728 total
- age 8: 80256 bytes, 39523984 total
- age 9: 90832 bytes, 39614816 total
- age 10: 150704 bytes, 39765520 total
- age 11: 44976 bytes, 39810496 total
- age 12: 114016 bytes, 39924512 total
- age 13: 309672 bytes, 40234184 total
- age 14: 73296 bytes, 40307480 total
- age 15: 227016 bytes, 40534496 total
: 1730709K->52157K(1887488K), 0.0440210 secs] 2947428K->1268934K(5033216K), 3.6648820 secs] [Times: user=0.23 sys=0.00, real=3.66 secs]
2020-11-13T11:23:49.740+0800: 246515.062: Total time for which application threads were stopped: 3.6662720 seconds
可以看到墙钟时间real远大于用户态时间user+内核态时间sys。一般real远大于user和sys,有两个原因:
一是因为繁忙的IO操作:当程序存在繁忙的I/O操作(网络IO或磁盘IO)时,会让
real
时间大幅上升。因为在记录GC日志的时候,你的程序进行了磁盘读写,如果同一时间其他IO操作较重,则此时GC事件会延迟,进而影响了最终的real
的值。二是缺乏CPU资源:当程序本身是CPU密集型应用,或机器上其他进程占用了大量的CPU计算资源,则有可能会出现分配不到 CPU cycles的情况,这会让程序挂起,GC所花费的实际时间也将远大于
user
+sys
的值。
首先查看CPU,发现没有异常,再查看磁盘使用情况,发现这段时间的磁盘占用很高,有一个很大的突刺,经过此可以初步判断是由于磁盘IO频繁导致gclog写入磁盘被阻塞。
解决办法可以将gc日志写入temfs,具体可以卸载文件夹:/dev/shm 下。
参考:
http://tang.love/2017/10/22/gc_analysis_user_sys_real/
https://blog.csdn.net/guo8113/article/details/28590963
Last updated
Was this helpful?