上周运维反馈线上程序出现了 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 个疑问:
即使一个请求分配 10M 内存, 堆有 8GB, 难道当时有这么多并发吗? 800 个 tomcat 线程?
参数只是设置了最大请求头 10M, 为什么 tomcat 就会一次性分配这么大的 buffer 呢?
为什么会有如此多的 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 也需要再去设置一下, 别被外部服务拖死了.
来源: https://www.cnblogs.com/lovecindywang/p/10800593.html