由 Finalizer 和 SocksSocketImpl 引起的 Fullgc 问题盘点


本文地址:http://www.6aiq.com/article/1571404213343
知乎专栏 点击关注
本文版权归作者和AIQ共有,欢迎转载,但未经作者同意必须保留此段声明,且在文章页面明显位置给出

问题描述

  • 问题 1: 我们的网关服务在发布刚启动的时候,总是会报几次 fullgc,并且会引起少量请求超时。

  • 问题 2.:同时服务在某些时间点会报出较多的超时异常,在 cat 监控上观察到超时异常和 fullgc 时间点吻合,fullgc 耗时在 600ms 左右,那么至少 fullgc 停顿时间是造成短时间内大量超时的因素。并且观察到 old 区内存非常缓慢的线性增长,在达到 old 区内存 92% 左右时,触发 fullgc,old 内存开始占用很小。并且从 eden 区 young gc 稳定,每次 young gc 后 eden 内存基本都可以回收, 所以当时初步判断进入 eden 区的对象应该是由于每次 younggc 少量对象因 gc 年龄太大而晋升。

  • 问题 3: fullgc 时间 600ms 左右,时间过长

JVM 运行参数:

-XX:InitialHeapSize=4244635648 -XX:MaxHeapSize=4244635648 -XX:MaxNewSize=1414529024 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=1414529024 -XX:OldSize=2830106624 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC

老年代回收默认使用了 ParallelOld 收集器

排查

调整 JVM 参数,打印 gc 详细日志,其它 JVM 参数没有变化。在线下环境进行压测,观察到服务刚启动时,下图红框显示了 fullgc 的原因是Metadata GC Threshold

f6282ee714fa490f9d6f0fadc290522a-image.png

因为使用 ParallelOld 收集器即使加上参数也无法打印 survivor 区的对象年龄分布,只能显示 desired survivor size。所以启用 CMS 收集器进行压测成功打印了 age 分布信息

46148fdd168a48a5a29cad5660213a60-image.png

登上线上机器查看当前进程里对象占用内存的前 20 排名


[bbb@aaa bin]$ ./jmap -histo:live 6258 | head -20

 num  #instances  #bytes class name

----------------------------------------------

 1:  26715  25520840 [I

 2: 215586  24046568 [C

 3:  95269  18935792 [B

 4:  69325 7764400 java.net.SocksSocketImpl

 5: 108223 6844216 [Ljava.lang.Object;

 6: 395157 6322512 java.lang.Object

 7: 213313 5119512 java.lang.String

 8: 125955 4030560 java.util.concurrent.ConcurrentHashMap$Node

 9:  69319 3327312 java.net.SocketInputStream

 10:  69319 3327312 java.net.SocketOutputStream

 11:  36674 3227312 java.lang.reflect.Method

 12:  98415 3149280 java.util.HashMap$Node

 13:  69833 2793320 java.lang.ref.Finalizer

 14: 106620 2558880 java.net.InetAddress$InetAddressHolder

 15: 106614 2558736 java.net.Inet4Address

 16:  31185 2536648 [Ljava.util.HashMap$Node;

 17:  59156 2366240 java.util.LinkedHashMap$Entry

dump 内存后进行分析,在 dominator_tree 中可以看到大对象 Finalizer 的 Retained Heap 列是指该对象 GC 之后所能回收到内存的总和,可以看出由 Finalizer 关联的引用所占的空间最多。

438775b946e5471fb87d3c3bbf7f172f-image.png

在 histogram 视图中可以看到占用内存前几高的对象都是和 socket 相关的

9d4ff80f75af4532b8b1cb619bfbae50-image.png

查看 dump 内存中的不可达对象中,org.apache.commons.pool.impl.CursorableLinkedList$Listable 对象非常多。

8827d303fc424fe2a7aabeda003246eb-image.png

在支配树中查看该对象的引用关系发现 Listable 中存的 value 是 GenericKeyedObjectPool 的内部类 ObjectTimestampPair,ObjectTimestampPair 中存的 value 指向的是 thrift 通信所用的 TSocket, TSocket 中封装着 jdk 的 java.net.Socket。Socket 中使用的 SocketImpl 的实现是 SocksSocketImpl,在 SocksSocketImpl 的父类 AbstractPlainSocketImpl 中,重写了 finalize()方法,从注释可以看出来,该方法的作用是:为了防止用户忘记关闭资源,当 SocksSocketImpl 被回收时,finalize 被调用执行清理工作,SocksSocketImpl 的 close() 方法体中也是直接调用 AbstractPlainSocketImpl 的 close()。

c307f3e44c124cff9b681d63c8c662ea-image.png

原因

启动时 fullgc

MetaspaceSize 初始值过小

线上设置 -XX:MetaspaceSize 初始值过小,metaspace 会在 -XX:MaxMetaspaceSize 范围内动态扩容,在启动过程中,每次 fullgc 后也观察到了 commit 的 metaspace 空间变大了。(在这里当时观察到 fullgc 后,整个新生代对象全部清空了,老年代大了非常多,难道本该进入 survivor 区的都进入了老年代???)

其它可能原因

-XX:TargetSurvivorRatio 为单个 survivor 区的目标存活率

Desired survivor size = (survivor_capacity _TargetSurvivorRatio) / 100 _sizeof(a pointer):survivor_capacity(一个 survivor space 的大小)乘以 TargetSurvivorRatio

3acd5dd73b7544a9a905b7f1a8edb701-image.png

正常默认 desired survivor size 是一个 survivor space 的 50%,线上默认没有启用 -XX: +UseAdaptiveSizePolicy,参数意味着 eden 区和 survivor 区的比例是动态调整的,从 gc 日志也能观察到某时刻 survivor 区可能非常小,很容易导致 survivor 区溢出,survivor 之所以动态调整是因为希望系统尽可能的满足系统吞吐量。

如果所有 age 的 survivor space 对象的大小如果超过 Desired survivor size,则重新计算 threshold,以 age 和 MaxTenuringThreshold 的最小值为准,否则以 MaxTenuringThreshold 为准,即为了满足设定的 survivor 区的目标存活率,JVM 会自动调整 MaxTenuringThreshold。比如年龄从 1-7 的对象总和已经 >Desired survivor size,那么 TenuringThreshold 可能降低为 6,生怕 survivor 区溢出。那么把 survivor 区适当调大,TenuringThreshold 值就可能到达 15,长期存活对象就越有可能在新生代被回收。

老年代缓慢增长

NettyIO 和 ThriftIO 的连接池

由于 tcp 连接频繁创建代价非常大,所以有了长连接和连接池技术。我们目前线上使用的原生的 thriftIO(TNonblockingSocket),使用上面提到的 apache 的对象池GenericKeyedObjectPool 的实现来缓存建立的连接,看了下我们连接池的参数配置,

minIdle=1,
MaxIdle=5,
maxActive=300,
连接池队列使用 FIFO 管理池对象
minEvictableIdleTimeMillis 为 30 分钟,默认 30 分钟后,连接从池中销毁

意味着

1. 在 qps 较低的时候(夜间)大量请求都会使用池的头部链接,后部连接会因为到达 evict 时间而被销毁

2. 在 qps 较高的时候,池对象无空闲,500ms 后在小于 maxActive 情况下创建新的连接,并使用完后立刻销毁无法复用

3. 查看我们 younggc 每分钟频次,在 30 分钟内对象年龄分布中超过 15 完全有可能,即很可能出现 SocksSocketImpl 对象频繁晋升老年代

4. Finalizer 的 Retain Heap 之所以那么大,也是因为内存中存在大量 SocksSocketImpl 对象

4. socket 对象内部的 byte[] 也会随着进入老年代

ThriftIO 情况下,每个请求独占一个 socket 连接,当基于该连接的请求在服务端处理时,该连接空闲率增加。

NettyIO 情况下,多个请求同一时刻可以复用同一个 channel 来传输数据,意味着同样 qps 下,NettyIO 会创建较少的连接数

ThriftIO 的池化依赖的 apache common pool,使用TNonblockingSocket作为TTransport

NettyIO 的池化由公司自研,看了下其实现 Netty 连接池的原理,大体原理是:



1. 设定池大小的最小最大配置

2. 将池对象 Channel 放到数组或 List 中,每个请求都从池中随机选择一个 Channel(很可能选择的是同一个)

3. 两个 ConcurrentHashMap 中,一个保存写出的消息 ID 和 Callback,另一个包含消息 ID 和 LinkedBlockingQueue,这样解决了多线程操作 channel 响应结果到底是哪个线程的问题

3. 业务线程使用 Netty 的 Channel 作为 thrift 的TTransport层进行 writeAndFlush 发送消息

4. 业务线程 blcok 在从 LinkedBlockingQueue 中获取结果

5. Netty 的某 ClientHandler 解码后进行 callback 调用,并添加结果到 LinkedBlockingQueue

6. 阻塞的业务线程返回 进行处理

Finalizer 原理

e0f7dc29deb34ee68fe06664ae7a9189-image.png

因为 SocksSocketImpl 对象实现了 finalize 方法,JVM 在 java 对象创建过程中识别出其实现了 finalize 方法,会将其封装成 Finalizer 对象,Finalizer 是一个双向链表,并添加到 Finalizer 链表中,这样有 Finalizer 引用存在,SocksSocketImpl 对象即使已经无用也不会被回收。

c652ca3a742b471db5a23735d4d9f575-image.png

Finalizer 的祖父类 Refrence 有一个 ReferenceHandler 线程,来完成将 Finalizer 新添加的对象加入到 RefrenceQueue 中,该线程具体执行时机是在pending字段被设置的时候,即会在 GC 线程进行第一次标记的时候,接着 RefrenceQueue 在 enquery 方法中通过notifyAll方法唤醒FinalizerThread线程执行后续逻辑,FinalizerThread是在Finalizer类的静态代码块中会创建一个FinalizerThread类型的守护线程,但是这个线程的优先级比较低,意味着在 cpu 吃紧的时候可能会抢占不到资源执行。实现如下

c749a6785f7a4d7d9d3b970541f1d1e8-image.png

FinalizerThread线程干的事情就是执行对象实现的 finalize 方法,然后将 Finalizer 对象从 Finalizer 链表中删除

0cd02f3724ae48969ba1709b37048427-image.png

意味着如果在执行 finalize 方法时,对象没有再次赋给强引用,现在也没有了 Finalizer 引用,那么在下一次 GC 时,便会被真正的回收,即实现 finalize 方法的对象的回收至少需要两次 gc,而FinalizerThread 执行优先级非常低,

SocksSocketImpl的父类重写了finalize方法,这么做主要是为了确保在用户忘记手动关闭socket连接的情况下,在该对象被回收时能够自动关闭socket来释放一些资源,但是在开发过程中,真的忘记手动调用了close方法,那么这些socket对象可能会因为FinalizeThread线程迟迟没有执行到这些对象的finalize方法,而导致一直占用某些资源,造成内存泄露。

fullgc 耗时较长

线上没有采用 更关注系统响应时间 CMS 收集器,同时有可能标记大量 Finalizer 对象的处理耗时较多,毕竟 Finalizer 对象数量很大。

如果采用 CMS 收集器,那么 CMS FinalMarking(并发重新标记,STW 过程)进行如下的处理:

  1. 遍历新生代对象,重新标记

  2. 根据 GC Roots,重新标记

  3. 遍历老年代的 Dirty Card,重新标记,这里的 Dirty Card 大部分已经在 clean 阶段处理过

在第一步骤中,需要遍历新生代的全部对象,如果新生代的使用率很高,需要遍历处理的对象也很多,这对于这个阶段的总耗时来说,是个灾难(因为可能大量的对象是暂时存活的,而且这些对象也可能引用大量的老年代对象,造成很多应该回收的老年代对象而没有被回收,遍历递归的次数也增加不少)

解决

NettyIO

推动各端的客户端使用 NettyIO

目标

  • 解决服务启动过程中会出现几次 fullgc 问题
  • 降低频繁创建连接
  • 降低 fullgc STW 时间
  • 降低高龄成员缓慢晋升导致 fullgc 次数

JVM 参数

  1. 打印 gc 详细信息及 gc 耗时
  2. 减少堆内存 减少 gc 耗时
  3. 打印 survivor 区年龄分布
  4. 启用 CMS,启动 remark 阶段并行 &remark 前 YGC,减少 remark 阶段耗时
  5. 增大 metaspace,解决服务启动时的 fullgc
  6. 并行处理 Reference Finalizer 队列 加快 Finalizer 引用对象(好多 socket 相关)的快速回收
  7. 提升 SurvivorRatio 目标存活率,减少分配担保晋升
-Xmx4g
-Xms4g
-Xmn1.5g
-Xloggc:gc.log
-XX:MetaspaceSize=200m
-XX:MaxMetaspaceSize=1g
-XX:+PrintHeapAtGC
-XX:+PrintFlagsFinal
-XX:+PrintGCDetails
-XX:+PrintGCDateStamps
-XX:+PrintTenuringDistribution
-XX:+PrintGCTimeStamps
-XX:+PrintGCApplicationStoppedTime
-XX:+ParallelRefProcEnabled
-XX:+UseParNewGC
-XX:+UseConcMarkSweepGC
-XX:+CMSScavengeBeforeRemark
-XX:TargetSurvivorRatio=70
-XX:SurvivorRatio=8
-XX:+HeapDumpOnOutOfMemoryError

优化后老年代增长比其它未优化机器缓慢,且启动时未再出现 fullgc。
0adb52c45e5a4f7d8817ddbe850bf07b-image.png
优化后,CMS 最耗时的 remark 阶段花费 160ms,remark 阶段 STW 总耗时降低到 200ms 以内,降低至优化前 1/3 耗时,且高峰低峰 STW 耗时平稳。
ca31811d60d84821a56c39f9dca35951-image.png

29e287d3dc7c4960bb2bbde4b69c7054-image.png

附录

GC ROOTS

  1. System Class:由 bootstrap classloader 加载的类,例如 rt.jar,里面的类的包名都是java.util.*开头的。

  2. JNI Local:native 代码中的局部变量,例如用户编写的 JNI 代码或 JVM 内部代码。

  3. JNI Global:native 代码中的全局变量,例如用户编写的 JNI 代码或 JVM 内部代码。

  4. Thread Block:被当前活跃的线程锁引用的对象。

  5. Thread:正在存活的线程

  6. Busy Monitor:调用了 wait()、notify() 或 synchronized 关键字修饰的代码——例如synchronized(object)synchronized方法。

  7. Java Local:局部变量。例如函数的输入参数、正在运行的线程栈里创建的对象。

  8. Native Stack:native 代码的输入或输出参数,例如用户定义的 JNI 代码或 JVM 的内部代码。在文件 / 网络 IO 方法或反射方法的参数。

  9. Finalizable:在 finalize 队列中等待它的 finalizer 对象运行的对象。

  10. Unfinalized:重载了 finalize 方法,但是还没有进入 finalize 队列中的对象。

  11. Unreachable:从任何 gc roots 节点都不可达的对象,在 MAT 中将这些对象视为 root 节点,如果不这么做,就不能对这些对象进行分析。

  12. Java Stack Frame:Java 栈帧,用于存放局部变量。只在 dump 文件被解析的时候会将 java stack frame 视为对象。

  13. Unknown:没有 root 类型的对象。有些 dump 文件(例如 IBM 的 Portable Heap Dump)没有 root 信息。


本文地址:http://www.6aiq.com/article/1571404213343
知乎专栏 点击关注
本文版权归作者和AIQ共有,欢迎转载,但未经作者同意必须保留此段声明,且在文章页面明显位置给出