踩坑记录-maxHttpHeaderSize配置-内存都去哪儿

作者: NormanCao | 来源:发表于2020-05-12 20:52 被阅读0次

            遇到一个问题,自己部署的线上springboot服务总是内存飙高,尤其是在30个以上的请求并发的时候,内存会立马大涨,并出现报错:

    java.lang.OutOfMemoryError: Java heap space
    

            后来通过一步一步排查发现了导致这个问题的原因,就是当初在设置springboot的上传文件大小限制的时候加了一个配置:

    server.maxHttpHeaderSize=102400000
    

            意思是http最大请求头大小设置成了大约100M,springboot默认的maxHttpHeaderSize是8K,如果没有特殊需要,应该是够用的。把这个配置注释掉就可以解决掉我提到的这个问题。
            遇到跟我一样问题的小伙伴,可以检查一下是不是跟我犯了一样的错误,到这儿这个文章也可以结束了,但是鉴于这一次问题的排查过程走了很多“弯路”,不过却学到了很多东西,所以把我找原因,并且找到原因之后定位导致这个错误的具体是哪一行代码的过程记录一下,有兴趣的小伙伴可以看一下。

    会涉及到哪些知识点?

    接下来要讲的会涉及到一些知识点,不懂也没关系,我会简单说明:

    JVM内存结构基础理解:

    jvm内存分成三块:堆内存(Heap Space)、方法区(Method Area/PermGen)和栈(Native Area)。

    • 堆内存:是内存大头,一般程序出现内存问题都在这里。由新生代和老生代组成。新生代由Eden空间、From Survivor空间、To Survivor空间组成。
    • 方法区:存储类信息、常量、静态变量等数据。又叫Non-Heap
    • 栈:主要用于方法的执行
    JVM两种GC机制:

    GC是指java自动回收内存的机制,有两种方式:

    • Minor GC:发生在新生代的垃圾收集动作。比较频繁,回收速度快。
    • Major GC/Full GC 是老年代GC(通常伴随Minor GC),速度很慢。
      因此要尽量避免触发Full GC.
    JVM内存分配机制:

            简单介绍一下java中新建的对象,一般会放在新生代的Eden,经过Minor gc之后没有被销毁的对象会被复制到新生代的Survivor区域(至于为什么Survivor分为from to,这里涉及到一个复制算法,有兴趣的可以自行查阅)
            对象会被分配到老生代的几种情况:

    • 经历了默认15次minor gc之后,还没被销毁
    • 动态对象年龄判断
    • 大对象直接进入老年代(这一次错误的主因)
    • MinorGC后的对象太多无法放入Survivor区
    • 老年代空间分配担保规则
    JVM命令:

    假设我们的java进程号是11111

    //jstack命令用来输出指定进程当前所有线程的运行步骤,用来查是不是又死循环很有用,结果输出到jstack.log文件
    jstack 88059 > jstack.log
    //jmap -histo 用来打印当前java进程有哪些对象,这些对象的数量和占用的内存大小分别是多少,结果输出到jmap.log文件
    jmap -histo 11111 > jmap.log
    
    jconsole:

            jconsole是一个java自带的查看进程内存情况的GUI神器,具体可以搜一下“springboot jconsole”有很多教程。简单看一下这个连接界面和内存监控界面,非常好用,也可以通过这个自己做一些小实验,对JVM内存机制进一步学习。


    jconsole新建连接
    jonsole2内存查看面板
    jmeter:

    压力测试工具

    为什么会有这个配置?

            先说一下为什么我会添加这个配置。有一个需求,是要通过base64上传大文件,springboot默认是由文件上传大小限制的,通过网上查,找到添加如下配置:

    spring.http.multipart.max-file-size=20Mb  
    spring.http.multipart.max-request-size=60Mb 
    

            但是这个配置只是针对multipart形式上传文件的限制有效,base64形式的这个配置无效,上传文件大小还是限制得很小,又从网上找到了配置:

    server.maxHttpHeaderSize=102400000
    server.maxHttpPostSize =102400000
    

    设置完之后问题得到解决

    为啥服务老挂?

            在修改完配置的很长一段时间内,使用一直没什么问题,但是随着用户量增多,并且提交了一些爬虫(百度,360,搜狗)的申请,外加添加了网站的sitemap之后,网站访问频率变高,服务时不时出现报错:

    java.lang.OutOfMemoryError: Java heap space
    

            检查nginx日志之后发现,尤其是在一秒钟有超过20个请求的情况下,就经常出现这个错误,一旦出现这个错误,服务的内存就很高,一个空的接口返回时间,也要几十秒,十分不正常。
            然后就开始了长时间挂了就重启,甚至封锁了有些搜索引擎的爬虫,来降低网站的被访问频率,降低造成OOM带来的用户影响。还对经常被爬虫访问的接口做了两三天的接口优化,每一次把优化上线,都祈祷着再也不要出现这个报错,但是事与愿违。

    哪里的内存出了问题

            这个问题在线上的时候,是偶发的,因为当时没有想到是并发造成的,觉得可能是业务中某个参数异常造成的。每一次出现这个问题:就利用jstack命令,查看了每一个线程运行的步骤,几次查找下来,都没有结果。
            再利用jmap -histo 查明每一个对象的数量以及它占用的内存,发现了异常情况下,内存的增长量几乎都是集中在“[B”,也就是字节数组,字节数组的话就很难定位具体对象,如果是我们业务中的某个自己写的对象的问,问题马上就能找到。
            利用jconsole,查看每一次内存被占满都是在老生代区域,手动执行jconsole上的gc之后,内存都还是这么高。但是每一次重启完服务之后内存都很低,看着很舒服,重启大法屡试不爽,但是终究解决不了问题。

    会不会不是自己业务接口的原因?

    综合分析一下:

    • 根据出问题时间的nginx日志访问统计,得出可能性结论,并发会导致这个问题出现,在测试环境用jmeter测试之后发现果然,并发就会出现OOM报错。
    • 内存问题出现在老生代,并且在并发之后,老生代内存一下飙高,结合对象进入老生代的几种情况,猜测是不是创建了什么超级大的对象,第一反应是不是读取了什么大文件?查找代码之后无果。

            几次调优之后不见效果,不禁怀疑,是不是跟业务代码无关,于是乎把自己的服务本地启动起来,针对出问题的接口,利用jmeter发起30QPS的查询,持续三十秒。
            不出意料,报OOM错误,确认这个情况本地能复现且必现。

            再编写了一个空业务的接口,controller层直接返回,做同样的压测,竟然也出现了OOM。这说明跟自己的业务没半毛钱关系,也就是之前的查询业务优化确实起不到任何作用。

            排除了业务上的问题的可能性,再下一步怀疑是不是引入的某个包导致的,于是一层一层的去掉如引入的包,去掉redis,mybatis,okhttp等等 ,甚至去掉了springcloud依赖只剩下springboot,依然会出现OOM。

            这样排除下来,基本上就只剩下一种可能,就是配置文件的问题,于是通过配置文件中的配置一个个删除,终于定位到了最开始提到的那一行maxHttpHeaderSize的配置。

    这个配置在哪里生效?为什么会导致这个问题?

            确定了是配置的问题之后,总算松了一口气,线上服务有救了,但是为什么这么一个配置,会导致内存溢出呢,他不就是规定http请求头最大限制,超过这个限制就应该报错而已嘛?那我们就追踪源代码一探究竟。

            首先这个配置会在哪里被读取呢?我按照做framework的人的老思路,配置一般都会被装配成配置实体类,既然他是"server."开头的,那是不是会有一个ServerConfig,或者ServerProperties这样的类。


    通过代码提示找到ServerProperties类

            利用代码提示,果真找到了有这么一个类。在这个类中也确实找到了这么一个变量,跟这个配置的命名是一致的。so lucky!


    ServerProperties中找到maxHttpHeaderSize
            可以看到这个配置默认大小是8KB。当然这个配置在哪个类里面在百度应该也能搜到具体在哪。
            再下一步,找到这个变量的get方法,查找这个方法的所有调用可以看到有以下四个地方调用了这个get方法:
    查找变量get方法的引用

            我们知道springboot是内置服务容器的,而默认内置的就是tomcat容器,因此我们双击查看第四条,也就是我框出来的那一条。可以看到如下代码:


    继续查找调用
            再对这个方法查找调用
    再查找发现只有一个调用
            很好,只有这一个调用。双击打开之后如下:
    在customize方法中找到此方法的调用
            这里的PropertyMapper看一下它的注释,大概意思是从一个地方拷贝值到另一个地方,从from拷贝到to,那我们进入第90行的customizeMaxHttpHeaderSize方法
    查看customizeMaxHttpHeaderSize方法
            这里看到maxHttpHeaderSize被赋值给了AbstractHttp11Protocol的一个对象,那么进入类,找到maxHttpHeaderSize变量
    在AbstractHttp11Protocol找到maxHttpHeaderSize

            在这个类里面搜了一下maxHttpHeaderSize,很幸运,这个变量只有get,set这两个方法在用,内部其他地方没有用到,大大降低了我们跟踪的复杂度,同样,对这里的get方法做查找调用


    查找getMaxHttpHeaderSize方法的调用
            只有一个地方调用,跟踪到Http11Processor里面调用getMaxHttpHeaderSize方法的代码
    定位到了Http11Processor的构造方法
            这里一个是Http11InputBuffer相关的,一个是Http11OutputBuffer相关的,先来看Http11InputBuffer
    Http11InputBuffer的构造函数
            被赋值给了headerBufferSize,然后我们看一下Http11InputBuffer中有使用到headerBufferSize的几个地方:
    A处
    B处
    C处
            聪明的你一定发现了A,C两个地方这个变量只是用来做了大小判断,但是B处,692行bufLength被赋值成了headerBufferSize加上了另外一个值,再看695行,有一个:
                byteBuffer = ByteBuffer.allocate(bufLength);
    

            是不是豁然开朗?不豁然开朗的同学一定是不清楚ByteBuffer.allocate是什么意思。ByteBuffer.allocate的意思是生成一个指定长度的字节数组,也就是说这个bufLength有多大,这个字节数组就有多长,而bufLength又是headerBufferSize加上了某个值,也就是说如果headerBufferSize=我所设置的102400000,那么这个地方就会生成一个至少102400000长度的字节数组,这非常消耗内存

    //这里将会有至少102400000个0
    byteBuffer = [0,0,0,0,0,0,0,0....,0];
    

            同样的道理你去查看Http11OutputBuffer,也会发现一个地方调用了ByteBuffer.allocate,可能会生成很长的字节数组。
            而之前提到过,java中的大对象会直接进入老生代。100M的对象还不够大吗?对我们的环境来说,100M足够大到直接进入老生代(多大会被认定为大对象有个jvm参数可以配置的)。
            另一方面,之前提到jmap -histo查看各个对象占用内存的时候发现其他对象内存几乎没有什么异常,但是“[B”大小特别大,也就是字节数组异常占内存,也与这里找到的原因正好契合。
            终于找到了导致内存飙高的真凶。那么什么情况下会产生这种情况呢?

    怎么确定高并发情况下就会执行到这个生成大字节数组的代码呢?

            在Http11InputBufferde 695行打断点,debug启动你的springboot服务,然后找一个测试接口,调用这个接口,你会发现695行会被命中,这个时候就会创建这个大数组。
            但是之前系统上线之后,没有并发的时候,能正常运行挺久时间的,接口一个一个调用,能正常,那么按照现在的发现,每一次请求生成一个大数组,比如消耗100M内存的话,调用100次,岂不是10G内存就没了?
    带着疑问,我们继续执行第二次测试接口的请求,发现第二次请求的时候,695行没有命中,也就是说对象在复用,所以如果不是并发的情况下,这个大数组是不是额外生成的。
            符合之前线上服务的异常特征。
            不知道大家在debug的时候有没有留意过debug里面这里产生的这些守护线程:


    守护线程们

            这里有1到30编号的线程,百度一下可以知道,这些线程就是用来处理用户发起的请求的,当我们用jmeter发起高并发请求的时候,这30个线程发现不够用了,就会产生新的线程,末尾的编号也会随之新增,Http11InputBufferde 695行也会不断命中,大数组也会不断生成。

    总结和疑惑

    小朋友,你是否有很多问号?

            至此我们对于这个问题的探索就告一段落,当然还有很多知识的盲区需要去扫,一个人了解的越多,头上的问号也会越多。那么这个算不算bug,我觉得严格意义上来说不算,但是确实存在设计的不合理。因为一个配置命名成maxHttpHeaderSize,给人的第一印象应该是是对http请求头的限制,如果请求头比这个限制大了,服务会报个错提示一下,而不是直接拿这个值用来初始化数组。
            而且我翻看了这些jar的后续版本对这个问题也没有做什么修改。那就这样吧,希望能帮到有缘人。

    相关文章

      网友评论

        本文标题:踩坑记录-maxHttpHeaderSize配置-内存都去哪儿

        本文链接:https://www.haomeiwen.com/subject/yckinhtx.html