CloseableHttpClient没设置超时时间引发的血案

项目背景

一个Java语言写的任务系统,使用固定线程大小的线程池处理长时间任务,任务具体业务逻辑为周期性调用一个外部http接口。调用外部接口使用的是CloseableHttpClient

问题现象

某一天任务调用的外部http接口切换到新域名下,连续好几天发现线程池有偶现的任务线程不打印业务日志了(就像任务线程好像异常退出了一样),但是查询数据库,对应的任务状态并没有结束。线程池提交任务执行代码如下:

Future future = executorService.submit(() -> {
    try {
        //执行任务
    } catch (InterruptedException e) {
        //更新任务状态1
    } catch (Exception e) {
        //更新任务状态2
    } finally {
        //提交数据库
    }
});

原因分析

1、如果是任务执行代码有异常,应该会走到finally更新数据库任务记录状态。数据库任务记录没有更新,说明线程任务还在执行(确定finally中的提交数据库代码没有异常)。

2、既然线程还在执行,对应任务却没有输出业务日志,就需要思考是不是线程阻塞了。

3、通过jstack -l ${pid} 查询jvm线程信息,并没有发现有线程存在共用对象互锁的情况。根据任务代码定位到某个异常任务对应的线程,发现状态是RUNNABLE,但是堆栈调用显示在这个方法上

"pool-2-thread-209" #476 prio=5 os_prio=0 cpu=5035.61ms elapsed=356247.91s tid=0x00007fcb90031000 nid=0x129c runnable  [0x00007fcb199de000]
   java.lang.Thread.State: RUNNABLE
	at java.net.SocketInputStream.socketRead0(java.base@11.0.2/Native Method)
	at java.net.SocketInputStream.socketRead(java.base@11.0.2/SocketInputStream.java:115)
	at java.net.SocketInputStream.read(java.base@11.0.2/SocketInputStream.java:168)
	at java.net.SocketInputStream.read(java.base@11.0.2/SocketInputStream.java:140)
	at sun.security.ssl.SSLSocketInputRecord.read(java.base@11.0.2/SSLSocketInputRecord.java:448)
	at sun.security.ssl.SSLSocketInputRecord.decodeInputRecord(java.base@11.0.2/SSLSocketInputRecord.java:237)
	at sun.security.ssl.SSLSocketInputRecord.decode(java.base@11.0.2/SSLSocketInputRecord.java:190)
	at sun.security.ssl.SSLTransport.decode(java.base@11.0.2/SSLTransport.java:108)
	at sun.security.ssl.SSLSocketImpl.decode(java.base@11.0.2/SSLSocketImpl.java:1152)
	at sun.security.ssl.SSLSocketImpl.readHandshakeRecord(java.base@11.0.2/SSLSocketImpl.java:1063)
	at sun.security.ssl.SSLSocketImpl.startHandshake(java.base@11.0.2/SSLSocketImpl.java:402)
	- locked <0x000000070a6b62d8> (a sun.security.ssl.TransportContext)
	at org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:436)
	at org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:384)
	at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)
	at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)
	at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)
	at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)
	at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
	at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
	at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
	at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)

推测这个方法at java.net.SocketInputStream.socketRead0(java.base@11.0.2/Native Method) 一致阻塞?

4、查询*,发现有网友提到openjdk 8的版本,概率性存在socketRead0一直阻塞的情况,但是后续版本修复了这个问题。当前线上环境用的是openjdk 11,所以排除这个可能。

5、那为什么socketRead0会一直阻塞呢,是不是没有设置超时时间?阅读JDK文档,发现如果没设置socket超时时间(默认为0),socketRead0会一直阻塞,直到读到数据。

6、当前项目工程调用第三方http接口,使用的CloseableHttpClient发现没有设置超时时间

setSocketTimeout、setConnectTimeout,而这个时间会在底层socket连接和读socket缓冲区内容时会用到,默认为0,表示一直阻塞直到读取到内容。

先这样处理,紧急上线,看看后续效果

上一篇:Java:常用pom依赖集合


下一篇:谱半径 ≤ 任何矩阵范数