JVM 性能调优实战（4）

实战:代码缓存区(Code Cache)与代码缓存区满

代码缓存区 - 存储编译后的代码

属性	作用	默认值
-XX:lnitialCodeCacheSize	设置代码缓存区的初始大小，以 java -XX: +PrintFlagsFinal 1 grep InitialCodeCacheSize结果为准	不同操作系统、不同编译器的值不同
-XX:ReservedCodeCacheSize	设置代码缓存区的最大大小，以java -XX: +PrintFlagsfinal 1 grep ReservedCodeCacheSize结果为准	不同版本不同，JDK8 64 位、JDK 11 64 位都是240M
-XX:PrintCodeCache	在JVM停止时打印代码缓存的使用情况	关闭
-XX:-PrintCodeCacheOnCompilation	每当方法被编译后，就打印一下代码缓存区的使用情况	关闭
-XX:+UseCodeCacheFlushing	代码缓存区即将耗尽时，尝试回收一些早期编译、很久未被调用的方法	打开
-XX:-SegmentedCodeCache	是否使用分段的代码缓存区，默认关闭，表示使用整体的代码缓存区	关闭

代码缓存区总结

• 设置合理的代码缓存区大小
• 如果项目平时性能OK ,但突然出现性能下降,业务没有问题
  可排查是否由代码缓存区满所导致

分析 GC 日志

Java GC日志参数整理与解读
本文来探讨如何分析GC日志。探讨的话题包括:

• JDK 8:
  GC日志打印相关的JVM参数
  o如何分析日志
• JDK11:
  GC日志打印相关的JVM参数
  如何分析日志
• GC日志可视化分析工具

JDK 8

GC 日志打印相关参数

参数	作用	默认值
-XX:+PrintGC	输出GC日志	关闭
-XX:+ PrintGCDetails	打印GC的详情	关闭
-XX:+PrintGCCause	是否在GC日志中打印造成GC的原因	关闭
-XX:+PrintGCID	打印垃圾GC的唯一标识	关闭
-XX:+PrintGCDateStamps	以日期的格式输出GC的时间戳，如2013-05-04T21 :53:59.234+0800	关闭
-XX:+PrintGCTimeStamps	以基准时间的格式，打印GC的时间戳	关闭
-XX:+PrintGCTaskTimeStamps	为每个GC工作线程的任务打印时间戳	关闭
-XX:+PrintHeapAtGC	在GC前后打印堆信息	关闭

…

另外，开启如下参数，可打印GC相关的更多信息，帮助我们更好地分析G1日志:

参数	作用	默认值
-XX:+PrintAdaptiveSizePolicy	某些GC收集器有自适应策略，自适应调整策略会动态调整Eden、Survivor、老年代的大小。使用该标记，可打印自适应调节策略相关 的信息。参考文档: https://www.jianshu.com/p/7414fd6862c5	关闭
-XX:+PrintTenuringDistribution	查看每次minor GC后新的存活周期的阈值。Desired survivor size 1048576 bytes, new threshold 7 (max 15)。其中，7新的存活周期的阈值为7	关闭

YoungGC 日志

2020-05-08T11:11:52.823-0800: 0.705: [GC (Allocation Failure) 2020-05-08T11:11 :52.823-0800:
0.705:[ DefNew: 15289K-> 1343K( 15360K) , 0.0036231 secs] 18555K-> 5065K(49536K) , 0.0037065
secs ] [Times: user=0.00 sys=0.00, real=0.00 secs ]
其中：

• 2020-05-08Т11:11:52.823-0800: 当前时间戳，由 PrintGCDateStamps 控制
• 0.705: 当前相对时间戳，表示应用启动多久后触发，由PrintGCTimeStamps 控制
• GC (Allocation Failure)：造成 GC 的原因， 由 PrintGCCause 控制
• [DefNew: 15289K-> 1343К(15360К), 0.0036231 secs]:
  DefNew: 使用不同垃圾收集器，这里的展示不同:
  ■ 使用 Serial 收集器:显示DefNew,表示Default New
  ■ 使用 ParNew 收集器:显示 ParNew
  ■ 使用 Paralle Scavenge 收集器:显示 PSYoungGen
  ■ 使用G1: G1格式和这个日志格式不一样，很好区分
  15289K: 回收前，年轻代使用的大小
  1343K:回收后，年轻代使用的大小
  15360K:年轻代总大小
  0.0036231: 花费了多久，
• 18555K 回收前，堆使用的大小
• 5065K: 回收后，堆使用的大小
• 495B6K: 堆的总大小
• 0.0037065 secs:花费时间
• user=0.00: 用户耗时
• sys=0.00: 系统耗时
• real=0.00: 实际耗时

Full GC 日志
2020-05-0811:28:16.911-0800: 7 .863:[Full GC (Allocation Failure) 2020-05-08T11:28:16.911-0800: 7.863: [ Tenured: 6847K->6848K( 6848K) 7 0.0329351 secs] 9914K- ->9483K(9920K) ,[Metaspace :30156K->30156K 1077248K)], 0.0330357 secs] [Times: user=0.03 sys=0.00, real=0.03 secs ]

• 2020-05-08T1 1:28:16.91 1-0800：当前时间戳，由 PrintGCDateStamps 控制
• 7.863: 当前相对时间戳, 表示启动多久后触发，由 PrintGCTimeStamps 控制
• Full GC (Allocation Failure) : 造成 GC 的原因，由 PrintGCCause 控制
• [Tenured: 6847K->6848K(6848K), 0.0329351 secs]
  Tenured: 使用不同垃圾收集器，这里展示不同：
  使用 Serial Old 收集器： 显示 Tenured
  使用 Parallel Old 收集器： 显示 ParOldGen
  使用 CMS 收集器：显示 CMS
  6847K：回收前，老年代使用的大小
  6848K：回收后，老年代使用的大小
  6848K: 老年代总大小
  0.0329351：货费时间
• 9914K：回收前，堆使用的大小
• 9920k：堆的总大小
• [Metaspace :30156K->30156K 1077248K)], 0.0330357 secs] [Times: user=0.03 sys=0.00, real=0.03 secs ]：元空间的使用情况
• [Times: user=0.03 sys=0.00, real=0.03 secs ] ： 同新生代日志

JDK 11

GC日志打印相关参数
从DK 9开始，GC日志由”统一日志管理”(Xlog) 管理。GC日志相关的JVM参数只剩如下两个，并且这两个参数也用Xlog代替。有关统一日志管理， 详见《JDK 11统一日志管理》一文。

参数	作用	默认值
-XX:+PrintGC	输出GC日志	关闭
-XX:+PrintGCDetails	打印GC的详情	关闭

示例:
-Xmx30m -XX: +UseSerialGC -Xlog:gc*:file=/Users/gc11.1og

日志解读

#打印使用的垃圾收集器
#0.015s指的是应用启动后过了多久
[0.015s][info][gc] Using Serial
#打印内存概览，例如堆内存地址、堆内存总大小、压缩指针模式等
[0. 015s][ info][ gc, heap,coops] Heap address: 0x00000007fe200000, size: 30 мв, Compressed oops mode: Zero based, Oop shift amount: 3

#发生了年轻代GC，原因是Allocation Failure
#GC(0)中的0， 是对垃圾收集的次数统计1从0开始
[0.213s][ info][gc, start.] GC(0) Pause Young (Al location Failure )

#年轻代占用情况:回收前占用8181K，回收后占用1023K，年轻代总大小9216K
[0.216s][ info] [ gc, heap] GC(0) DefNew: 8181K -> 1023K(9216K)

#老年代占用情况: 回收前、回收后、总大小
[0.216s][info][ ge, heap] GC(0) Tenured: 0K-> 1548K( 20480K)

#元数据占用情况: 回收前、回收后、总大小
[0.216s][ info][ gc , metaspace ] GC(0) Metaspace: 5645K->5645K(1056768K)

#整个堆的占用情况:回收前、回收后、总大小
[0.216s][info] [gc] GC(0) Pause Young (Allocation Failure) 7M->2M(29M) 3.642ms

#用户耗时、系统耗时、实际耗时
[0.217s][ info] [ge, cpu] GC(0) User=0.00s Sys=0.00s Real=o.00s

综上，其实和JDK 8的日志打印区别并不大，只是打印的格式更加整齐，输出更加清晰了。同理，其他垃圾收集器也是类似的。

GC日志可视化分析工具

• GCEasy: https://www.gceasy.io/
  TIPS:在线工具，不开源
• GCViewer: https://github.com/chewiebug/GCViewer
  TIPS:不完全支持”统一日志管理”打印出的日志。详见https://github.com/chewiebug/GCViewer中的README说明
• GCPlot: https://github.com/dmart28/gcplot
  TIPS: 很久不维护了

实战：定位并解决项目月抛越慢的问题

项目变慢的可能性有哪些?

• Stop The World过长
• 项目依赖的资源导致变慢
  数据库、网络…
• Code Cache 满了
• 线程争抢过于激烈
• 服务器问题
  操作系统问题
  其他进程争抢资源

总结

• 了解导致项目变慢的场景
• 掌握定位问题的思路
• 掌握可视化分析线程Dump的工具

TLAB与实战

• 什么么是TLAB ,作用是什么
• 对象分配总结
• TLAB实战

TLAB是什么

• 全称Thread Local Allocation Buffer，即线程私有分配缓存区
• 是一块线程专用的内存分配区域, JVM会为每个线程分配一块
• TLAB区域，占用Eden区的空间

为什么要有 TLAB

• 加速对象的分配
  对象一般都是在堆内存分配的，而堆内存是线程共享的，因此可能会有多个缓存同时在堆上分配空间，于是每一步的对象分配都需要做同步处理，JVM 底层使用 CAS 以及失败重试的方式进行处理，从而保证分配不出问题。但是如果竞争非常激烈，在堆内存分配对象效率肯定会下降，而实际项目中对象分配是 java 中最常用的操作，因此 JVM 设计了 TLAB

TLAB局限性

TLAB空间较小，所以大对象无法在 TLAB 分配，只能直接分配到线程共享的堆里面

误区避免

是一块线程专用的内存分配区域, JVM会为每个线程分配一块 TLAB 区域，占用Eden区的空间

分配独享，使用共享

属性	作用	默认值
-XX:+UseTLAB	是否启用线程私有分配缓存区(thread-local allocation buffer)	启用
-XX:MinTLABSize	最小TLAB大小，单位字节	2048
-XX:+ResizeTLAB	是否动态调整TLAB的大小	是
-XX:TLABRefillWasteFraction	由于TLAB空间比较小，因此很容易装满。比如TLAB 100K，已使用80KB，当需要再分配一个30KB的对象时，就无法分配到这个TLAB了。 这时虚拟机会有 两种选择，第一，废弃当前TLAB， 这样就会浪费20KB空间;第二，保留当前的TLAB并将这30KB的对象直接分配在堆上，这样将来有小于20KB的对象时，仍可使用这块空间。实际上虚拟机内部维护了一个叫作refill. waste的值，当请求对象大于refill waste时，会在堆中分配;若小于该值，则会废弃当前TLAB,新建TLAB分配对象。TLABRefillWasteFraction来调整该阈值，它表示TLAB中允许产生这种浪费的比例，默认值为64，即允许使用1/64的TLAB空间作为refill waste。默认情况下，TLAB和refill_ waste都会在运行时不断调整，使系统的运行状态达到最优。如果想要禁用自动调整TLAB的大小，可以使用-XX:-ResizeTLAB禁用ResizeTLAB，并使用-XX:TLABSize手工指定一个TLAB的大小。	64
-XX:+TLABStats	是否提供详细的TLAB的统计信息	是
-XX:TLABSize	设置TLAB的初始大小。如果设置成0，jVM会 自动设置TLAB初始大小。	0
-XX:TLABWaste TargetPercent	允许TLAB占用Eden空间百分比	1

对象分配总结