ZGC在去哪儿机票运价系统实践
作者介绍
5年一线项目开发经验,2019年加入去哪儿网,深耕于去哪儿机票底层数据系统,擅长高并发系统的设计及开发。
一、背景
我所负责的机票运价系统是去哪儿机票底层最核心的价格计算和存储引擎,其提供的基础航班运价数据供去哪儿机票几乎所有业务系统使用,提供接口调用QPS 3万+,日均调用 7 亿次以上,平均响应时间小于 2 ms,是当之无愧的亿级流量、高并发、低延迟系统。在这样的系统中,接口 P99 长尾往往会成为性能瓶颈。这次在上游核心系统重构的契机下,发现调用运价接口超时率达到了 2% ,这表示有至少 2% 的用户体验将受到影响,作为机票最核心的服务之一,这种可用性是不能被接受的。我们需要排查这个问题并做出优化。如果你的项目对低延迟有很高的要求,这篇文章对你一定有帮助。
分析业务监控指标,有无需求迭代影响
讨论接口超时率,先看超时时长设置
调用方B(超时时间:100ms)监控指标如下:100ms下超时率接近百分之三:103/3498=0.029
如果超时时间不能调整呢
全链路追踪,超时 case 一览无遗
第一步是调用方执行时长(我们上游的处理时长),由于超过 100ms 的超时时间,显示为异常。
第二步是提供方的执行时长(我们服务的处理时长),显示为 0ms 。接下来让我们看看具体的细节,下面第一张图是调用方记录的处理过程,第二张图是提供方记录的处理过程:
我们可以看到调用方在 16:58:23:041 发起了调用,一直到 16:58:23:147 超过了 100ms ,由于超时结束调用。而提供方是在 16:58:23:208 才收到请求开始处理。这意味着调用方都超时了,提供方还没有收到请求,并不是我们的服务业务处理慢导致。那么问题是,中间的 100ms 去哪里了?
消失的100ms到底去哪了
public class QTraceFilter {
@Activate(group = {Constants.CONSUMER}, before = "qaccesslogconsumer")
public static class Consumer implements Filter {
private static final QTraceClient traceClient = QTraceClientGetter.getClient();
@Override
public Result invoke(Invoker<?> invoker, Invocation inv) throws RpcException {
final long startTime = System.currentTimeMillis();
Result result = invoker.invoke(inv);
//收集consumer指标
}
}
@Activate(group = {Constants.PROVIDER}, before = "qaccesslogprovider")
public static class Provider implements Filter {
private static final QTraceClient traceClient = QTraceClientGetter.getClient();
@Override
public Result invoke(Invoker<?> invoker, Invocation inv) throws RpcException {
final long startTime = System.currentTimeMillis();
Result result = invoker.invoke(inv);
//收集provider指标
}
}
}
通过以上代码我们可以知道,链路系统记录的时间只是业务的执行时间,那消失的 100ms 可能在如下部分:
是我们的服务有问题吗
线程池大小调整
<dubbo:protocol name="dubbo" port="20880" id="main" threads="800" iothreads="32"/>
遗憾的是超时率是没有任何的变化,扩大线程池没有太大作用。
终究还是STW惹的祸
-Xms7g -Xmx7g -XX:NewSize=5g -XX:PermSize=256m -server -XX:SurvivorRatio=8 -XX:GCTimeRatio=2 -XX:+UseParNewGC -XX:ParallelGCThreads=2 -XX:+CMSParallelRemarkEnabled -XX:+UseCMSCompactAtFullCollection -XX:+UseFastAccessorMethods -XX:+CMSPermGenSweepingEnabled -XX:+CMSClassUnloadingEnabled -XX:CMSInitiatingOccupancyFraction=70 -XX:SoftRefLRUPolicyMSPerMB=0 -XX:+UseCMSInitiatingOccupancyOnly -XX:+DisableExplicitGC -Dqunar.logs=$CATALINA_BASE/logs -Dqunar.cache=$CATALINA_BASE/cache -verbose:gc -XX:+PrintGCDateStamps -XX:+PrintGCDetails -Xloggc:$CATALINA_BASE/logs/gc.log
可以看到在 GC 上也是做了比较多的优化,主要针对 CMS 做了各种优化,对于新生代的优化主要是两个:设置新生代堆内存为 5g ,以及设置 ParNew 的垃圾回收线程数为 2 ;通常我们会忽略新生代的 GC 的影响,下意识认为 YoungGC 很快,且 STW 的时间短,不会对服务产生大的影响。而我们这次的问题恰恰就是 YoungGC 导致的问题。让我们仔细分析一下:由于我们的服务 qps 高,又有大量的本地缓存(缓存时间短)的使用,会产生大量的对象,这些对象朝生夕死,一般的调优思路为加大新生代内存,不让这些对象由于内存不足进入老年代,在新生代就完成 GC 。可是问题是 YoungGC 真的快吗?针对于大内存(超过4G)的 YoungGC 其实并不快,ParNew 本质上是一个多线程垃圾回收器,采用了标记复制算法,在多线程标记和复制的过程中,用户线程就会 STW ,新生代越大则 STW 时间越长。我们的 YoungGC 时间监控如下所示:
在 GC 日志中可以看到 ParNew 在不同维度的耗时,user 是 GC 实际使用 CPU 的时间,sys 是系统调用或系统事件响应的耗时,real 是导致应用程序暂停的时间,也就是 STW 的时间,以下截取自我们线上服务日志:
2022-08-22T15:06:12.131+0800: 1051305.996: [GC (Allocation Failure) 2022-08-22T15:06:12.132+0800: 1051305.997: [ParNew: 4381100K->188250K(4718592K), 0.1881919 secs] 6342998K->2153358K(6815744K), 0.1890062 secs] [Times: user=0.37 sys=0.00, real=0.19 secs]
2022-08-22T15:06:22.782+0800: 1051400.647: [GC (Allocation Failure) 2022-08-22T15:06:22.783+0800: 1051400.648: [ParNew: 4382554K->192088K(4718592K), 0.1679972 secs] 6347662K->2163478K(6815744K), 0.1687044 secs] [Times: user=0.32 sys=0.01, real=0.17 secs]
所以到这里,我们得出结论:我们服务的超时率和YoungGC相关,我们需要优化GC。
继续使用 ParNew+CMS,优化参数,减少新生代堆内存大小,让 CMS 也可以发挥作用
使用 G1 垃圾回收器
升级使用 ZGC ,让性能达到极致
JDK11升级
删除部署堆栈 删除 Java EE 和 CORBA 模块 安全更新 移除 API、工具和组件
代码改动
<!-去哪儿项目指定JDK版本为11的方式-->
<properties>
<java_source_version>11</java_source_version>
<java_target_version>11</java_target_version>
</properties>
<!-如果你的项目中使用了@Resource、@PostContruct等注解,请增加下面依赖-->
<dependency>
<groupId>javax.annotation</groupId>
<artifactId>javax.annotation-api</artifactId>
<version>1.3.2</version>
</dependency>
<!-如果你的项目中使用了JDK事务相关,请增加下面依赖-->
<dependency>
<groupId>javax.transaction</groupId>
<artifactId>javax.transaction-api</artifactId>
<version>1.3</version>
</dependency>
<!-如果你的项目中使用了XML解析相关工具,请增加下面依赖-->
<dependency>
<groupId>javax.activation</groupId>
<artifactId>activation</artifactId>
<version>1.1.1</version>
</dependency>
<dependency>
<groupId>javax.xml.bind</groupId>
<artifactId>jaxb-api</artifactId>
<version>2.2.11</version>
</dependency>
<dependency>
<groupId>com.sun.xml.bind</groupId>
<artifactId>jaxb-core</artifactId>
<version>2.2.11</version>
</dependency>
<dependency>
<groupId>com.sun.xml.bind</groupId>
<artifactId>jaxb-impl</artifactId>
<version>2.2.11</version>
</dependency>
环境准备
我这里使用去哪儿的云原生环境,可以直接选择JDK11+tomcat8镜像直接部署:
JVM参数配置,参考下一小节ZGC使用
ZGC使用
-Xmx7g -Xms7g -XX:ReservedCodeCacheSize=256m -XX:InitialCodeCacheSize=256m -XX:+UnlockExperimentalVMOptions -XX:+UseZGC -XX:ConcGCThreads=4 -XX:ZAllocationSpikeTolerance=5 -Xlog:gc*:file=$CATALINA_BASE/logs/gc.log:time
去哪儿云原生环境下设置方式如下图:
ZGC 是一款相当智能的垃圾回收器,配置参数不算太多,需要优化的就更少了,后面会提到,全部配置如下:
G1 和 ZGC 效果对比
ZGC回收次数(大概6秒每次)
ZGC回收时间(13ms)
GC次数小幅增加,STW 时间降低为10ms
调用方超时率降低几乎100倍,超时率从百分之二降低到万分之三
观察调用方监控,超时量从高峰期 100qps 以上降低到 1 左右,超时率降低 100 倍。我们的服务在 100ms 超时下,实现了 3 个 9 ,接近 4 个 9 的可用性。
从 CMS 到 G1 再到 ZGC ,到底优化了啥
ZGC内存模型
小页面:容量固定为 2MB,用于存放小于 256KB 的小对象。 中页面:容量固定为 32MB,用于存放大于等于 256KB 但小于 4MB 的对象。 大页面:容量不固定,可以动态变化,但必须为 2MB 的整数倍,用于存放大于等于 4MB 的对象。每个大页面只会一个大对象,也就是虽然它叫大页面,但它的容量可能还没中页面大,最小容量为 4MB 。
ZGC核心组件介绍
对象 MarkWord 中的 GC 标记
指针如何染色指针
指针的原本的作用在于寻址,如果我们想实现染色指针,就得把43~46位赋予特殊含义,这样寻址就不对了。所以最简单的方式是寻址之前把指针进行裁剪,只使用低 42 位去寻址。那么解决的方案可能是:
// 比如我们的一个指针如:0x13210 ,高位1表示标记,低位3210表示地址。
ptr_with_metadata = 0x13210;
// 移除标记位,得到真实地址
AddressBitsMask = ((1 << 16) - 1);
address = ptr_with_metadata & AddressBitsMask
// 使用真实地址
use(*address)
// 将物理内存pmem映射到marked0、marked1、remapped
map_view(ZAddress::marked0(offset), pmem);
map_view(ZAddress::marked1(offset), pmem);
map_view(ZAddress::remapped(offset), pmem);
// 最终对于linux mmap函数的调用
void ZPhysicalMemoryBacking::map(uintptr_t addr, size_t size, uintptr_t offset) const {
const void* const res = mmap((void*)addr, size, PROT_READ|PROT_WRITE, MAP_FIXED|MAP_SHARED, _fd, offset);
if (res == MAP_FAILED) {
ZErrno err;
fatal("Failed to map memory (%s)", err.to_string());
}
}
视图 (View)
和染色指针适配的三种视图
“好”指针和“坏”指针
触发读屏障
Object o = obj.fieldA; // 只有从堆中获取一个对象时,才会触发读屏障
//读屏障伪代码
if (!(o & good_bit_mask)) {
if (o != null) {
//处理并注册地址
slow_path(register_for(o), address_of(obj.fieldA));
}
}
ZGC收集过程
void ZDriver::run_gc_cycle(GCCause::Cause cause) {
ZDriverCycleScope scope(cause);
// Phase 1: 初始标记(STW) Pause Mark Start
{
ZMarkStartClosure cl;
vm_operation(&cl);
}
// Phase 2: 并发标记 Concurrent Mark
{
ZStatTimer timer(ZPhaseConcurrentMark);
ZHeap::heap()->mark();
}
// Phase 3: 最终标记(STW) Pause Mark End
{
ZMarkEndClosure cl;
while (!vm_operation(&cl)) {
// Phase 3.5: 如果超时,继续并发标记
ZStatTimer timer(ZPhaseConcurrentMarkContinue);
ZHeap::heap()->mark();
}
}
// Phase 4: 并发弱引用处理 Concurrent Reference Processing
{
ZStatTimer timer(ZPhaseConcurrentReferencesProcessing);
ZHeap::heap()->process_and_enqueue_references();
}
// Phase 5: 并发重置Relocation Set, 在进行标记后,GC统计了垃圾最多的若干region,将它们称作:relocation set
{
ZStatTimer timer(ZPhaseConcurrentResetRelocationSet);
ZHeap::heap()->reset_relocation_set();
}
// Phase 6: 并发回收无效页
{
ZStatTimer timer(ZPhaseConcurrentDestroyDetachedPages);
ZHeap::heap()->destroy_detached_pages();
}
// Phase 7: 并发选择Relocation Set
{
ZStatTimer timer(ZPhaseConcurrentSelectRelocationSet);
ZHeap::heap()->select_relocation_set();
}
// Phase 8: 初始转移前准备(STW)
{
ZStatTimer timer(ZPhaseConcurrentPrepareRelocationSet);
ZHeap::heap()->prepare_relocation_set();
}
// Phase 9: 初始转移(STW)
{
ZRelocateStartClosure cl;
vm_operation(&cl);
}
// Phase 10: 并发转移
{
ZStatTimer timer(ZPhaseConcurrentRelocated);
ZHeap::heap()->relocate();
}
}
让我们仔细分析下这个过程,看看 ZGC 是如果做到 STW 不受堆内存扩大的影响。ZGC 只有三个 STW 阶段:初始标记,最终标记,初始转移。其中,初始标记和初始转移类似,都只需要扫描所有 GC Roots,其处理时间和 GC Roots 的数量成正比,一般情况耗时非常短;再标记阶段 STW 时间更短,最多 1ms ,超过 1ms 则再次进入并发标记阶段。即,ZGC 几乎所有暂停都只依赖于 GC Roots 集合大小,停顿时间不会随着堆的大小或者活跃对象的大小而增加。与 ZGC 对比,G1 的转移阶段完全 STW 的,且停顿时间随存活对象的大小增加而增加。
ZGC日志解读
统计日志,默认10秒打印1次
垃圾回收日志,回收1次打印1次
ZGC调优
阻塞内存分配请求触发:当垃圾来不及回收,垃圾将堆占满时,会导致部分线程阻塞。日志中关键字是“Allocation Stall”。 基于分配速率的自适应算法:最主要的 GC 触发方式,其算法原理可简单描述为” ZGC 根据近期的对象分配速率以及 GC 时间,计算出当内存占用达到什么阈值时触发下一次 GC ”。日志中关键字是“Allocation Rate”。 主动触发规则:类似于固定间隔规则,但时间间隔不固定,是 ZGC 自行算出来的时机。日志中关键字是“Proactive”。其中,最主要使用的是 Allacation Stall GC 和 Allocation Rate GC。我们的调优思路为尽量不出现 Allocation Stall GC , 然后 Allocation Rate GC 尽量少。为了做到不出现 Allocation Stall GC ,我们需要做到垃圾尽量提前回收,不要让堆被占满,所以我们需要在堆内存占满前进行 Allocation Rate GC 。为了 Allocation Rate GC 尽量少,我们需要提高堆的利用率,尽量在堆占用 80% 以上进行 Allocation Rate GC 。基于此,Oracle 官方 ZGC 调优指南只建议我们调整两个参数:
堆大小(-Xmx -Xms):设置更大的堆内存空间 ZGC 线程数 (-XX:ConcGCThreads):调整线程数控制 Allocation Rate GC 回收的速度
https://wiki.openjdk.org/display/zgc/Main
http://cr.openjdk.java.net/~pliden/slides/ZGC-Jfokus-2018.pdf
https://docs.oracle.com/en/java/javase/11/gctuning/z-garbage-collector1.html#GUID-A5A42691-095E-47BA-B6DC-FB4E5FAA43D0
https://pdai.tech/md/java/jvm/java-jvm-gc-zgc.html#gc---java-%E5%9E%83%E5%9C%BE%E5%9B%9E%E6%94%B6%E5%99%A8%E4%B9%8Bzgc%E8%AF%A6%E8%A7%A3