问题描述
-
问题 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
。
因为使用 ParallelOld 收集器即使加上参数也无法打印 survivor 区的对象年龄分布,只能显示 desired survivor size。所以启用 CMS 收集器进行压测成功打印了 age 分布信息
登上线上机器查看当前进程里对象占用内存的前 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 关联的引用所占的空间最多。
在 histogram 视图中可以看到占用内存前几高的对象都是和 socket 相关的
查看 dump 内存中的不可达对象中,org.apache.commons.pool.impl.CursorableLinkedList$Listable 对象非常多。
在支配树中查看该对象的引用关系发现 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()。
原因
启动时 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
正常默认 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 连接池的原理,大体原理是:
- 本文地址:由 Finalizer 和 SocksSocketImpl 引起的 Fullgc 问题盘点
- 本文版权归作者和AIQ共有,欢迎转载,但未经作者同意必须保留此段声明,且在文章页面明显位置给出
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 原理
因为 SocksSocketImpl 对象实现了 finalize 方法,JVM 在 Java 对象创建过程中识别出其实现了 finalize 方法,会将其封装成 Finalizer 对象,Finalizer 是一个双向链表,并添加到 Finalizer 链表中,这样有 Finalizer 引用存在,SocksSocketImpl 对象即使已经无用也不会被回收。
Finalizer 的祖父类 Refrence 有一个 ReferenceHandler 线程,来完成将 Finalizer 新添加的对象加入到 RefrenceQueue 中,该线程具体执行时机是在 pending
字段被设置的时候,即会在 GC 线程进行第一次标记的时候,接着 RefrenceQueue 在 enquery 方法中通过 notifyAll
方法唤醒 FinalizerThread
线程执行后续逻辑,FinalizerThread
是在 Finalizer
类的静态代码块中会创建一个 FinalizerThread
类型的守护线程,但是这个线程的优先级比较低,意味着在 CPU 吃紧的时候可能会抢占不到资源执行。实现如下
FinalizerThread
线程干的事情就是执行对象实现的 finalize 方法,然后将 Finalizer 对象从 Finalizer 链表中删除
意味着如果在执行 finalize 方法时,对象没有再次赋给强引用,现在也没有了 Finalizer 引用,那么在下一次 GC 时,便会被真正的回收,即实现 finalize 方法的对象的回收至少需要两次 gc,而 FinalizerThread
执行优先级非常低,
SocksSocketImpl
的父类重写了 finalize
方法,这么做主要是为了确保在用户忘记手动关闭 socket
连接的情况下,在该对象被回收时能够自动关闭 socket
来释放一些资源,但是在开发过程中,真的忘记手动调用了 close
方法,那么这些 socket
对象可能会因为 FinalizeThread
线程迟迟没有执行到这些对象的 finalize
方法,而导致一直占用某些资源,造成内存泄露。
fullgc 耗时较长
线上没有采用 更关注系统响应时间 CMS 收集器,同时有可能标记大量 Finalizer 对象的处理耗时较多,毕竟 Finalizer 对象数量很大。
如果采用 CMS 收集器,那么 CMS FinalMarking(并发重新标记,STW 过程)进行如下的处理:
-
遍历新生代对象,重新标记
-
根据 GC Roots,重新标记
-
遍历老年代的 Dirty Card,重新标记,这里的 Dirty Card 大部分已经在 clean 阶段处理过
在第一步骤中,需要遍历新生代的全部对象,如果新生代的使用率很高,需要遍历处理的对象也很多,这对于这个阶段的总耗时来说,是个灾难(因为可能大量的对象是暂时存活的,而且这些对象也可能引用大量的老年代对象,造成很多应该回收的老年代对象而没有被回收,遍历递归的次数也增加不少)
解决
NettyIO
推动各端的客户端使用 NettyIO
目标
- 解决服务启动过程中会出现几次 fullgc 问题
- 降低频繁创建连接
- 降低 fullgc STW 时间
- 降低高龄成员缓慢晋升导致 fullgc 次数
JVM 参数
- 打印 gc 详细信息及 gc 耗时
- 减少堆内存 减少 gc 耗时
- 打印 survivor 区年龄分布
- 启用 CMS,启动 remark 阶段并行&remark 前 YGC,减少 remark 阶段耗时
- 增大 metaspace,解决服务启动时的 fullgc
- 并行处理 Reference Finalizer 队列 加快 Finalizer 引用对象(好多 socket 相关)的快速回收
- 提升 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。
优化后,CMS 最耗时的 remark 阶段花费 160ms,remark 阶段 STW 总耗时降低到 200ms 以内,降低至优化前 1/3 耗时,且高峰低峰 STW 耗时平稳。
附录
GC ROOTS
-
System Class:由 bootstrap classloader 加载的类,例如 rt.jar,里面的类的包名都是
java.util.*
开头的。 -
JNI Local:native 代码中的局部变量,例如用户编写的 JNI 代码或 JVM 内部代码。
-
JNI Global:native 代码中的全局变量,例如用户编写的 JNI 代码或 JVM 内部代码。
-
Thread Block:被当前活跃的线程锁引用的对象。
-
Thread:正在存活的线程
-
Busy Monitor:调用了 wait()、notify()或 synchronized 关键字修饰的代码——例如
synchronized(object)
或synchronized
方法。 -
Java Local:局部变量。例如函数的输入参数、正在运行的线程栈里创建的对象。
-
Native Stack:native 代码的输入或输出参数,例如用户定义的 JNI 代码或 JVM 的内部代码。在文件/网络 IO 方法或反射方法的参数。
-
Finalizable:在 finalize 队列中等待它的 finalizer 对象运行的对象。
-
Unfinalized:重载了 finalize 方法,但是还没有进入 finalize 队列中的对象。
-
Unreachable:从任何 gc roots 节点都不可达的对象,在 MAT 中将这些对象视为 root 节点,如果不这么做,就不能对这些对象进行分析。
-
Java Stack Frame:Java 栈帧,用于存放局部变量。只在 dump 文件被解析的时候会将 Java stack frame 视为对象。
-
Unknown:没有 root 类型的对象。有些 dump 文件(例如 IBM 的 Portable Heap Dump)没有 root 信息。
注意:本文归作者所有,未经作者允许,不得转载