频繁IO导致---java.io.IOException: 设备上没有空间

2021-5-7下午,优付(SSM框架的老项目)商户站点无法访问,页面报500。

运维紧急重启tomcat并删了一些临时文件,故障暂时得到解决。

造成此故障的原因有二:一是IO操作过于频繁,二是磁盘空间不足。

如下是log文件记录的异常:

2021-05-07 17:51:38.276 [ERROR] [http-bio-8180-exec-1] [com.yft.controller.SettleController:2236] ====MERCHANT==结算凭证下载,执行异常
java.io.IOException: 设备上没有空间
    at java.io.FileOutputStream.writeBytes(Native Method)
    at java.io.FileOutputStream.write(FileOutputStream.java:326)
    at java.util.zip.DeflaterOutputStream.deflate(DeflaterOutputStream.java:253)
    at java.util.zip.DeflaterOutputStream.write(DeflaterOutputStream.java:211)
    at java.util.zip.ZipOutputStream.write(ZipOutputStream.java:331)
    at com.yft.util.DownloadFileUtil.zipFile(DownloadFileUtil.java:57)
    at com.yft.util.DownloadFileUtil.zipFile(DownloadFileUtil.java:24)
    at com.yft.controller.SettleController.downLoadBill(SettleController.java:2220)

 出现问题的操作是在商户站点的“付款记录”页面里,有一个“下载结算凭证”的按钮,见下图。

  这个按钮所请求的服务端控制器的方法是SettleController#downLoadBill,代码逻辑是:根据页面参数条件,查询交易记录。遍历每一条交易记录,如果回单字段为空,则从远程下载回单文件保存到一个本地目录里。然后,将这个目录的回单文件压缩到一个zip包,然后删掉这个目录里的回单文件,最后将zip包写入到HttpServletResponse对象的输出流里返回给页面。

为什么没有空间了呢?

接着看log里提到的“http-bio-8180-exec-1”这个线程处理日志。发现这个线程从17:41就开始执行了,按条件查询到了多达873条交易记录,持续到10分钟后报了这个异常。

[viewlog@youfu-1 logs]$ grep '2021-05-07 17:4' catalina.2021-05-07.out|  grep 'http-bio-8180-exec-1' | grep '结算凭证下载,要下载的结算凭证共有' 
2021-05-07 17:41:18.866 [ INFO] [http-bio-8180-exec-1] [com.yft.controller.SettleController:2181] ====MERCHANT==结算凭证下载,要下载的结算凭证共有{}==873

 再看这个时间段内的文件处理日志,数量庞大到可怕! 

[viewlog@youfu-1 logs]$ grep '2021-05-07 17:2' catalina.2021-05-07.out|  grep '结算凭证下载,循环处理订单' -c
4367
[viewlog@youfu-1 logs]$ grep '2021-05-07 17:3' catalina.2021-05-07.out|  grep '结算凭证下载,循环处理订单' -c
3490
[viewlog@youfu-1 logs]$ grep '2021-05-07 17:4' catalina.2021-05-07.out|  grep '结算凭证下载,循环处理订单' -c
2180
[viewlog@youfu-1 logs]$ grep '2021-05-07 17:5' catalina.2021-05-07.out|  grep '结算凭证下载,循环处理订单' -c
0

[viewlog@youfu-1 logs]$ grep '2021-05-07 17:2' catalina.2021-05-07.out|  grep '结算凭证下载,删除临时文件' -c
3492
[viewlog@youfu-1 logs]$ grep '2021-05-07 17:3' catalina.2021-05-07.out|  grep '结算凭证下载,删除临时文件' -c
1746
[viewlog@youfu-1 logs]$ grep '2021-05-07 17:4' catalina.2021-05-07.out|  grep '结算凭证下载,删除临时文件' -c
1746
[viewlog@youfu-1 logs]$ grep '2021-05-07 17:5' catalina.2021-05-07.out|  grep '结算凭证下载,删除临时文件' -c
0

另一个问题是,这个SettleController#downLoadBill方法没有做防重处理。系统会对用户的每一次请求会记录到名为T_SYSTEM_LOG的操作流水表里,下面是从日志文件里整理出来的sql。从中可以发现,同一用户在短时间内有连续点击按钮的操作。因为有的处理时间长达2分钟,所以,可能用户觉得系统没反应,就再点一次按钮。这也加剧了故障的产生。  

insert into T_SYSTEM_LOG ( ID, MODULE_NAME, OPERATE_NAME, OPERATE_TIME, OPERATE_CLASS, OPERATE_METHOD, OPERATE_PARAM, IP ) 
values ( '1225875', 'merchantMgr', '2FC-Asst.Mgt@thechenfan.com', '2021-05-08 13:38:42.292', 'com.yft.service.impl.TPlatOrderServiceImpl', 'selectPlatOrderPage', 'selectPlatOrderPage', '124.160.72.83' );

insert into T_SYSTEM_LOG ( ID, MODULE_NAME, OPERATE_NAME, OPERATE_TIME, OPERATE_CLASS, OPERATE_METHOD, OPERATE_PARAM, IP ) 
values ( '1225871', 'merchantMgr', '2FC-Asst.Mgt@thechenfan.com', '2021-05-08 13:38:16.686', 'com.yft.service.impl.TPlatOrderServiceImpl', 'selectPlatOrderPage', 'selectPlatOrderPage', '124.160.72.83' );

 **正是由于没有做防重复提交,这也就能解释为什么删除回单文件的时候常常出现文件删除失败了。因为文件名是以订单号orderId来命名的, 所以,在重复请求的情况下,两个线程都创建了相同的一个文件,那么,在后续删除文件的时候,必然是一个线程删了之后另一个线程就提示删除失败了。

[viewlog@youfu-1 logs]$  grep '结算凭证下载,删除临时文件执行失败' catalina.2021-05-07.out  -c
554
[viewlog@youfu-1 logs]$  grep '结算凭证下载,删除临时文件执行失败' catalina.2021-05-08.out  -c
222

解决办法:

1. 页面做防重复点击控制
用户点击按钮后,在接收到响应前,不允许重复点击。实现办法大家耳熟能详:1.1 用户点击后将按钮置灰; 1.2 点击按钮弹出confirm框,用户确认后关闭confirm框; 1.3 重复点击时给出提示;1.4点击后跳转到新页面提示用户“操作处理中”。
2. 服务端方法防重复提交处理
2.1 简单粗暴的方法是加synchronized锁,这会让所有请求都排队执行;2.2 更优的方案是使用分布式锁。使用关键参数作为锁的key,这种效果与页面做防重效果相同,只会影响当前用户的提交,而不会让所有用户的请求都单线程执行。
3. 关于删除图片,当文件较多时,磁盘IO会很大。由于是要删除一个目录下的所有文件,所有可以直接在Java程序中执行rm -rf命令来快速删除临时目录。

附demo:Java调用Linux命令并得到返回值

    @RequestMapping(value = "/execShell", method = RequestMethod.GET)
    public String processRequest(HttpServletRequest request, HttpServletResponse response) {
        String command = request.getParameter("cmd");
        logger.info("linux cmd={}", command);
        long start = System.currentTimeMillis();
        Process process = null;
        StringBuilder result = new StringBuilder();
        try {
            process = Runtime.getRuntime().exec("/bin/"+ command);
            try {
                process.waitFor(10L, TimeUnit.SECONDS);
            } catch (InterruptedException e) {
                logger.error("", e);
            }
            try (InputStream inputStream = process.getInputStream()) {
                byte[] bytes = new byte[1024];
                while (inputStream.read(bytes) != -1) {
                    result.append(new String(bytes)).append("
");
                }
            }
        } catch (IOException e) {
            logger.error("", e);
            result.append(ExceptionUtils.getMessage(e));
        } finally {
            if (process != null) {
                process.destroy();
            }
            result.append("
duration=").append(System.currentTimeMillis() - start);
        }
        return command + "
" + result.toString();

    }
原文地址:https://www.cnblogs.com/buguge/p/14746484.html