前因:
我写了一个小项目,主要功能是用Spring task定时任务每天定时给用户发送邮件。执行了几个月一直没有问题,前几天,莫名其妙的突然不再发送邮件了。
只好花费一些时间来查看到底是什么原因造成的。
定时任务的作业内容:
step1: http请求方式调用远程的一个WebService接口,来获取数据,一个任务中需要调用n(n>1)次远程接口。
step2: 解析获取的数据,生成数据表和曲线图。
step3: 将数据表和曲线图,以邮件的形式发送给用户。
问题出现:
在步骤1中,需要调用10(假定值)次webservice接口,在日志中可以看到执行了3(假定值)次后,突然不在往下执行了。此时的服务已经执行了好几个月了。
问题分析:
因为步骤1中的代码,全部放在了try{}catch(){}代码快中,如果有异常被捕获,肯定会被记录到日志当中。
所以这个异常不是我本地的代码造成的,如果是我本地的代码,异常肯定会被抛出,并且被记录下来。
如果不是我本地的代码出错,那基本可以确定异常是在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请求时设置一下超时时间即可。