最近在交易高峰期,会偶尔出现跟上游的请求中断问题,一般集中在交易量较大时。上游反馈日志未见异常,所以我们决定进行抓包分析定位一下。
1. 发现问题
假定上游请求地址为:https://ip:8843,http请求双向认证。 目前日志报错为:
javax.net.ssl.SSLHandshakeException: Remote host closed connection during handshake
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:992)
at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1375)
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1403)
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1387)
at org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:396)
at org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:355)
at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:373)
at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:394)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:237)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
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)
通过关键字搜索,在stackoverflow有相关问题,说是可能客户端和服务端的tls版本不一致,jdk8默认tls2.0( 原文 ),但是我检查后发现,这个错误是偶尔发生,不应该是这个原因。
2. 抓包分析
2.1 tcpdump抓包
假定上游请求地址为:https://ip:8843,采用http双向认证。我们抓包命令如下:
tcpdump tcp port 8843 -i eth0 -w ./tcpdump10.13.0.17.cap
抓取所有经过eth0,目的或源端口是8843的网络数据,并写入到cap文件中。
2.2 wireshark分析
下载安装相应版本的wireshark软件,打开后加载抓包的cap文件,
首先我们来把时间格式化一下,
然后,我们对应着异常日志,定位到大概的请求。异常的tcp请求,会以红色的背景标注出来,比较好识别。
定位到异常请求后,右击日常记录,选择”Follow --> TCP Stream“,
本次请求的完整通信链路就自动汇集在一起了,方便我们分析排查。
2.3 分析问题
我们通过抓包分析看到,本次请求握手过程中,两块黑底红字的部分,是客户端重发数据给服务端的记录,整个握手时间,整整持续了60秒.
15686 2020-12-04 12:02:05.365118 10.13.0.17 x.x.x.180 TLSv1 91 Encrypted Alert
在这个时间段,本地客户端主动给服务端发起了中断指令,这个又是因为什么呢?原来,客户端配置的请求超时时间是60s。所以在这里,60s之内没有和服务器成功建立连接,客户端就主动断开了。