零、背景
我的一个java应用代码,部署到了多个域名。在某个域名(访问量较小)下,上传文件的操作忽然失败了,其它域名(访问量较大)则正常。而后台nginx、应用server均没有错误日志,前端却直接被302跳转。
现象诡异, 记录解决的过程如下:
一、收到用户反馈
用户反馈工单,新加坡的线上环境,导入实验失败。
二、问题重现
我们去新加坡的线上环境,发现上传文件失败,而其它操作创建模板、查看状态等均正常。
同样的操作,在访问量较大的域名下,验证正常。
同样的操作,在新加坡的预发环境(新部署的一台机器)也正常。
即:这个问题可以在访问量小的域名可以重现,而访问量大的、新的域名下,均无法重现。
三、排查
3.1、前端排查
在新加坡线上环境,上传实验文件, 打开浏览器控制台,的确看到请求被302跳转了。
用同一套代码,重新部署一台服务,却运行正常。
查看后端代码,可以跳转的情况只有一个:前端请求参数中没有项目id,会跳走。代码示意如下:
String projectId = request.getParameter("projectId");
if (StringUtils.isBlank(projectId)) {
redirect(request, response);
return;
}所以请求前端同学支援,但是前端同学很客气的证明了,这个参数已经传给了后端。
问题陷入僵局,前端说传了,而后端却没有拿到。
后端的filter里,这里没有加日志,暂时无法自证是否真的没拿到,还是代码问题。
根据以往经验,感觉还是参数问题。所以我进一步用postman验证,然而现实很骨感,同样的参数、cookie、header,在新部署的环境正常,在线上的访问量较小是则出现跳转。如下:

3.2、排查后端
难道后端filter真的有问题?因为这是一个刚上线的低频功能,还没有推广,为了保护现场,我们没有重启线上服务。
幸好有线上排查神器Arthas (https://alibaba.github.io/arthas/index.html 极力推荐)。即便没有线上日志,它也监控jvm的各种指标。它比btrace方便太多,用交互式控制,监控jvm的各种指标、方法调用堆栈、观察方法的参数、返回、异常等。
我们在一台线上机器安装Arthas后,用watch命令, 监控javax.servlet.ServletRequest的getParameter方法(这需要查看代码、多次watch才能定位到这个方法)。发起多次请求(因为不确定一次前端请求会落到哪台服务器),观察到了这个方法的调用堆栈、参数、异常等。

后端果然没有拿到3.1的项目id参数,但是前端传的值去哪里了呢?毫无头绪的时候,幸运的是,我们也发现了蛛丝马迹,在HttpRequest里有一个partsParseException,如上图。
异常partsParseException是tomcat暂存的POST方法的、ContentType=multipart/form-data类型的上传参数,没有被正确parse导致的。奇怪的是这个异常被tomcat吞了,只在内存中看到,却没有打印到日志。
接下来,我在POST的url上,手动加上这个项目Id参数https://domain/experimentMeta.json?projectId=28901,再次发起请求,终于在日志中看到久违的异常堆栈。

追查这个MuitipartException和partsParseException异常原因,可以看到两块源码,分别是:


至此,我们看出了,因为3.2步骤中的日志里,异常堆栈的临时文件夹/tmp/xxxxx不存在,导致上传文件的功能都受到影响。
但是为什么国内服务、刚启动的预发服务都正常呢,参照 https://askubuntu.com/questions/20783/how-is-the-tmp-directory-cleaned-up 、 https://blog.csdn.net/daniel7443/article/details/51620308 的解释:这个 /tmp 下的临时文件,在国内和预发经常被用到或重置,所以一直没被回收,功能正常;而国际region由于长时间不使用这个功能,被linux回收了。
4、解决方案
查到问题是上传目录被回收的原因后,解决办法也随之而来,只要在spring config中增加配置项:spring.http.mutipart.location, 并指定到一个不会被回收的目录即可。
本文记录了一起因Linux系统回收上传目录导致的Tomcat POST请求异常问题,通过Arthas监控定位到问题在于multipart/form-data参数未正确解析,并在后端排查中发现异常被Tomcat吞没。最终通过设置spring.http.multipart.location配置解决了问题。
64万+

被折叠的 条评论
为什么被折叠?



