记一次印象深刻的bug---并发下File has been moved - cannot be read again源码分析

以你之姓@ 2023-05-22 14:25 8阅读 0赞

# 记一次印象深刻的bug—并发下File has been moved - cannot be read again源码分析 #

每天多学一点点~  
话不多说，这就开始吧…

### 文章目录 ###

*  记一次印象深刻的bug---并发下File has been moved - cannot be read again源码分析
 *  1.前言
 *  2.代码
 *  3.分析
 *   *  3.1 线程池分析
     *  3.2 日志的重要性
     *  3.3 File has been moved - cannot be read again异常源码分析
 *  4.解决方法
 *  5.总结
 *  6.结语

# 1.前言 #

之前和微信端调试接口，图片上传至OSS，因为微信的原因，不能批量上传，前端只能循环调用接口。后来新增了**缩略图**功能，前端给图片，后端压缩一份再上传，于是就想着在不影响性能的情况下，用线程池做成异步方法。本地调试都是ok的，谁知上了生产，缩略图显示时而上传成功，时而上传失败，还没抛出异常，**偶发性的**。但是**换成同步**，就不会出现问题。头大了~一步步分析吧。

# 2.代码 #

微信端用了**模板方法**设计模式，抽起出抽象方法用于上传，各个模块的方法用于拼接路径。  
所有的service实例因为业务需要，将其全部配置在了xml文件中，从xml文件读取(当然从db查，让如jvm缓存也可以，根据需求来)  
![代码目录结构][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3dlaXhpbl80MjQzNzYzMw_size_16_color_FFFFFF_t_70]  
![fileupload.xml][]  
![controller][]

ThumbnailAsyncConfig 线程池配置

@Configuration
    @EnableAsync
    public class ThumbnailAsyncConfig { 
    
        private static final int CORE_POOL_SIZE = 10;   //核心线程数 考虑到有压缩图片 选5
    
        private static final int MAX_POOL_SIZE = 100;    // 线程池 最大 
    
        private static final int QUEUE_CAPACITY = 80;   //队列大小
    
        private String ThreadNamePrefix = "thumbnailExecutor-";
    
        @Bean("thumbnailExecutor")
        public ThreadPoolTaskExecutor executor() { 
            ThreadPoolTaskExecutor taskExecutor = new ThreadPoolTaskExecutor();
            taskExecutor.setCorePoolSize(CORE_POOL_SIZE);
            taskExecutor.setMaxPoolSize(MAX_POOL_SIZE);
            taskExecutor.setQueueCapacity(QUEUE_CAPACITY);
            taskExecutor.setKeepAliveSeconds(60);
            taskExecutor.setThreadNamePrefix(ThreadNamePrefix);
            taskExecutor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());//满了之后，由当前线程执行
            taskExecutor.setWaitForTasksToCompleteOnShutdown(true);
            taskExecutor.initialize();
            return taskExecutor;
        }
    
    }

调用 异步上传的方法

@Autowired
       			 private AsyncTask asyncTask;
     			// 方法的调用
                String thumbnailPath = reMap.get("thumbnailPath");
                if (StringUtils.isNotBlank(thumbnailPath)) { 
                    LOGGER.info("asyncTask.uploadThumbnail ");
    
                    try { 
                        asyncTask.uploadThumbnail(file, thumbnailPath);
                    } catch (Exception e) { 
                        e.printStackTrace();
                    }
                }
    
        /** * spring 异步上传 缩略图 具体的方法实现 */
        @Async("thumbnailExecutor")
        public Future<String> uploadThumbnail(MultipartFile file, String thumbnailPath) { 
            LOGGER.info("Thumbnail file upload start !!!!!!!!!!!!!!!!!!!!!!!!! ");
    
            try { 
                ByteArrayInputStream byteArrayInputStream = OSSUpload.imageCompress(file.getInputStream());	 // 缩略图 file.getInputStream()会异常
                OSSUpload.uploadOssPhoto(thumbnailPath, byteArrayInputStream);
            } catch (Exception e) { 
                // e.printStackTrace(); // 这里原本是这样的 没有打印日志
                LOGGER.info(" info e: {} " , e.getMessage());
            }
            LOGGER.info("Thumbnail file upload end ~~~~~~~~~~~~~~~~~~~ ");
            return new AsyncResult<String>("success");
        }
        /** * 压缩图片 * * @param input * @return */
        public static ByteArrayInputStream imageCompress(InputStream input) { 
            ByteArrayOutputStream out = null;
            try { 
                out = new ByteArrayOutputStream();
                Thumbnails.of(input).scale(0.25f).toOutputStream(out);
            } catch (IOException e) { 
                e.printStackTrace();
            } finally { 
                if (input != null) { 
                    try { 
                        input.close();
                    } catch (IOException e) { 
                        e.printStackTrace();
                    }
                }
            }
            return new ByteArrayInputStream(out.toByteArray());
        }

# 3.分析 #

## 3.1 线程池分析 ##

一开始也以为时线程池的原因，会不会因为核心线程数配置太大了。但是每次**线上debug**和看日志，线程其实每次都能进入。后查资料得证：

**corePoolSize**与**maximumPoolSize** ：由于ThreadPoolExecutor 将根据 corePoolSize和 maximumPoolSize设置的边界自动调整池大小，当执行 execute(java.lang.Runnable) 方法提交新任务时：

1.  如果运行的线程少于 corePoolSize，则创建新线程来处理请求，即使其他辅助线程是空闲的；
2.  如果设置的corePoolSize 和 maximumPoolSize相同，则创建的线程池是大小固定的，如果运行的线程与corePoolSize相同，当有新请求过来时，若workQueue任务阻塞队列未满，则将请求放入workQueue中，等待有空闲的线程从workQueue中取出任务并处理。
3.  如果运行的线程多于 corePoolSize 而少于 maximumPoolSize，则仅当workQueue任务阻塞队列满时才创建新线程去处理请求；
4.  如果运行的线程多于corePoolSize 并且等于maximumPoolSize，若workQueue任务阻塞队列已满，则通过handler所指定的策略来处理新请求；
5.  如果将 maximumPoolSize 设置为基本的无界值（如 Integer.MAX\_VALUE），则允许池适应任意数量的并发任务。

**也就是说，处理任务的优先级为**：  
6. 核心线程corePoolSize > 阻塞队列workQueue > 最大线程maximumPoolSize，如果三者都满了，使用handler处理被拒绝的任务。  
7. 当池中的线程数大于corePoolSize的时候，多余的线程会等待keepAliveTime长的时间，如果无请求处理，就自行销毁。

**corePoolSize**：在创建了线程池后，**默认情况下，线程池中并没有任何线程，而是等待有任务到来才创建线程去执行任务**，除非调用了prestartAllCoreThreads()或者 prestartCoreThread()方法，从这2个方法的名字就可以看出，是预创建线程的意思，即在没有任务到来之前就创建 corePoolSize个线程或者一个线程。**默认情况下，在创建了线程池后，线程池中的线程数为0，当有任务来之后，就会创建一个线程去执行任务，当线程池中的线程数目达到corePoolSize后，就会把到达的任务放到阻塞队列当中**；  
**maximumPoolSize** ：线程池最大线程数，这个参数也是一个非常重要的参数，它表示在线程池中最多能创建多少个线程；

## 3.2 日志的重要性 ##

一开始没有打日志，怀疑线程有问题。后来加上日志，反复测试，发现日志每次都打印了。

LOGGER.info("Thumbnail file upload start !!!!!!!!!!!!!!!!!!!!!!!!! ");
    LOGGER.info("Thumbnail file upload end ~~~~~~~~~~~~~~~~~~~ ");

但是就是不报错。很奇怪，后来查资料才知道，**e.printStackTrace()** 并不能将信息打印到日志中，遂改成**LOGGER.info(" info e: \{\} " , e.getMessage());**

然后再次测试，好家伙，**cn.jtb.wechat.fileupload.service.ICommonFileUploadService**，终于出来了！但是为何会出现这个异常？之前没有仔细研究过，反复查找资料。

## 3.3 File has been moved - cannot be read again异常源码分析 ##

前言中也说了，这个异常时**偶发性**的。  
**查资料得知**：  
①在配置spring MultipartResolver时不仅要配置maxUploadSize，还需要配置maxInMemorySize。但原因都没说的很清楚。只是简单说maxInMemorySize的默认值为10240 bytes（好像是），超出这个大小的文件上传spring会先将上传文件记录到临时文件中。临时文件会被删除。  
②多线程，每个请求上传都开一个线程。

从file.getInputStream()入手  
![getInputStream()源码][getInputStream]  
![isAvailable()][isAvailable]  
![getStoreLocation()源码][getStoreLocation]  
![isInMemory源码][isInMemory]  
![在这里插入图片描述][2020070201115284.png]  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3dlaXhpbl80MjQzNzYzMw_size_16_color_FFFFFF_t_70 1]  
源码debug路径

org.springframework.web.multipart.commons.CommonsMultipartFile#getInputStream
         ---> org.springframework.web.multipart.commons.CommonsMultipartFile#isAvailable
    		--->org.apache.commons.fileupload.disk.DiskFileItem#getStoreLocation
    			--->org.apache.commons.fileupload.disk.DiskFileItem#isInMemory
    			   --->org.apache.commons.io.output.DeferredFileOutputStream#isInMemory
    			      --->org.apache.commons.io.output.ThresholdingOutputStream#isThresholdExceeded

**到底是保留在内存还是缓存到临时文件，由阈值大小threshold决定,默认是10kib**

*  内容字节数大于threshold，缓存到临时文件，临时文件自己配置
 *  内容字节数小于threshold，保留在内存中

一步步debug发现，最后发现调用了**ThresholdingOutputStream**的**isThresholdExceeded()方法，其会检查准备写出到输出流的文件大小，是否超过设定的阈值，这个阈值通过debug发现，就是我们前面配置的参数maxInMemorySize，其默认是10Kib**。在本项目中，由于上传的图片都在10Kib大小以上，其都超过了阈值，方法执行返回为true，参数传入到isInMemory方法后，返回false，最终传入到最上层会返回false，从而抛出本次记录的异常。

org.apache.commons.fileupload.disk.DiskFileItemFactory中  
private int sizeThreshold = DEFAULT\_SIZE\_THRESHOLD;  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3dlaXhpbl80MjQzNzYzMw_size_16_color_FFFFFF_t_70 2]

**但是，我tomcat 就算没配置maxInMemorySize（下面会说）这个值，在单线程情况下依然可以。所以原因有，但不在这里。**  
查找很多资料，这篇说的蛮好的

**https://www.iteye.com/blog/lawrencej-2262675**

原因出在 **org.apache.commons.fileupload.disk.DiskFileItemFactory\#createItem**

@Override
        public FileItem createItem(String fieldName, String contentType,
                boolean isFormField, String fileName) { 
            DiskFileItem result = new DiskFileItem(fieldName, contentType,
                    isFormField, fileName, sizeThreshold, repository);
            result.setDefaultCharset(defaultCharset);
            FileCleaningTracker tracker = getFileCleaningTracker();
            if (tracker != null) { 
                tracker.track(result.getTempFile(), result);
            }
            return result;
        }

Tracker即用来**删除临时**文件。理解它的工作机制就会理解临时文件是怎么被删除的，那么就能知道，我们程序为什么读不到文件了。  
[fileupload的官网地址][fileupload]  
找到Resource cleanup一段  
temporary files are deleted automatically, if they are no longer used (more precisely, if the corresponding instance of java.io.File is garbage collected. This is done silently by the org.apache.commons.io.FileCleaner class, which starts a reaper thread.）  
翻译一下：  
临时文件会自动删除，如果它们不再被使用(更准确地说，如果相应的 java.io文件实例 被垃圾收集，这是由org.apache.common .io. filecleaner类静悄悄地完成的，它启动一个新的线程)

**如果文件没有被引用，被GC回收那么文件被清理。**

**自己的理解**：  
Spring上传文件默认的文件上传处理器 CommonsMultipartResolver 这个类中使用了 common fileUpload 组件来进行文件的上传。  
而 fileUpload 组件在进行文件上传时因为 java 内存有限，所以会先将较大的文件存放在硬盘中的一个**临时目录**中读取，**而不是直接在内存中进行操作**。  
因此，在对较大文件进行分步骤操作时（例如对大小超过10M的图片进行缩略图生成处理），  
就不能从内存中读取了，需要从硬盘直接读取，磁盘中临时文件被删除，这时候调用file.getInputStream()必然要抛异常了，就会因为要读取的文件已经不存在于内存中而出现java.lang.IllegalStateException: File has been moved - cannot be read again 这个异常。

**同步**：**个人觉得**程序是顺序进行的，每张图片的大小在2m左右，压缩之后还需要上传至oss，上传也会耗时，在同步情况下，就算没配置maxInMemorySize参数，放入了临时文件，但此时是单线程，文件没有被删除，所以成功。  
**异步**：并发操作下，线程太快，才会**偶发性**的出现， T1…Tn线程，超过10kb文件会放入磁盘临时目录，**而多线程下，当tomcat的处理线程完成后，GC回收了该对象，通过虚引用apache接收到回收的消息删除了临时文件（个人理解）**，所以在压缩的时候file.getInputStream()会抛出异常。

# 4.解决方法 #

1.  将压缩图片的方法写成同不，上传至oss写成异步  
    这种方式是从逻辑处理方面上的，从而避免出现文件异常。但是会影响性能，毕竟每次压缩操作都是同步执行的。
2.  修改spring CommonsMultipartResolver参数

<bean id="multipartResolver" class="org.springframework.web.multipart.commons.CommonsMultipartResolver">
            <property name="defaultEncoding" value="UTF-8"/>
            
            <property name="maxUploadSizePerFile" value="209715200"/>
            
            <property name="maxUploadSize" value="2097152000"/>
            
            <property name="maxInMemorySize" value="2097152000"/>
            
            <property name="resolveLazily" value="true"/>
        </bean>
    # maxInMemorySize 源码分析
    org.springframework.web.multipart.commons.CommonsFileUploadSupport#setMaxInMemorySize
    	--->org.apache.commons.fileupload.disk.DiskFileItemFactory#setSizeThreshold

![在这里插入图片描述][20200702014900341.png]  
![在这里插入图片描述][20200702014922201.png]

**maxInMemorySize** ：这个属性用来决定大小超多多大的文件会被放在硬盘中的临时目录而不是直接在内存中操作，所以我们调整这个数值的大小为超过我们要进行操作的文件的最大大小即可。根据自己系统的并发下，设置合适的值便可。我这里直接设置成50MB，足够应付图片了  
**resolveLazily**:是否要延迟解析文件。当 resolveLazily为false（默认）时，会立即调用 parseRequest() 方法对请求数据进行解析，然后将解析结果封装到 DefaultMultipartHttpServletRequest中；而当resolveLazily为 true时，会在DefaultMultipartHttpServletRequest的initializeMultipart()方法调用parseRequest()方法对请求数据进行解析，而initializeMultipart()方法又是被getMultipartFiles()方法调用，即**当需要获取文件信息时才会去解析请求数据，这种方式用了懒加载的思想**。

# 5.总结 #

1.  善用线程池，而不是乱用，调整好合适的参数
2.  代码中关键部分要打印日志  
    e.printStackTrace();并不能打印出日志，要用LOGGER.info(" info e: \{\} " ， e.getMessage());
3.  spring的上传图片原理

# 6.结语 #

**世上无难事，只怕有心人，每天积累一点点，fighting！！！**

[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3dlaXhpbl80MjQzNzYzMw_size_16_color_FFFFFF_t_70]: /images/20230521/adfc7752dfd04c5780f5bd716e245b90.png
[fileupload.xml]: /images/20230521/b9e9527679294d7dbdb09708f64a386a.png
[controller]: /images/20230521/fa1a5b3299384928a63923fe1652968b.png
[getInputStream]: /images/20230521/647c22495f05426d8ad070a04f64205f.png
[isAvailable]: /images/20230521/3a59180bab34468b9726c05de8914cc7.png
[getStoreLocation]: /images/20230521/6660325582f5429f860dfaa735ec0c6a.png
[isInMemory]: /images/20230521/96f2c9e5ccd84f73afa922fbbe46be78.png
[2020070201115284.png]: /images/20230521/ecd68c49741a46928cf92b15e52a60a6.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3dlaXhpbl80MjQzNzYzMw_size_16_color_FFFFFF_t_70 1]: /images/20230521/639d465ed8344944b6894314ff137bf7.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3dlaXhpbl80MjQzNzYzMw_size_16_color_FFFFFF_t_70 2]: /images/20230521/4fc0dc92f3bd4cf4bca5a061bf2aaf0f.png
[fileupload]: https://commons.apache.org/proper/commons-fileupload/
[20200702014900341.png]: /images/20230521/1f0e41e4183241e2995753d9f278f474.png
[20200702014922201.png]: /images/20230521/d33f5f1948cd4c4797af150c1c0a9bb2.png