场景
最近生产上执行日批量一直停留到了某一天,但是却没有收到中断报警,后面客户反馈缺少统计数据才发现该问题。后面查看日志只发现了一个 java.lang.NullPointerException
,然后日志到这里就中断了。刚看到这里到时候很茫然,感觉无从下手。
由于没有收到批量中断报警,所以首先怀疑是进程还在,然后使用ps + grep
查看,发现进程还在。接着我们使用 jstack -l pid
打印出所有线程到堆栈。根据看到的信息,main
线程处于 sleep
状态,批量调度的线程池里面的线程都处于 object.wait
状态。
为了方便理解,我先说一下项目背景,使用的批量框架是一套已经使用了超过10年的程序,它的线程分为主线程和线程池的工作线程,启动的时候主线程会先查询批量调度任务,然后根据是否需要并行或者串行调度给工作线程进行分配任务,这套程序是由自己管理数据库链接,而工作线程通过反射的方式调用起我们的具体对账程序,而对账程序使用了
druid + mybatis
进行数据库操作,和旧的批量框架的链接没有直接关联。
僵死问题分析
根据日志输出的具体打印日志的为止,我们发现了主线程陷入了死循环,具体代码类似下面:
while(true) {
if (ThreadPoolManger.hashActive) {
sleep();
} else {
break;
}
}
// 分配具体任务
assignJob()
而这里的hashActive
方法主要是轮训线程池的每个线程的状态是等待还是处于活动中。每个线程的具体处理如下。
// 分配任务
synchnorized excute (step) {
this.step = step;
this.notifyAll();
}
// 执行任务
synchnorized run() {
while (true) {
this.wait();
try {
doSomething
.....
isRunning = false;
}catch(Exception e) {
log.error(e.getMessage);
}
}
}
首先第一个为什么线程会一直僵死的问题已经找到了,主要就是catch 的时候没有将running的状态设置为 false;这里比较推荐使用 try + finnally
的结构。接着我们来排查空指针问题。
空指针问题排查
在抛出空指针之前我们先根据日志发现这个线程执行的任务已经完成了的,已经走到了最后一步,就是批量框架自己去更新批量步骤的状态,在执行更新的 SQL的时候抛出错误出来,所以我们一进来就开始怀疑是数据库链接有问题,因为在最后执行更新操作使用的是批量框架的链接,而这个链接是批量框架自己管理的。
首先我们执行 netstat -antp
发现该线程已经没有和数据库之间的链接了,这个证实我们的猜想是正确的,同时我们注意到一个情况,就是这个批量由于当天数据量非常大,后面大概跑了超过了 8 个小时,也就是在批量框架调起批量到批量结束,去更新批量状态这个之间隔了 8 个小时。然后我们查了数据库的 wait_timeout
也就是mysql 链接的最大空闲等待时长是 28800 也就是 8个小时。由于具体批量程序和批量框架没有混用数据库链接池,也就是这段时间,批量框架的链接一直是空闲的,所以我们就定位到了应该是由于批量链接超时导致的 NullPointerException
。
紧接着我们在测试环境上将 wait_timeout
改小后也重现了该问题。具体报错类似如下:
java.lang.SqlException : java.lang. NullPointerException
.....
大概的意思是在执行SQL的时候现调用connect去创建一个 statement, 然后抛出错误。知道了这个问题后,我们很好奇,批量框架对于这种空闲的链接应该有一套连的机制的,为什么会有这种问题呢?于是我们就进行了考古(毕竟是10年前的代码了),找到了具体保持链接的代码如下:
connection getConnetion() {
if (pool.size > 0) {
cnn = pool.getFirst;
pool.remove(cnn);
if (cnn.isClosed()) {
getConnection();
} else {
return cnn;
}
} else {
return newConnection();
}
}
我们来分析一下这段代码,这里使用了一个递归调用,(我理解假如使用for循环遍历的话会有 ConcurrentModifyException
的问题,所以选择了递归调用),最后假如所有的链接都是 closed
的话,就会创建一个新的线程。第一眼看过去好像没啥问题,理论上也不会出现上面的那个空指针。其实问题就是出现在这个 isClosed
方法。我查看了 java 的关于 Connect 的源码,解释如下:
Retrieves whether this <code>Connection</code> object has been
closed. A connection is closed if the method <code>close</code>
has been called on it or if certain fatal errors have occurred.
This method is guaranteed to return <code>true</code> only when
it is called after the method <code>Connection.close</code> has
been called.
<P>
This method generally cannot be called to determine whether a
connection to a database is valid or invalid. A typical client
can determine that a connection is invalid by catching any
exceptions that might be thrown when an operation is attempted.
@return <code>true</code> if this <code>Connection</code> object
is closed; <code>false</code> if it is still open
@exception SQLException if a database access error occurs
它的大概意思是这个方法只有在 connect被调用了 closed 方法,或者在执行中发生了 fatal 错误的时候才会返回 true,这个方法通常不能用来决定这个链接是否在数据库端是否可用。这里划重点,也就是我们所说的Mysql 链接被回收调用 isClosed
方法是无法检查出来的,我们可以看一下类似于 druid 这种专门的连接池都是可以配置空闲链接心跳的,类似于 Netty 的 idelStatHandler
, 也就是当数据库链接一直在使用的时候是不会发送心跳的,只有当空闲时间超过一定时长后会发送心跳,这里推演到数据库就是执行一下 select 1;
就可以了。
总结
- 对于之后资源释放的程序必须要使用
try + finnaly
的结构,假如使用了这种结构起码可以在客户发现问题之前及时发现该问题。 - 对于数据库链接这种操作最好还是使用类似于
druid
这种优秀的第三方开源框架,当然,假如你是大神,对于整个JDBC 的程序理解都很透彻的话当我没说,哈哈哈哈。