记一次OOM问题排查过程

上周运维反馈线上程序出现了OOM,程序日志中的输出为

Exception in thread "http-nio-8080-exec-1027" java.lang.OutOfMemoryError: Java heap space
Exception in thread "http-nio-8080-exec-1031" java.lang.OutOfMemoryError: Java heap space

看线程名称应该是tomcat的nio工作线程,线程在处理程序的时候因为无法在堆中分配更多内存出现了OOM,幸好JVM启动参数配置了-XX:+HeapDumpOnOutOfMemoryError,使用MAT打开拿到的hprof文件进行分析。

第一步就是打开Histogram看看占用内存最大的是什么对象:

可以看到byte数组占用了接近JVM配置的最大堆的大小也就是8GB,显然这是OOM的原因。 第二步看一下究竟是哪些byte数组,数组是啥内容:

可以看到很明显这和HTTP请求相关,一个数组大概是10M的大小。 第三步通过查看GC根查看谁持有了数组的引用:

这符合之前的猜测,是tomcat的线程在处理过程中分配了10M的buffer在堆上。至此,马上可以想到一定是什么参数设置的不合理导致了这种情况,一般而言tomcat不可能为每一个请求分配如此大的buffer。 第四步就是检查代码里是否有tomcat或服务器相关配置,看到有这么一个配置:

max-http-header-size: 10000000

至此,基本已经确定了八九不离十就是这个不合理的最大http请求头参数导致的问题。 到这里还有3个疑问:

  1. 即使一个请求分配10M内存,堆有8GB,难道当时有这么多并发吗?800个tomcat线程?
  2. 参数只是设置了最大请求头10M,为什么tomcat就会一次性分配这么大的buffer呢?
  3. 为什么会有如此多的tomcat线程?感觉程序没这么多并发。

先来看问题1,这个可以通过MAT在dump中继续寻找答案。 可以打开线程视图,搜索一下tomcat的工作线程,发现线程数量的确很多有401个,但是也只是800的一半:

再回到那些大数组的清单,按照堆分配大小排序,往下看:

可以发现除了有10008192字节的数组还有10000000字节的数组,查看引用路径可以看到这个正好是10M的数组是output buffer,区别于之前看到的input buffer:

好吧,这就对了,一个线程分配了输入输出两个buffer,占用20M内存,一共401个线程,占用8GB,所以OOM了。 还引申出一个问题为啥有这么多工作线程,

再来看看问题2,这就需要来找一下源码了,首先max-http-header-size是springboot定义的参数,查看springboot代码可以看到这个参数对于tomcat设置的是MaxHttpHeaderSize:

然后来看看tomcat源码:

进一步看一下input buffer:

buffer大小是MaxHttpHeaderSize+ReadBuffer大小,这个默认是8192字节:

   <attribute name="socket.appReadBufSize" required="false">
        <p>(int)Each connection that is opened up in Tomcat get associated with
        a read ByteBuffer. This attribute controls the size of this buffer. By
        default this read buffer is sized at <code>8192</code> bytes. For lower
        concurrency, you can increase this to buffer more data. For an extreme
        amount of keep alive connections, decrease this number or increase your
        heap size.</p>
      </attribute>

这也就是为什么之前看到大量的buffer是10008192字节的。至于为什么分配的buffer需要是MaxHttpHeaderSize+ReadBuffer。显然还有一批内容是空的10000000字节的buffer应该是output buffer,源码可以印证这点:

嗯这是一个header buffer,所以正好是10000000字节。

至于问题3,显然我们的应用程序是配置过最大线程的(查看配置后发现的确,我们配置为了2000,好吧有点大),否则也不会有401个工作线程(默认150),如果当时并发并不大的话就一种可能,请求很慢,虽然并发不大,但是因为请求执行的慢就需要更多线程,比如TPS是100,但是平均RT是4s的话,就是400线程了。这个问题的答案还是可以通过MAT去找,随便看几个线程可以发现很多线程都在等待一个外部服务的返回,这说明外部服务比较慢,去搜索当时的程序日志可以发现有很多"feign.RetryableException: Read timed out executing的日志"。。。。追杀下游去!慢点,我们的feign的timeout也需要再去设置一下,别被外部服务拖死了。

本文分享自微信公众号 - Java后端技术栈(t-j20120622)

原文出处及转载信息见文内详细说明,如有侵权,请联系 yunjia_community@tencent.com 删除。

原始发表时间:2019-09-09

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

发表于

我来说两句

0 条评论
登录 后参与评论

相关文章

来自专栏理想二旬不止

Servlet技术 【第二篇】入门还没有放弃

request是Servlet.service()方法的一个参数,在客户端发出每个请求时,服务器都会创建一个request对象,并把请求数据封装到request...

11330
来自专栏upuptop的专栏

【趣学程序】更换idea编辑器

配置JDK,保证下面两个地方的版本一致,不然启动会报错,最后一个选项配置项目的输出路径。

9420
来自专栏实战docker

IDEA的Docker插件实战(Docker Image篇)

本文是《IDEA的Docker插件实战》系列的第二篇,IDEA的Docker插件一共有三种:Dockerfile、Docker Image、Docker-com...

40120
来自专栏玩转JavaEE

说出来你可能不信,Spring Boot 中 Session 共享不超过 5 行代码!

在传统的单服务架构中,一般来说,只有一个服务器,那么不存在 Session 共享问题,但是在分布式/集群项目中,Session 共享则是一个必须面对的问题,先看...

9840
来自专栏Java3y

聊聊Docker镜像

在上篇也同样留下一个问题:我们知道Tomcat运行起来需要Java的支持,那么我们在DockerHub拉取下来的Tomcat镜像是不是也有Java环境呢?

8820
来自专栏Java研发军团

Tomcat中的类是怎么被一步步加载的?

之前实习的时候学习JavaMelody的源码,但是它是一个Maven的项目,与我们自己的Web项目整合后无法直接断点调试。后来同事指导,说是直接把Java类复制...

5310
来自专栏java技术大本营

tomcat学习|tomcat中组件结构设计

通过下图我们可以看到,在我们直接使用的Context,Service,Server上面还有一层接口: Container 和 Lifecycle

8540
来自专栏java技术大本营

tomcat学习|通过tomcat源码启动web项目

上一波,我们学习了tomcat 中主要接口的方法及关系: https://www.lixiang.red/articles/2019/08/12/1565622...

36120
来自专栏java技术大本营

tomcat学习|源码学习方法及tomcat处理Web请求

上一波,我们一起新建了web应用,然后把war包丢到tomcat源码中的webapps 目录,然后通过源码启动的方式成功debug运行了我们web应用,并且在浏...

10140
来自专栏白石

使用Eclipse来开发调试WebBuilder项目

​ 命名为WB8,然后在项目的右键菜单里,添加Groovy支持!如下图所示:

8330

扫码关注云+社区

领取腾讯云代金券

年度创作总结 领取年终奖励