频繁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();

    }