JAVA 十一月 19, 2023

【转】由 System.gc() 频繁引起 Full GC 的问题排查

文章字数 4.8k 阅读约需 4 mins. 阅读次数

原文地址:https://mp.weixin.qq.com/s/IHMHP9b-k0XwKPE1KjpLoQ

早上服务频繁出现 Full GC 报警(由于昨晚下掉了 -XX:+DisableExplicitGC 参数,其实会有 Full GC 产生已经在意料之中,但属实没想到会触发的这么频繁),

jstat

这里 JVM 总共运行了 4531.278 s,可以看到差不多半分钟一次 Full GC,单次 Full GC 大概耗时 1.5s。

根据经验可以判断出是由于 System.gc() 被调用引起的,但问题的关键是确定了哪个函数引发了 System.gc() 的调用(在网上最著名的案例之一是由 JXL API 框架引发的)。

这里可以借用 Arthas 的 stack 来做:

很多时候我们都知道一个方法被执行,但这个方法被执行的路径非常多,或者你根本就不知道这个方法是从哪里被执行了,此时你需要的是 stack 命令。

https://arthas.aliyun.com/doc/stack.html

但要注意的是,这里会对 java.lang.System 这个系统级别的类进行增强,所以需要开启 unsafe 开关,官网也提到了注意事项:

名称 默认值 描述
unsafe false 是否支持对系统级别的类进行增强,打开该开关可能导致把 JVM 搞挂,请慎重选择

https://arthas.aliyun.com/doc/options.html

所以可以执行命令:

# 下载&启动 Arthas
wget https://alibaba.github.io/arthas/arthas-boot.jar
java -jar arthas-boot.jar

# 输出当前方法被调用的调用路径
[arthas@1]$ options unsafe true
 NAME    BEFORE-VALUE  AFTER-VALUE                                                                                                   
-----------------------------------                                                                                                  
 unsafe  false         true                                                                                                          
[arthas@1]$ stack java.lang.System gc -n 1  >> /home/work/logs/applogs/stack_gc.log
Press Q or Ctrl+C to abort.

接下来查看日志即可:

Affect(class count: 1 , method count: 1) cost in 300 ms, listenerId: 6
ts=2023-09-13 11:02:07;thread_name=http-nio-8080-exec-18;id=1b9;is_daemon=true;priority=5;TCCL=org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedWebappClassLoader@17f22084
    @java.lang.System.gc()
        at jxl.write.biff.File.close(File.java:135)
        at jxl.write.biff.WritableWorkbookImpl.close(WritableWorkbookImpl.java:456)

可以看到在 jxl.write.biff.File#close 函数中会调用 System.gc()

  void close(boolean cs) throws IOException, JxlWriteException
  {
    CompoundFile cf = new CompoundFile(data, 
                                       data.getPosition(), 
                                       outputStream, 
                                       readCompoundFile);
    cf.write();

    outputStream.flush();
    data.close();

    if (cs)
    {
      outputStream.close();
    }

    // Cleanup the memory a bit
    data = null;

    if (!workbookSettings.getGCDisabled())
    {
      System.gc();
    }
  }

而是否会执行 System.gc() 是根据 jxl.WorkbookSettings#gcDisabled 来的:

  /**
   * Flag to indicate whether the system hint garbage collection
   * is enabled or not.
   * As a rule of thumb, it is desirable to enable garbage collection
   * when reading large spreadsheets from  a batch process or from the
   * command line, but better to deactivate the feature when reading
   * large spreadsheets within a WAS, as the calls to System.gc() not
   * only garbage collect the junk in JExcelApi, but also in the
   * webservers JVM and can cause significant slowdown
   * GC deactivated using -Djxl.nogc=true on the JVM command line
   * Activated by default or by using -Djxl.nogc=false on the JVM command line
   */
  private boolean gcDisabled;

所以这里有两种方式:

  1. JVM 启动命令添加 -Djxl.nogc=true(不建议)
  2. 手动设置 gcDisabled 属性:
WorkbookSettings workbookSettings = new WorkbookSettings();
workbookSettings.setGCDisabled(true);
workbook = Workbook.createWorkbook(outputStream, workbookSettings);

属性修改后重新发布,问题解决:

visual

References

0%