锐客网

  1. 首页 > it技术 > >

springboot升级2后文件上传引起的坑

1.今天测试环境启动后，才启动没好久，在浏览器请求服务器的地址，发现没有返回接口，一直在请求等待。查询日志报了内存溢出的错误:

2020-08-31 15:31:40.314INFO 11371 --- [nio-8016-exec-1] a.s.s.m.AbstractValidatingSessionManager : Enabling session validation scheduler... Exception in thread "http-nio-8016-exec-4" Exception in thread "http-nio-8016-exec-6" Exception in thread "http-nio-8016-exec-2" Exception in thread "http-nio-8016-exec-7" Exception in thread "http-nio-8016-exec-5" java.lang.OutOfMemoryError: Java heap space java.lang.OutOfMemoryError: Java heap space at java.nio.HeapByteBuffer.(HeapByteBuffer.java:57) at java.nio.ByteBuffer.allocate(ByteBuffer.java:335) at org.apache.coyote.http11.Http11OutputBuffer.(Http11OutputBuffer.java:111) at org.apache.coyote.http11.Http11Processor.(Http11Processor.java:238) at org.apache.coyote.http11.AbstractHttp11Protocol.createProcessor(AbstractHttp11Protocol.java:876) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:794) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:748) java.lang.OutOfMemoryError: Java heap space at java.nio.HeapByteBuffer.(HeapByteBuffer.java:57) at java.nio.ByteBuffer.allocate(ByteBuffer.java:335) at org.apache.coyote.http11.Http11OutputBuffer.(Http11OutputBuffer.java:111) at org.apache.coyote.http11.Http11Processor.(Http11Processor.java:238) at org.apache.coyote.http11.AbstractHttp11Protocol.createProcessor(AbstractHttp11Protocol.java:876) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:794) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:748) java.lang.OutOfMemoryError: Java heap space java.lang.OutOfMemoryError: Java heap space Java HotSpot(TM) 64-Bit Server VM warning: ignoring option MaxPermSize=512M; support was removed in 8.0 Listening for transport dt_socket at address: 9011

启动就报上面的错误，很诡异。
于是用查询了下tcp连接相关的信息:
netstat -na | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'
处于CLOSE_WAIT 23 # 非常异常
发现绝大部份的链接处于 CLOSE_WAIT 状态，这是非常不可思议情况。然后用 netstat -an 命令进行了检查
netstat -anlp|grep 8015
发现我本机IP连接的状态很多一直处理CLOSE_WAIT 状态，每请求一次页面，连接一直增多。
具体tcp状态请见:https://cloud.tencent.com/developer/article/1381359
2.于是用jmap -heap PID
[root@SIT6002 chain.lo]# jmap -heap 23936 Attaching to process ID 23936, please wait... Debugger attached successfully. Server compiler detected. JVM version is 25.231-b11using thread-local object allocation. Parallel GC with 8 thread(s)Heap Configuration: MinHeapFreeRatio= 0 MaxHeapFreeRatio= 100 MaxHeapSize= 1073741824 (1024.0MB) NewSize= 178782208 (170.5MB) MaxNewSize= 357564416 (341.0MB) OldSize= 358088704 (341.5MB) NewRatio= 2 SurvivorRatio= 8 MetaspaceSize= 21807104 (20.796875MB) CompressedClassSpaceSize = 1073741824 (1024.0MB) MaxMetaspaceSize= 17592186044415 MB G1HeapRegionSize= 0 (0.0MB)Heap Usage: PS Young Generation Eden Space: capacity = 315621376 (301.0MB) used= 162599672 (155.06713104248047MB) free= 153021704 (145.93286895751953MB) 51.5173192832161% used From Space: capacity = 20447232 (19.5MB) used= 0 (0.0MB) free= 20447232 (19.5MB) 0.0% used To Space: capacity = 20971520 (20.0MB) used= 0 (0.0MB) free= 20971520 (20.0MB) 0.0% used PS Old Generation capacity = 716177408 (683.0MB) used= 550499696 (524.9974212646484MB) free= 165677712 (158.00257873535156MB) 76.86638671517547% used

从上面的信息可以看到老年代，内存使用已经达76%了,明显老年代的使用率过高，容易发生full gc。堆内存不够。
3.使用jstat查询gc回收情况,每5秒执行一次
[root@SIT6002 chain.lo]# jstat -gc 23936 5000 S0CS1CS0US1UECEUOCOUMCMUCCSCCCSUYGCYGCTFGCFGCTGCT 19968.0 20480.00.00.0308224.0 230911.6699392.0537597.483840.0 81358.2 10368.0 9901.8240.65450.7081.363 19968.0 20480.00.00.0308224.0 231832.7699392.0537597.483840.0 81358.2 10368.0 9901.8240.65450.7081.363 19968.0 20480.00.00.0308224.0 232702.8699392.0537597.483840.0 81358.2 10368.0 9901.8240.65450.7081.363 19968.0 20480.00.00.0308224.0 234124.6699392.0537597.483840.0 81358.2 10368.0 9901.8240.65450.7081.363 19968.0 20480.00.00.0308224.0 235045.6699392.0537597.483840.0 81358.2 10368.0 9901.8240.65450.7081.363 19968.0 20480.00.00.0308224.0 235915.5699392.0537597.483840.0 81358.2 10368.0 9901.8240.65450.7081.363 19968.0 20480.00.00.0308224.0 236836.6699392.0537597.483840.0 81358.2 10368.0 9901.8240.65450.7081.363 19968.0 20480.00.00.0308224.0 237757.8699392.0537597.483840.0 81358.2 10368.0 9901.8240.65450.7081.363 19968.0 20480.00.00.0308224.0 238627.4699392.0537597.483840.0 81358.2 10368.0 9901.8240.65450.7081.363 19968.0 20480.00.00.0308224.0 239548.6699392.0537597.483840.0 81358.2 10368.0 9901.8240.65450.7081.363

刚启动，就发生了5次full gc。
4.想到堆内存，不够。于是增加堆内存，同时把新生代的比例调整为6。增加伊甸区的内存比例。
-Xms1024M -Xmx1024M -XX:SurvivorRatio=6
重启应用后，问题更严重。full gc 更加严重
[root@SIT6002 chain.lo]# jstat -gc 16912 5000 S0CS1CS0US1UECEUOCOUMCMUCCSCCCSUYGCYGCTFGCFGCTGCT 25600.0 512.00.00.0299008.0 258178.0699392.0646180.379616.0 76343.9 9984.0 9333.7230.569162.6673.236

【springboot升级2后文件上传引起的坑】5.查看内存中对象数量及大小
jmap ‐histo 16912 | more
使用上面的命令，一直报错，都没有反应。
6.决定用dump把快照
jmap -dump:format=b,file=heap.hprof 16912
生成后差不多有1个G左右的大小，还好是测试环境。要是在现在估计是不能这样直接使用。可以使用arthas工具，查询。由于测试环境，把相关外网静止了，不能使用，只有手动用命令来操作了.
7.下面dump文件到本地后，使用java的sdk提供的jvisualvm.exe工具，导入分析如
springboot升级2后文件上传引起的坑
文章图片
同时上图可以得知，Byte[]实例不是最多，但是占用的大小比例是最多的。

springboot升级2后文件上传引起的坑
文章图片
查询实例试图，得知是http head 的内存占用，如下
springboot升级2后文件上传引起的坑
文章图片
springboot升级2后文件上传引起的坑
文章图片
于是想到，之前接口联调的时候，调用方文件超过10M后不能上传，我这边做了配置调整。
之前springboot1版本的，配置
#spring.http.multipart.max-file-size=100MB #spring.http.multipart.enabled=true

是可以生效，但是版本升级到2.0版本后，上面的配置没有生效，于是在网上搜索了，如下配置
spring.servlet.multipart.enabled=true spring.servlet.multipart.file-size-threshold=0 #Maxfilesize. spring.servlet.multipart.max-file-size=20MB #Maxrequestsize. spring.servlet.multipart.max-request-size=30MB #设定HttpHeader请求头大小10MB server.tomcat.max-http-header-size=124288000 #设定Httppost数据大小 server.tomcat.max-http-post-size=124288000

配置后，在本地接口上传文件是生效的，于是就发布到测试环境，让别人测试。部署好后，访问界面，
访问不了，发生了文章开头提到问题。
server.tomcat.max-http-header-size=124288000这个参数，怀疑是配置有文件。于是搜索下
这个参数，一搜发现由于这次参数引起的坑，排在了前面。问题还不少。
https://blog.csdn.net/sinat_24044957/article/details/82493561
于是把参数注释掉，并设置max-http-post-size设置-1，表示不限制
#server.tomcat.max-http-header-size=124288000 server.tomcat.max-http-post-size=-1

把之前gc调整的-XX:SurvivorRatio=6去掉，使用默认参数。重新启动后，应用正常了。
用jmap和jstat查询堆和gc情况，full gc只发生了一次，并且老年代的占用也很小。应用界面终于正常访问了。
server.tomcat.max-http-header-size配置居然是每次请求，都打满配置的100M,堆才配置的1G,所以看到每请求一次,内存很快被打满。
教训:主要还是对于网上提供的参数，没有仔细去研究作用。
参考:
https://www.cnblogs.com/shuliyuanshi/p/11510993.html
https://www.hellojava.com/a/89406.html
jmap
https://www.cnblogs.com/Zzzzn/p/12403764.html
gc原理
https://www.cnblogs.com/caison/p/11641791.html
gc日志查看
https://www.cnblogs.com/qlqwjy/p/7929414.html

    推荐阅读


    上一篇：04|04 | 深入浅出索引（上）

    下一篇：成长，每一步都算数