上周末,客服突然在群里说整个系统不可用了,当时看到这个消息,心里慌的一批。找到运维,通过jmap 命令导出当前的dump文件,并且通过jstack 导出当前的堆栈信息,然后就是艰辛的数据分析与代码跟踪路径了。下面是我的心路历程以及思路。
拿到对应的线程的堆栈信息,发现所有的tomcat 线程都是阻塞在德鲁伊的takeLast上面。
"http-nio-8080-exec-3" #31 daemon prio=5 os_prio=0 tid=0x000000001bc92000 nid=0x57b4 waiting on condition [0x000000001d839000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000082800cc0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at com.alibaba.druid.pool.DruidDataSource.takeLast(DruidDataSource.java:2094)
at com.alibaba.druid.pool.DruidDataSource.getConnectionInternal(DruidDataSource.java:1620)
at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:1395)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1375)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1365)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:109)
at org.springframework.jdbc.datasource.lookup.AbstractRoutingDataSource.getConnection(AbstractRoutingDataSource.java:164)
at com.github.pagehelper.page.PageAutoDialect.getUrl(PageAutoDialect.java:173)
at com.github.pagehelper.page.PageAutoDialect.getDialect(PageAutoDialect.java:199)
at com.github.pagehelper.page.PageAutoDialect.initDelegateDialect(PageAutoDialect.java:97)
at com.github.pagehelper.PageHelper.skip(PageHelper.java:65)
at com.github.pagehelper.PageInterceptor.intercept(PageInterceptor.java:92)
at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61)
看到这个第一个猜想是用户数增多,有很多慢查询导致连接不能释放,紧接着询问运维这个时常是多久,根据性能监控工具显示,在30分种内,线程数,请求书均没有任何波动,然后发现有的请求是一直hang住的。这就很显然不是连接池不释放,这是整个系统都停滞了。包括已经拥有的连接的线程也是无法继续执行下去了。看到这就很慌了。这时候该怎么办呢?当我头大的时候,我只能按照惯例去分析,首先线程都在等待数据库连接,那持有数据库连接的哪些个线程有在干嘛?有了这个思路,于是通过jprofile 分析dump文件.(我之前都用的mat,但是对于超过2g的dump文件,根本就分析不出来)。发现持有锁的线程也是在等待连接(如图2)。
那么问题来了。正常情况他已经持有一个连接,为什么不会复用他之前的连接呢。看了半天并没有任何头绪,最后只能想办法在本地复现,本地复现方法很简单,将maxActive连接池改为一个很小的数,如果出现整个系统都在等待的情况下,就是复现了。通过改为5,启动本地服务,立即就复现了。于是通过本地断点的方式,在方法A(事务) -> 方法B(事务)。在spring事务管理是使用了镶嵌事务,但是在myabtis获取连接的时候(SpringManagedTransaction#openConnection)。竟然获取不到对应的connectionHolder对象。当时我就尴尬了。于是通过对比配置文件,发现我们使用了AbstractRoutingDataSource,spring 事务和sessionFactory 配置的数据源竟然不是一个,顿时就炸了。。这基本事务回滚都会有问题。。问题找到了。但是这个错误导致的损失是无法挽回的。好在排查出了问题。找上运维,发个紧急修复邮件。罪恶的代码分析从下次生产故障开始。