由 System.gc() 频繁引起 Full GC 的问题排查
  6DOeteBHjp6w 2023年11月02日 56 0


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

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

这里 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 开关,官网也提到了注意事项:

名称默认值描述unsafefalse是否支持对系统级别的类进行增强,打开该开关可能导致把 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);

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

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

References

欢迎关注公众号:

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


【版权声明】本文内容来自摩杜云社区用户原创、第三方投稿、转载,内容版权归原作者所有。本网站的目的在于传递更多信息,不拥有版权,亦不承担相应法律责任。如果您发现本社区中有涉嫌抄袭的内容,欢迎发送邮件进行举报,并提供相关证据,一经查实,本社区将立刻删除涉嫌侵权内容,举报邮箱: cloudbbs@moduyun.com

  1. 分享:
最后一次编辑于 2023年11月08日 0

暂无评论

推荐阅读
  2Vtxr3XfwhHq   2024年05月17日   55   0   0 Java
  Tnh5bgG19sRf   2024年05月20日   113   0   0 Java
  8s1LUHPryisj   2024年05月17日   47   0   0 Java
  aRSRdgycpgWt   2024年05月17日   47   0   0 Java
6DOeteBHjp6w