背景:本地有一台windows7系统的台式机,每天定时向服务器上传文件,后台是个http接口(为什么不用ftp呢,因为这个接口原来是一个html页面用form表单来实现的文件上传,改成ftp就需要改后台处理逻辑)。
问题:由于上传文件很大,最大有20MB,并且同一时刻可能有多个任务并发上传。由于挂了内网vpn网速只有600KB,网速很慢。在并发上传的时候偶尔会出现http请求挂起,代码里面已经设置了连接超时setConnectTimeout(5000)和读超时setReadTimeout(5000),挂起的http请求超过了1天都还没有结束,按理说设置了超时时间,超时应该抛出异常,超时抛出异常才能执行重试机制,但是代码既不抛出异常,也不往下执行阻塞在那里,这就导致重试机制没用了。
通过cmd命令查询,当前有哪些java进程
wmic process where caption="java.exe" get processid,caption,commandline /value
结果如下,发现有个进程id为11428的进程超过1天都未结束。
C:\Users\stu>wmic process where caption="java.exe" get processid,caption,commandline /value
Caption=java.exe
CommandLine="java" -jar "xxl-job-executor-2.1.2.jar"
ProcessId=11428
通过日志查询程序的线程名
1、先从日志中找到了执行的线程 "2023-03-31 05:17:06.277 logback [main] INFO com.xx.transfer.TransferService - 上传开始"
可以看出线程名为[main]
2、使用jstack命令查看线程堆栈
执行命令:jstack 11428
11428为java的进程号,找到线程名 "main" #1 prio=5 os_prio=0
"main" #1 prio=5 os_prio=0 tid=0x00000000003eb800 nid=0x3a4c runnable [0x00000000025dd000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111)
at java.net.SocketOutputStream.write(SocketOutputStream.java:155)
at java.io.BufferedOutputStream.write(BufferedOutputStream.java:122)
- locked <0x00000006c33c92a8> (a java.io.BufferedOutputStream)
at java.io.PrintStream.write(PrintStream.java:480)
- locked <0x00000006c33c9288> (a java.io.PrintStream)
at java.io.ByteArrayOutputStream.writeTo(ByteArrayOutputStream.java:167)
- locked <0x000000076d0800a0> (a sun.net.www.http.PosterOutputStream)
at sun.net.www.http.HttpClient.writeRequests(HttpClient.java:647)
at sun.net.www.http.HttpClient.writeRequests(HttpClient.java:655)
at sun.net.www.protocol.http.HttpURLConnection.writeRequests(HttpURLConnection.java:699)
at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1605)
- locked <0x000000076d080110> (a sun.net.www.protocol.http.HttpURLConnection)
at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1512)
- locked <0x000000076d080110> (a sun.net.www.protocol.http.HttpURLConnection)
at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
at com.xx.transfer.TransferService.sendUpload(TransferService.java:337)
at com.xx.transfer.TransferService.upload(TransferService.java:274)
at com.xx.transfer.TransferService.upload(TransferService.java:240)
根据这个堆栈最后定位到源码socket的socketWrite0方法挂起了。
再往后看是HttpURLConnection.getResponseCode这行代码挂起导致的(这点有点误导,实际上就是socket的write方法阻塞挂起了,后面会验证)。
假如确实是HttpURLConnection.getResponseCode这行代码挂起导致的,但是我已经设置了超时时间,超时并未抛出异常,阻塞了1天都没有退出。
con.setConnectTimeout(5000);//连接超时
con.setReadTimeout(5000);//输入流read超时
上传使用HttpURLConnection来实现的。
/**
* http上传
*/
private static String sendUpload(String url, Map<String, String> heads, byte[] body) {
HttpURLConnection con = null;
OutputStream os = null;
InputStream is = null;
try {
con = (HttpURLConnection) new URL(url).openConnection();
con.setRequestMethod("POST");
con.setDoOutput(true);
con.setDoInput(true);
con.setUseCaches(false);
con.setConnectTimeout(5000);//连接超时,单位毫秒
con.setReadTimeout(5000);//读超时,单位毫秒
// 请求头
// heads.put("Content-Type", "multipart/form-data; boundary=" + boundary);
for (Map.Entry<String, String> entry : heads.entrySet()) {
con.setRequestProperty(entry.getKey(), entry.getValue());
}
// 请求参数
if (body != null && body.length > 0) {
os = con.getOutputStream();
os.write(body);
os.flush();
}
// 响应
logger.info("响应码:" + con.getResponseCode());
if (con.getResponseCode() == 200) {
is = con.getInputStream();
ByteArrayOutputStream baos = new ByteArrayOutputStream();
byte[] buf = new byte[1024];
int len;
while ((len = is.read(buf)) != -1) {
baos.write(buf, 0, len);
baos.flush();
}
return baos.toString(StandardCharsets.UTF_8.name());
}
} catch (Exception e) {
logger.error(e.getMessage(), e);
} finally {
try {
if (os != null) {
os.close();
}
if (is != null) {
is.close();
}
if (con != null) {
con.disconnect();
}
} catch (IOException e) {
logger.error(e.getMessage(), e);
}
}
return null;
}
由于HttpURLConnection实现文件上传,有些参数设置不了,所以使用socket模拟http报文来实现文件上传。
采用socket模拟http请求,看会不会出现这个问题
https://blog.csdn.net/u014644574/article/details/129882740
结果第二天还是出现了,有几个http文件上传请求hang住了,既不抛异常,也不继续往下执行。
搜到了这篇文章 HttpURLConnection里setReadTimeout超时无效 - 白菜不是菜
文章说 setReadTimeout 此方法的某些非标准实现会忽略指定的超时
Some non-standard implementation of this method ignores the specified timeout. To see the read timeout set, please call getReadTimeout().
临时解决办法
给出的解决办法,使用 Future 来守护线程,超时退出,这个办法有个问题,被阻塞的子线程不会退出的,还是会一直阻塞。
所以需要改造一下,让上传方法独立打包成一个jar包成为一个独立进程,调用jar包执行上传操作,超时后直接杀掉进程,这样就避免子线程阻塞。
@SpringBootApplication
public class UploadApplication {
private static Logger logger = LoggerFactory.getLogger(UploadApplication.class);
public static void main(String[] args) {
String param1= args[0]; //参数1,比如要上传的文件路径
String param2= args[1]; //参数2
final ExecutorService threadPool = Executors.newFixedThreadPool(1);
Callable<String> call = new Callable<String>() {
public String call() throws Exception {
// 调用上传方法,sendUpload这个方法就是具体实现上传的操作
String upload = sendUpload(param1, param2);
return upload;
}
};
Future<String> future = null;
try {
future = threadPool.submit(call);
String obj = future.get(30, TimeUnit.SECONDS); //任务处理超时时间设为 30 秒
logger.info("任务成功返回:" + obj);
// 这里根据实际业务,上传成功,使用System.exit(0)退出程序
if (obj != null) {
//按照惯例,非零状态码表示异常终止。
System.exit(0);//正常终止当前运行的Java虚拟机
}
} catch (TimeoutException e) {
logger.info("处理超时", e);
future.cancel(true);
} catch (Exception e) {
logger.error("处理异常", e);
} finally {
// 关闭线程池
threadPool.shutdown();
}
//按照惯例,非零状态码表示异常终止。
System.exit(1);//异常终止当前运行的Java虚拟机
}
}
这里使用System.exit()方法退出进程,防止上传方法阻塞。
上传成功,使用 System.exit(0) 退出进程。
上传失败,使用 System.exit(1) 退出进程。
封装公共上传方法,以后上传就调用该方法。
/**
* 上传文件
* @param param1 参数1,比如要上传的文件路径
* @param param2 参数2
* @date 2022/9/8 16:37
*/
public static boolean uploadByJar(String param1, String param2) {
try {
// 处理参数,参数中有空格或者引号
param1 = "\"" + param1.replace("\"", "\\\"") + "\"";
param2 = "\"" + param2.replace("\"", "\\\"") + "\"";
String jarPath = "D:/jar/upload.jar";//jar包路径
String command = "java -jar " + jarPath + " " + param1 + " " + param2;
// 失败重试10次
for (int i = 0; i < 10; i++) {
Process exec = Runtime.getRuntime().exec(command);
printMessage(exec.getInputStream());//打印日志
printMessage(exec.getErrorStream());//打印日志
int exit = exec.waitFor();//等待外部命令执行完毕,然后返回执行的结果
exec.destroy();
//按照上面的约定,非零状态码表示异常终止。
if (exit == 0) {//System.exit(0) 退出进程返回就是0
logger.info("上传进程正常完成");
return true;
} else {
logger.info("第{}次,上传进程异常结束", i + 1);
}
}
} catch (Exception e) {
logger.error("上传执行异常", e);
}
throw new RuntimeException("上传失败最大次数:" + param1);
}
/**
* 打印日志
*/
private static void printMessage(InputStream is) {
new Thread(() -> {
BufferedReader br = null;
try {
br = new BufferedReader(new InputStreamReader(is, "GBK"));
String line;
while ((line = br.readLine()) != null) {
System.out.println(line);
}
} catch (Exception e) {
logger.error(e.getMessage(), e);
} finally {
if (br != null) {
try {
br.close();
} catch (IOException e) {
e.printStackTrace();
}
}
}
}).start();
}
使用临时解决办法,虽然解决了问题,但是还是要深究下是什么原因导致的,该怎么解决。
当第二天发现有任务挂起后,先不要关闭,使用 Wireshark 抓包。
由于挂了内网vpn,导致没抓到包,需要勾选下面的选项。
抓包发现每隔1分钟都会收到后端服务发送的 TCP ZeroWindow
TCP ZeroWindow 表示接收端窗口满了,接收方发送信号告诉发送方不要发送数据了,直到接收方窗口不再为0。
TCP window Full 表示接收端窗口满了,发送方发送信号告诉接收方不再发送数据了,直到接收方窗口不再为0。
TCP ZeroWindowProbe:接收方滑动窗口降为0后,发送方会停止发送数据,但此时如果发送有数据待发送,发送方发送TCP ZeroWindowProbe包,主动获取接收方滑动窗口的最新值。
TCP Window Update:接收方滑动窗口降为0后,发送方停止发送数据,如果接收方滑动窗口出现空闲空间,则接收方主动发送TCP Window Update来更新发送方的滑动窗口。
这里需要再去详细了解tcp的3次握手4次挥手及数据传输过程。
确认应答机制是 实现TCP可靠性的关键机制,简单来说,确认应答机制就是,客户端和服务端任意一方,在发送消息之后,都必须要收到对方的回复来表明自己发送的消息已经被对方收到。
分析到这里,虽然知道了是因为零窗口导致的,但是解决问题的过程也很漫长,包括使用了chatgpt一样没能给出正确答案。
由于出现问题的是一台windows7系统的台式机,所以我换成我笔记本windows11系统测试发现,同样挂的内网vpn,网速也是600KB,但是没有出现http文件上传挂起的现象。
所以猜想由于是不同版本的windows系统是不是tcp默认参数问题,对比下两台电脑的tcp默认参数,发现果然不一样。
netsh int tcp show global
通过对比发现,确实有很多默认参数不一致,经过一个一个对比修改测试,定位到具体原因:由于网络延迟,windows7系统默认的拥塞控制算法没能正常工作。
Windows 7 中仅支持以下几种拥塞控制算法:
默认:使用标准 TCP 拥塞控制算法。
CTCP:使用 Compound TCP 算法,它能够在高延迟和高带宽网络上提供更好的性能。
CUBIC:使用 CUBIC 拥塞控制算法,它能够更好地应对高带宽网络拥塞情况。
NewReno:使用 NewReno 算法,它在网络拥塞时减少了传输延迟。
以下就是windows7系统默认的tcp全局参数
C:\Users\stu>netsh int tcp show global
查询活动状态...
TCP 全局参数
----------------------------------------------
接收方缩放状态 : enabled
烟囱卸载状态 : automatic
NetDMA 状态 : enabled
直接缓存访问(DCA) : disabled
接收窗口自动调谐级别 : normal
附加拥塞控制提供程序 : none
ECN 功能 : disabled
RFC 1323 时间戳 : disabled
** 上述 autotuninglevel 设置是窗口缩放启发的结果
正在覆盖至少一个配置文件的任何本地/策略配置。
如下修改解决问题:
netsh interface tcp set global congestionprovider=ctcp
netsh int tcp set global timestamps=enabled
修改后再次查询
C:\Users\stu>netsh int tcp show global
查询活动状态...
TCP 全局参数
----------------------------------------------
接收方缩放状态 : enabled
烟囱卸载状态 : automatic
NetDMA 状态 : enabled
直接缓存访问(DCA) : disabled
接收窗口自动调谐级别 : normal
附加拥塞控制提供程序 : ctcp
ECN 功能 : disabled
RFC 1323 时间戳 : enabled
修改tcp的拥塞控制算法以后,测试发现没再出现http文件上传挂起,超时后会正常抛出异常 java.net.SocketTimeoutException: Read timed out
参考:
记录TCP window full和TCP zero window报文排查 | Pandaho