线上由于ActiveMQ内存泄露导致FullGC的定位过程-chapter 1

1,805 阅读6分钟

双十一预热压测过程中,陆陆续续发现了些中间件、工程代码中隐藏的坑,引发内存溢出、cpu消耗过高、线程池不可用...... 按顺序一个个总结下,便于日后问题回顾~

一、故事的开始

  叮!叮!叮! 有天突然线上大批量告警,系统超时~
  难道“某某云”又出问题了??因为在昨天刚刚遇到“某某云”服务器上DB大量延时,并且后台监控没有任何异样。也就是这个错误的方向导致了故障持续了许久。
  看应用监控发现是某些交易耗时严重,也怀疑到是某个节点有问题 (因为并不是所有交易都是超时),挨个看了下链路监控全都是到交易主链路的pfs这个系统开始超时,下游系统监控耗时正常,并且只有其中003这台机器有此现象(耗时情况如下pinpoint截图:),当然 第一反应是赶紧找运维把003这台机器的流量切掉,保存环境现场方便定位具体原因。

二、问题定位过程

跳板机登陆到服务器

top 命令,看到有个进程(3043)  cpu82.8%

top -Hp 3043 查看该进程下子线程占用资源情况

  • 其一: 3051这个子线程肯定是关键;
  • 其二: 内存信息,堆内存被耗尽基本不可用 (此时差不多可以猜出来是内存泄露触发了FullGC)

jstat -gcutil 3043 1000 5 可以看到老年代的对象一直回收不掉,并且FullGC次数一直在增加,就基本确认是内存泄露导致的机器FullGC

通过jstack命令也验证了这个结论

  1. 把十进制的线程pid转换为jvm中对应的16进制nid:
    printf "%x\n” 3051 --> 拿到对应nid: beb
  2. 通过jstack 3051 | grep beb 找到对应的线程堆栈信息,看到“VM Thread”这个线程基本上就是JVM在频繁FullGC

jmap -heap 3043 查看jvm中线程运行的情况

线上应用怎么才512内存??(后来才发现之前做网络迁移时候一台老机器配置漏改,也正是这台机器内存分配小,并且当天流量大才触发了线上fullGC,把这个问题暴露了出来)

jmap -dump:live,format=b,file=heap.bin   拿到dump文件分析原因

  • gzip heap.bin 压缩后下载到本地分析下;
  • 分析工具(Jprofiler或者MAT、JConsole),下面是Jprofiler分析截图

  可以看的出来,导出来的存留堆栈信息,大对象都是跟activemq.pool 相关的并且回收不掉的对象,reentrantLock和CopyOnWriteArrayList数量上大概是2:1的关系(看了后面ActiveMQ连接池源码这个关系更清晰)。
  搜索整个工程,找到系统中引用的activemq包中的对应代码PooledConnection源码,其中 "connTempQueues"、"connTempTopics"两个类变量刚好跟Jprofiler中分析的关系一致, activemq内部的PooledConnection对象中是存在2个CopyOnWriteArrayList的类型,大概可以定位到是这里的问题导致内存泄露,具体引发的根源看下面具体分析 (摆弄了一堆源码无获,求救)

apache的论坛上的线索

  • apache的论坛上找到一篇关于ActiveMQ内存泄露的issue
    issues.apache.org/jira/browse…
  • apache.issues上也给了具体的代码优化方案(附源码) issues.apache.org/jira/secure…
  • activemq的5.6.0版本是存在连接池内存泄露的坑,5.7.0解决了 (确认了下我们系统中刚好是引用了5.6.0的版本),看上面的git源码修复逻辑, pooledconnection实现了session事件监听器接口,在放入监听器时直接将自己放入list中,在创建新的连接前先判断是否已存在该事件监听器,不存在才把监听器add进PooledSession.tempDestEventListeners。而5.6.0这个版本中的activemq在发送消息时候链接池无限创建链接,并且最终在PooledSession的close方法中没有做监听器对象的回收。 直观点看官方解决bug的git提交记录:
Index: src/main/java/org/apache/activemq/pool/PooledConnection.java
===================================================================
--- src/main/java/org/apache/activemq/pool/PooledConnection.java	(revision 1378004)
+++ src/main/java/org/apache/activemq/pool/PooledConnection.java	(working copy)
@@ -16,6 +16,7 @@
  */
 package org.apache.activemq.pool;
 
+import java.util.List;
 import java.util.concurrent.CopyOnWriteArrayList;
 
 import javax.jms.Connection;
@@ -54,13 +55,13 @@
  * href="http://jencks.org/Message+Driven+POJOs">this example</a>
  *
  */
-public class PooledConnection implements TopicConnection, QueueConnection, EnhancedConnection {
+public class PooledConnection implements TopicConnection, QueueConnection, EnhancedConnection, PooledSessionEventListener {
     private static final transient Logger LOG = LoggerFactory.getLogger(PooledConnection.class);
 
     private ConnectionPool pool;
-    private boolean stopped;
-    private final CopyOnWriteArrayList<TemporaryQueue> connTempQueues = new CopyOnWriteArrayList<TemporaryQueue>();
-    private final CopyOnWriteArrayList<TemporaryTopic> connTempTopics = new CopyOnWriteArrayList<TemporaryTopic>();
+    private volatile boolean stopped;
+    private final List<TemporaryQueue> connTempQueues = new CopyOnWriteArrayList<TemporaryQueue>();
+    private final List<TemporaryTopic> connTempTopics = new CopyOnWriteArrayList<TemporaryTopic>();
 
     public PooledConnection(ConnectionPool pool) {
         this.pool = pool;
@@ -151,20 +152,17 @@
 
         // Add a temporary destination event listener to the session that notifies us when
         // the session creates temporary destinations.
-        result.addTempDestEventListener(new PooledSessionEventListener() {
+        result.addTempDestEventListener(this);
+        return (Session) result;
+    }
 
-            @Override
-            public void onTemporaryQueueCreate(TemporaryQueue tempQueue) {
-                connTempQueues.add(tempQueue);
-            }
 
-            @Override
-            public void onTemporaryTopicCreate(TemporaryTopic tempTopic) {
-                connTempTopics.add(tempTopic);
-            }
-        });
+    public void onTemporaryQueueCreate(TemporaryQueue tempQueue) {
+        connTempQueues.add(tempQueue);
+    }
 
-        return (Session) result;
+    public void onTemporaryTopicCreate(TemporaryTopic tempTopic) {
+        connTempTopics.add(tempTopic);
     }
 
     // EnhancedCollection API
Index: src/main/java/org/apache/activemq/pool/PooledSession.java
===================================================================
--- src/main/java/org/apache/activemq/pool/PooledSession.java	(revision 1378004)
+++ src/main/java/org/apache/activemq/pool/PooledSession.java	(working copy)
@@ -78,7 +78,10 @@
     }
 
     public void addTempDestEventListener(PooledSessionEventListener listener) {
-        this.tempDestEventListeners.add(listener);
+        // only add if really needed
+        if (!tempDestEventListeners.contains(listener)) {
+            this.tempDestEventListeners.add(listener);
+        }
     }
 
     protected boolean isIgnoreClose() {
@@ -123,6 +126,7 @@
             } finally {
                 consumers.clear();
                 browsers.clear();
+                tempDestEventListeners.clear();
             }
 
             if (invalidate) {
Index: src/main/java/org/apache/activemq/pool/ConnectionPool.java
===================================================================
--- src/main/java/org/apache/activemq/pool/ConnectionPool.java	(revision 1378004)
+++ src/main/java/org/apache/activemq/pool/ConnectionPool.java	(working copy)
@@ -19,10 +19,10 @@
 
 import java.io.IOException;
 import java.util.Iterator;
+import java.util.List;
 import java.util.concurrent.ConcurrentHashMap;
-import java.util.concurrent.ConcurrentLinkedQueue;
+import java.util.concurrent.CopyOnWriteArrayList;
 import java.util.concurrent.atomic.AtomicBoolean;
-
 import javax.jms.JMSException;
 import javax.jms.Session;
 
@@ -39,7 +39,7 @@
 
     private ActiveMQConnection connection;
     private ConcurrentHashMap<SessionKey, SessionPool> cache;
-    private ConcurrentLinkedQueue<PooledSession> loanedSessions = new ConcurrentLinkedQueue<PooledSession>();
+    private List<PooledSession> loanedSessions = new CopyOnWriteArrayList<PooledSession>();
     private AtomicBoolean started = new AtomicBoolean(false);
     private int referenceCount;
     private ObjectPoolFactory poolFactory;

  看了修复的代码大致知道问题的点在哪里了,优先把线上所有引用这个版本ActiveMQ的依赖做了升级,观察后线上没有再重现,并且拉取了线程堆栈文件也都正常,暂时把线程问题处理了,再静下心来学习下埋坑的代码~

三、上源码

  我们来从头看下发消息执行的代码 (前面是我们自己封装的发送消息代码)

首先找到业务代码中发送消息的入口:

mqAccssor中调用了jmstemplate模板的send方法

jmstemplate中使用了模版模式,模版方法execute中封装了创建连接和session的逻辑。

继续看execute方法 (跳坑的路口就在这)

  这里注入了ActiveMQ的一个连接工厂类PooledConnectionFactory先创建连接,再基于连接对象创建session。
  其中创建连接是每次都会新建一个实例。 创建session最终调用了前一步创建的连接实例的createSession方法(如下图:),根据jvm堆dump文件分析,查看源码 使用了匿名类,匿名类中隐式的引用了外部类 this$0,所以tempDesEventListeners对pooledConnection有间接的引用。

分析dump文件,引用也在session的tempDestEventListeners这个list中

activemq的修复在session关闭时添加了连接池的清理,在发送完消息之后会调用close方法,同时会清理连接池,之后gc会清理掉不再被引用的连接。

     protected boolean isIgnoreClose() {
@@ -123,6 +126,7 @@
             } finally {
                 consumers.clear();
                 browsers.clear();
+                tempDestEventListeners.clear();
             }

在5.7.0版本中的createSession方法也做了拆解

  PS: 至于为什么在PooledConnection和ConnectionPool类中把CopyOnWriteArrayList、ConcurrentLinkedQueue类型的成员变量换成了List继续~