JVM GC

作者: 天高s | 来源:发表于2018-10-11 15:10 被阅读0次

    从实例出发
    新建一个空的 SpringBoot 项目, 比如 https://www.jianshu.com/p/2ba67caabcea

    启动运行时加一些参数 -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -verbose:gc -Xloggc:gc.log

    加 VM 参数

    - XX:+PrintGCDetails 该选项用于记录 GC 运行时的详细数据信息并输出,是最基本、使用最普遍的一个选项。这个选项适用于所有 GC,输出内容主要包括新生成对象占用内存大小以及耗费时间、各个年 龄代的情况、每次回收的对应数据等。
    -verbose:gc -Xloggc:gc.log 运行后会在项目文件夹下面生成一 个 gc.log 文件

    启动项目,查看 gc.log 文件

    gc.log

    Parallel GC 是 JDK7 之后的默认 GC,它通过多线程方式减缓了独占式 GC 的副作用(停顿时间比较长)。年轻代和老年代在 Parallel GC 里都是并行执行且独占的,老年代也执行了压缩操作,这个压缩操作指的是移动存活对象到相邻位置,这样可以减少内存浪费,更好地实现内存布局 。
    -XX:+UseCompressedOops 这个可以压缩指针,起到节 约内存占用的选项。 CompressedOops 的实现方式是在机器码中植入压缩与解压指令,可能会给 NM 增加额外的开销 。
    -XX:+UseCompressedClassPointers 选项是在 JDK8 出现的,也是在永久 区消失之后出现的新的选项,主要用于对类的元数据进行压缩 。

    GC 详细日志解读

    日志释义

    简单调优

    下面是应用启动的日志

    ***
    2018-10-11 14:47:44.561  INFO 9242 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
    2018-10-11 14:47:44.565  INFO 9242 --- [           main] com.example.gcdemo.GcDemoApplication     : Started GcDemoApplication in 4.139 seconds (JVM running for 4.801)
    2018-10-11 14:47:44.944  INFO 9242 --- [on(4)-127.0.0.1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring FrameworkServlet 'dispatcherServlet'
    2018-10-11 14:47:44.944  INFO 9242 --- [on(4)-127.0.0.1] o.s.web.servlet.DispatcherServlet        : FrameworkServlet 'dispatcherServlet': initialization started
    ***
    

    应用启动花费了 4.139 秒,查看 gc.log 日志

    应用启动 GC 日志

    启动过程中总共进行了 10 次 GC, 包括两次 Full GC, YoungGen 进行了 4 次扩容,所以为了加快启动时间,尝试一下加大初始化内存大小,减少 GC 发生次数,启动参数添加 -Xms1536m -Xmx1536m

    再次启动

    ***
    2018-10-11 16:37:22.078  INFO 9422 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
    2018-10-11 16:37:22.081  INFO 9422 --- [           main] com.example.gcdemo.GcDemoApplication     : Started GcDemoApplication in 3.373 seconds (JVM running for 3.788)
    ***
    
    gc.log

    GC 次数减少了一半, 启动时间提升了 10%,感觉不明显

    内存再加大一倍 -Xms3096m -Xmx3096m

    2018-10-11 16:44:15.991  INFO 9431 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
    2018-10-11 16:44:15.994  INFO 9431 --- [           main] com.example.gcdemo.GcDemoApplication     : Started GcDemoApplication in 3.358 seconds (JVM running for 3.971)
    
    gc.log

    启动时间相比最开始提升了 19%

    切换使用 G1GC

    添加参数 -XX:+UseG1GC

    2018-10-11 17:14:14.904  INFO 9517 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
    2018-10-11 17:14:14.908  INFO 9517 --- [           main] com.example.gcdemo.GcDemoApplication     : Started GcDemoApplication in 3.274 seconds (JVM running for 3.724)
    

    又提升了一丢丢, 达到 21%, 不过 GC 日志就变得相当复杂了
    gc.log
    贴个外链
    浅谈 G1 GC 日志格式

    相关文章

      网友评论

          本文标题:JVM GC

          本文链接:https://www.haomeiwen.com/subject/ipubaftx.html