G1会将整个Java堆划分成多个大小相等的独立区域(Region),虽然还保留着新生代和老年代的概念,但新生代和老年代不再是物理隔离的,它们都是一部分Region(不需要连续)的集合。G1会跟踪各个Region里面的垃圾堆积的价值大小(回收所获得的空间大小以及回收所需时间的经验值),在后台维护一个优先列表,每次根据允许的回收时间,优先回收价值最大的Region。图2(点击可查看大图)
G1除了使用基于SATB形式的并发标记[2],使得标记效率更高外,最大的不同之处在于使用了分而治之的思路。好处主要有两点:一是可以进行部分回收,回收老年代性价比最高的Region,提高效率,并使每次回收的时间相对可控;二是,虽然从宏观上来看G1是标记清理的方式(标记需要回收的Region 并清理)。但从微观上来看,是采用标记复制的方式,即从一个或多个Region把存活对象复制到另一个Region,这样就解决了空间碎片的问题。数据的产生>>
直接去生产线验证服务运行在新框架下的表现并不是一个好的选择。在这里我们使用了框架团队自研的Traffic Mirror工具。它可以将生产上的实际流量复制,发送给两台目标机器并收集和对比响应结果。在这里我们主要利用它去模拟生产流量分别发送到部署了新、老代码的机器上,然后对比两者的性能参数。
数据的监控>>
选取的观察数据有GC count,GC Overhead,CPU Usage 和 JVM memory available。前两个参数能够直观反映 GC 运行状况,其中 GC Overhead 表示GC 的开销,它指的是,GC运行的实际时间所占的百分比。换句话说,如果GC Overhead达到了100%,那么表示在这段时间内,一直在进行垃圾收集。通常情况下,认为互联网应用的GC Overhead应该小于等于7‰。后两个参数主要用来判断当前GC的运行状况是否会对程序的运行产生严重的影响。
- 性能监控:由于通常情况下,GC发生的频率大致在秒级,而性能监控则是分钟级甚至更久,由于采样率较低,可能会导致图像的失真,所以我们主要用性能监控作为参考,去发现问题。
- GC日志:在性能监控发现问题后,可以查看对应时间的GC日志获取更加详细的信息,以此来定位问题的具体原因。
在迁移的过程中,性能是用户非常关心的一个指标,而GC的运行情况会对CPU和Memory这些关键性指标产生很大的影响,下文将会分享在迁移过程中遇到的和GC相关的问题。
在对准备迁移的代码进行性能测试时,发现使用G1替代之前的垃圾回收器之后,GC开销会普遍变高,并且 JVMmemoryavailable 的表现差异较大。如下图所示,笔者利用traffic mirror模拟某服务的实际生产流量,选取了两台硬件参数相同的服务器,在堆内存均设为4G的情况下,进行对比测试。可以看出,在使用不同GC的情况下,虽然接收的请求完全一致,但性能指标却有较大差距。图3(点击可查看大图)
从上图可以看出在有流量的时候(TPS 约为20左右)主要的不同有两处:- 数值的区别: G1 的gccount 在5左右,gcovhdx10(GC Overhead 乘以 10) 大约是10。gencon的gccount 在2左右,gcovhdx10 约为2,但是有比较多的毛刺。
波形的区别: 使用G1时,JVM Memory的波动较大,而gencon较为平稳。
虽然从GC的数据来看,G1的开销更大,但在实际情况下,使用G1的程序性能表现普遍会好一些,比如响应时间更快,CPU Usage 更低。从图3中的CPU Usage 和 JVM memory available 的数值也可以看出,在当前TPS情况下,G1的开销并没有影响到程序的正常运行。但是我们依然需要了解造成差异的具体原因,才能对实际的影响有准确的判断。获取信息最好的途径就是查看日志。前文介绍过,两种GC都采用了分代回收的技术。由于新生代和老年代的回收频率、回收区域和回收方式都有较大的区别,所以下文会分别选取新生代和老年代的日志进行对比,分析性能指标差异的原因。
图5(点击可查看大图)
通过对比并联系GC日志的上下文,可以得出以下几点:- gencon的新生代空间(2G+)远大于G1(1G);
gencon两次GC间的平均间隔时间(约40秒)远大于G1的间隔(约12秒);
gencon的young GC平均时间(约60毫秒)却远远小于G1(约140毫秒)。
由于gencon新生代空间更大,所以回收的频率会更低,在监控上即表现为 gencon的 gccount会比 G1的小。但是gencon回收的空间更大,回收花费的时间却比G1更短,这点不符合常理。因此我们把关注点转移到了为什么G1的youngGC会花费这么长的时间。继续观察G1 的日志,可以发现,总共150毫秒的执行过程中,仅Ref Proc一步就花费了108毫秒。那么可以判断,多出来的时间,应该是和Ref Proc 有关了。从JDK1.2版本开始,加入了对象的几种引用级别,从而使程序能够更好地控制对象的生命周期,帮助开发者更好地缓解和处理内存泄露的问题。这几种引用级别由高到低分别为:强引用(StrongReference)、软引用(SoftReference)、弱引用(WeakReference)和虚引用(PhantomReference)。- 强引用:当内存空间不足时,Java虚拟机宁愿抛出OutOfMemoryError错误,使程序异常终止,也不会使用GC回收。
软引用:如果一个对象只有软引用,那么它就会在内存空间不足时被GC回收。
弱引用:弱引用的对象拥有比软引用更短暂的生命周期。当一个对象只有弱引用时,每次GC都会被回收。
虚引用:虚引用并不会决定对象的生命周期。如果一个对象仅持有虚引用,那么它就和没有任何引用一样,在任何时候都可能被垃圾回收。虚引用主要用来跟踪对象被垃圾回收的活动。
软引用和弱引用经常会用作缓存。为了方便理解, 这里举一个例子。如下代码,在每次循环的结束前,都会创建一个Integer对象,变量integer持有该对象的强引用,而map持有该对象的弱应用。当前循环结束后,由于超出了变量integer的作用域,强引用会被释放,仅剩map持有该对象的弱引用。在这种情况下,在执行GC时该对象会被回收。作为key的对象被回收后,对应的value也随之被回收。
因此,如果每次循环时都检查map的size,会发现size并没有一直增加,当执行GC时,size会变小。因此示例中的代码不会OOM。但如果将示例中的WeakHashMap改为HashMap,那么map对key就会持用强引用,分配的空间在GC时不会被回收,最终会由于空间不足而导致OOM。
图6(点击可查看大图)
在G1中,Ref Proc这一步就来处理这些引用对象。默认是由单线程执行[3],如果这一步花费的时间较长,可以通过加参数-XX:+ParallelRefProcEnabled改为多线程处理。图7中的sys表示本次GC是由System.gc()显示调用的。在gencon中,由于采用的是标记清除的算法,所以会存在空间碎片的问题。从GC日志中可以发现,每隔一小时(intervalms)会执行一次带有压缩功能的global gc 去避免空间碎片。在G1中,当垃圾占比达到一定参数时,会执行多次mixed GC,直到将所有标记为需要回收的Region回收完毕。因此,mixed GC 触发的时间取决于老年代增长的速度。图8(点击可查看大图)
由于在生产环境中,老年代的增长速度并不快,G1不需要考虑空间碎片,通常需要4个小时左右才会回收一次老年代,而gencon则是一个小时一次。所以从图上来看,gencon的JVM memory available 会更加稳定。这是由不同GC的特性决定的,不需要做改动。增加启动参数-XX:+ParallelRefProcEnabled后,性能测试结果如下:图9(点击可查看大图)
可以发现,在相同TPS的情况下(约为20),gccount 仍然在5左右,但是gcovhdx10 从10降到了5。从GC日志中同样可以发现,young GC平均间隔为12秒,保持不变,平均每次执行时间从140毫秒下降到约50毫秒,单位时间内GC花费的时间减少了60%+。与图片数据吻合。看到这里可能会有疑问,为什么不将G1的新生代也调整到2G,进一步提升GC的性能? 其实也做过相关的测试,在将G1的新生代代调整为2G,同时也加上-XX:+ParallelRefProcEnabled参数后,随着新生代空间的增大,平均单次回收时间增加到了约120毫秒,平均回收间隔约50秒。单位时间内的GC花费的时间会在只加参数的情况下再次减少40%左右。但是,当回收老年代的时候,会出现to-space exhausted事件,并进行一次长达3秒的full GC。to-space exhausted[4]通常意味着survivor 或者老年代没有足够的空间留给存活或者晋升的对象。此处是由于增大新生代后,老年代空间变小,当老年代空间不足时,并没有标记出足够的空间提供给晋升的对象。我们可以通过减小-XX:InitiatingHeapOccupancyPercent(默认为45) 的值来更早地触发标记周期,在老年代满之前标记出足够的空间可供回收。由于在只添加-XX:+ParallelRefProcEnabled参数的情况下,GC开销已经达到了期望值,而且进一步的优化则需要根据不同应用的实际情况而不断地尝试各自的最优配置,不具备通用性,所以这部分留给业务团队根据各自的实际情况进行配置。现象>>
在对某个服务进行迁移时,我们观察到如下数据。不同颜色代表不同的机器,可以发现很多机器在不同的时间段内都出现了GC overhead达到了100%的情况。意味着这段时间内,该机器不能对外提供服务。这是一个很危险的情况,而且并不是偶然。
图10(点击可查看大图)
我们找到其中一台机器在GC overhead到达100%时的GC日志,如下:图11(点击可查看大图)
从日志中可以发现,这两次GC都是full GC。在G1中正常情况下只有young GC 和 mixed GC,full GC 在G1 GC 无法满足内存分配需求时就会切换到serial old GC来收集整个堆内存。严格意义上来讲,full GC 并不属于G1,而是G1无法满足需求时使用的兜底策略。另外,我们还可以从时间戳和执行时间上发现,这两次GC是连续的,并且花费的时间也很长,这就是GC Overhead会升到100%的原因。第一次GC的原因是Metadata GC Threshold,这表示是由MetaSpace空间不足引起的,而经过第一次GC,Metaspace空间并没有减少,于是引起了第二次GC,第二次GC会尝试清除软引用,但是MetaSpace空间依然没有减少。看到这里,第一反应就是MetaSpace有问题。在JDK1.8中,为了更灵活地管理内存,永久代被移除,取而代之的是Metaspace。配置永久代的相关参数PermSize以及MaxPermSize也不会再生效了。在检查了启动参数之后,发现在V3的启动参数中,指定了永久代大小,并且大于Raptor.io中metaSpace的默认大小。当在大量使用反射、动态代理、动态生成JSP功能时, Metaspace空间会发生不足,导致无法正常回收。解决方案>>
了解原因之后,解决起来就很简单了,在启动参数中将maxMetaSpaceSize设置为与V3的永久代大小相同。改动后GCOverhead如下图所示,100%的情况不再出现了。
经过这次的GC调优,有两点让我感触很深: 一是纸上得来终觉浅,绝知此事要躬行。GC的知识大家或多或少都在书本上看到过,但是要把这些知识运用到实际的生产中,则是另一种完全不同的体验。在这个过程中,会发现很多自己之前忽略的细节。二是很多问题解决起来其实并不复杂,甚至十分简单。就如同本文中分享的例子,只用加一个参数就能解决。但是要知道加哪个参数,为什么加,则需要平时不断的积累。总之,前路漫漫,关于平台迁移中的GC调优,还有许多需要学习的地方。希望能通过本篇文章,与大家分享已有的一些案例和经验,从而为同业人员提供一定的借鉴和参考。[1]https://www.oracle.com/technetwork/tutorials/tutorials-1876574.html[2]https://docs.oracle.com/javase/8/docs/technotes/guides/vm/gctuning/g1_gc.htmll[3]https://docs.oracle.com/javase/9/gctuning/garbage-first-garbage-collector-tuning.htm#JSGCT-GUID-4914A8D4-DE41-4250-B68E-816B58D4E278[4]https://www.oracle.com/technical-resources/articles/java/g1gc.html