前言

事件的起因源自一次客户现场的调试,调试到一半,客户说办公系统突然登录不进去了Σ(っ °Д °;)っ,当时因为手头上的事还没有搞定,就顺手把客户的tomcat重启了,然后似乎就一切正常,我也没有太放在心上。然鹅,事情并没有这么简单。

麻烦接踵而至

之后的几周里,几乎每隔两周服务就会异常一次,时间非常稳定,问题的表现也很简单,就是登录之后无法完成跳转,一直表现为加载中的状态,直到访问超时。处理方式也很简单粗暴,只要重启tomcat就好了( ̄﹏ ̄;),其实第一次的时候如果深究一下原因或许就能很快定位了,然而,现在就很麻烦了,因为客户的系统是内部系统,不与互联网连接,每次又急着用不能保留“死亡现场”,就只能通过日志进行判定。

那就看日志吧

问题是!catalina.out日志里面没有任何登录相关的异常~(╯‵□′)╯︵┻━┻,出现的异常内容也和登录的问题无关。这就说明,至少与登录代码本身是没有什么关系的,那么原因是什么呢?我们做一下简单的分析:

  • 硬盘空间满:这个是个很坑的问题,在运行中好像也不会产生什么明显的症状,但是一旦硬盘满了,日志无法正常写入,IO就会被阻塞了,然后整个tomcat就不好了,应用的运行自然会受到影响。
  • 请求处理异常:就是在浏览器提交请求后,服务端抛出了异常导致请求没有正常被返回。
  • 数据库服务异常:这个其实和上一点差不多,不过主要问题出在服务器上,上一点造成异常的原因会很多,当然,对于大部分问题来说可能都是NullPointerException(手动滑稽)。

在排除了第一点和第二点之后,问题就主要集中在第三点上,但是数据库本身是正常的,那肯定就是数据库连接出现了问题,问题应该就在c3p0连接池上了。连接池连接数被耗尽,导致登陆时无法正常获取数据库连接,进而无法正常响应请求。

寻找证据

首先自然是寻找catalina.out日志啦,在里面确实发现了蛛丝马迹,虽然不是登录代码中抛出的数据库无法获取连接的异常,但是确实同一时间段内其他业务类里面抛出的问题。其次,我又手动添加了线程日志的获取以便进一步的取证,创建getlog.sh:

#!/bin/bash
pid=`ps aux | grep java | grep -v grep | awk '{print $1}'`
jstack $pid >> logs/thread_log.`date +%Y%m%d`

在crontab中添加定时任务:

crontab -e

*/5 * * * * SCRIPTPATH/getlog.sh

根据后续的日志分析来说,确实是在获取数据库连接那里阻塞了。(原谅我没有截图,弄不出来╮(╯▽╰)╭)

处理和原因

处理方式很简单,修改一下c3p0连接池的参数就好了

<!-- 超过时间限制是否回收 -->
<property name="removeAbandoned" value="true">
<!-- 超时时限 -->
<property name="removeAbandonedTimeout" value="60">

只修改了这个就ok了,因为原来连接数分配的是相对充足的,只是连接一直没有得到正确的释放。这就要继续追问了,为啥没有正确释放呢?


一般情况下,使用sessionFactory.openSession()的话,会因为session过多且没有关闭导致连接数溢出,但是我的代码里使用的是sessionFactory.getCurrentSession(),session不会被多次创建。

最后发现是后来添加的定时任务报错了,最开始c3p0连接池设置的超时回收时间长达3小时!你没有看错,3小时!然后这个定时任务就把连接数逐渐蚕食掉了,而且很稳定的2周挂一次。

总之,这是一个悲伤的故事,请大家引以为戒,如果能够给大家带来帮助,那就是最好的了。

完结,撒花,★,°:.☆( ̄▽ ̄)/$:.°★