Spring task定时任务执行一段时间后莫名其妙停止的问题

前因:

我写了一个小项目,主要功能是用Spring task定时任务每天定时给用户发送邮件。执行了几个月一直没有问题,前几天,莫名其妙的突然不再发送邮件了。

只好花费一些时间来查看到底是什么原因造成的。

定时任务的作业内容:

step1: http请求方式调用远程的一个WebService接口,来获取数据,一个任务中需要调用n(n>1)次远程接口。

step2: 解析获取的数据,生成数据表和曲线图。

step3: 将数据表和曲线图,以邮件的形式发送给用户。

问题出现:

在步骤1中,需要调用10(假定值)次webservice接口,在日志中可以看到执行了3(假定值)次后,突然不在往下执行了。此时的服务已经执行了好几个月了。

问题分析:

因为步骤1中的代码,全部放在了try{}catch(){}代码快中,如果有异常被捕获,肯定会被记录到日志当中。

所以这个异常不是我本地的代码造成的,如果是我本地的代码,异常肯定会被抛出,并且被记录下来。

如果不是我本地的代码出错,那基本可以确定异常是在http请求远程接口的时候出现的,而且这个异常可能造成了任务线程的阻塞或者死亡。

顺着这个思路,网搜了一下可能或造成http请求中断的可能原因。找到了两篇比较有价值的文章。

Http请求偶尔超时+总结各种超时死掉的可能和相应的解决办法

线程中抛出未捕捉的异常会如何? [修正版]

最终锁定了两个可能的原因:

1. 和远程服务间创建的keep alive的connection过多,导致后面创建的连接会一直连接超时,导致线程出现异常。

2. http请求出现某种错误时,http请求僵死,导致线程也不再往下执行。最终导致后面的定时任务也不再执行。

  之前一直认为http会有一个默认的超时时间(可能是5min),超过这个时间后会报超时异常。这个看法误导了我。

先check是不是第一个原因,逐行的检查http请求部分的代码,发现所有的connection都是即时的关闭的。所以第一个原因排除了。

那么就剩第二个原因了。做个试验来验证是不是果真如此呢。

测试1:

1. 设置每2min执行一个定时任务(为了缩短测试时间,减少了需要请求的次数,设置只请求2次),启动服务。

2. 程序运行,我去吃了个午饭,回来时程序运行了近半小时,邮件一直正常发出,没有出现异常。

3. 在又一次请求远程接口的时候,我拔掉了网线。见证奇迹的时候到了,线程不再继续执行了。而且没有错误日志。

4. 过了30秒,插上网线,恢复网络。线程还是没有继续执行。

5. 过了2min,该是下一次定时任务执行的时候了,线程还是没有继续执行。

6. 过了30min,如果有默认的超时时间,也该抛出time out的异常了吧。结果没有。程序还是停留在第一次断网的那个时候。这个时候我已经开始写这篇日志了。

原因找到了。因为网络的不稳定,可能是暂时性的断网,导致了http请求僵死,最终导致整个线程不再执行。

那么怎么解决呢?如果给http请求设置一个默认的超时时间,能不能解决问题呢?

测试2:

1. 在http请求的代码中设置超时时间,连接超时时间设置为30s,读取数据超时时间设置为3min。

        // 设置连接主机超时(30s)
connection.setConnectTimeout(30 * 1000); // 设置从主机读取数据超时(3min)
connection.setReadTimeout(180 * 1000);

2. 仍然是2min执行一次定时任务,启动服务。

3. 第一次定时任务执行成功,开始执行第二次定时任务,在http发送后还未返回的时候(一次查询耗时10-20s),果断又拔掉网线。线程又中断了。30s后连上网线。

4. 2min后该下一个定时任务执行了,线程还是没有继续执行。

5. 大约3min的时候,报了一个异常出来(好长没全拷贝出来)。报出异常后程序又继续向下执行了。

java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:152)
at java.net.SocketInputStream.read(SocketInputStream.java:122)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:275)

不同时间断网,还报了下面3种异常:

java.io.IOException: missing CR
at sun.net.www.http.ChunkedInputStream.processRaw(ChunkedInputStream.java:405)
at sun.net.www.http.ChunkedInputStream.readAheadBlocking(ChunkedInputStream.java:572)
at sun.net.www.http.ChunkedInputStream.readAhead(ChunkedInputStream.java:609)
at sun.net.www.http.ChunkedInputStream.read(ChunkedInputStream.java:696)
at java.io.FilterInputStream.read(FilterInputStream.java:133)
java.net.UnknownHostException: ceshi11.test.com
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:178)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:172)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
at java.net.Socket.connect(Socket.java:579)
at java.net.Socket.connect(Socket.java:528)
java.net.NoRouteToHostException: No route to host: connect
at java.net.DualStackPlainSocketImpl.connect0(Native Method)
at java.net.DualStackPlainSocketImpl.socketConnect(DualStackPlainSocketImpl.java:79)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)

6. 大约10min后,在来看看日志。发现,定时任务又开始每2min执行一次。但是因为报错超时导致中间的错过的2个定时任务,却是没有再被执行。

至此,问题应该就可以被解决了。就是在http请求时设置一下超时时间即可。

上一篇:4-log4j2之切分日志文件


下一篇:Linux