快捷導(dǎo)航

一次OOM問題排查過程實(shí)戰(zhàn)記錄

更新時(shí)間：2019年05月02日 10:51:47 作者：lovecindywang

這篇文章主要給大家介紹了一次OOM問題排查過程，文中通過示例代碼介紹的非常詳細(xì)，對(duì)大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價(jià)值，需要的朋友們下面來一起學(xué)習(xí)學(xué)習(xí)吧

上周運(yùn)維反饋線上程序出現(xiàn)了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

看線程名稱應(yīng)該是tomcat的nio工作線程，線程在處理程序的時(shí)候因?yàn)闊o法在堆中分配更多內(nèi)存出現(xiàn)了OOM，幸好JVM啟動(dòng)參數(shù)配置了-XX:+HeapDumpOnOutOfMemoryError，使用MAT打開拿到的hprof文件進(jìn)行分析。

第一步就是打開Histogram看看占用內(nèi)存最大的是什么對(duì)象：

可以看到byte數(shù)組占用了接近JVM配置的最大堆的大小也就是8GB，顯然這是OOM的原因。

第二步看一下究竟是哪些byte數(shù)組，數(shù)組是啥內(nèi)容：

可以看到很明顯這和HTTP請(qǐng)求相關(guān)，一個(gè)數(shù)組大概是10M的大小。

第三步通過查看GC根查看誰持有了數(shù)組的引用：

這符合之前的猜測(cè)，是tomcat的線程在處理過程中分配了10M的buffer在堆上。至此，馬上可以想到一定是什么參數(shù)設(shè)置的不合理導(dǎo)致了這種情況，一般而言tomcat不可能為每一個(gè)請(qǐng)求分配如此大的buffer。

第四步就是檢查代碼里是否有tomcat或服務(wù)器相關(guān)配置，看到有這么一個(gè)配置：

max-http-header-size: 10000000

至此，基本已經(jīng)確定了八九不離十就是這個(gè)不合理的最大http請(qǐng)求頭參數(shù)導(dǎo)致的問題。

到這里還有3個(gè)疑問：

即使一個(gè)請(qǐng)求分配10M內(nèi)存，堆有8GB，難道當(dāng)時(shí)有這么多并發(fā)嗎？800個(gè)tomcat線程？
參數(shù)只是設(shè)置了最大請(qǐng)求頭10M，為什么tomcat就會(huì)一次性分配這么大的buffer呢？
為什么會(huì)有如此多的tomcat線程？感覺程序沒這么多并發(fā)。

先來看問題1，這個(gè)可以通過MAT在dump中繼續(xù)尋找答案。

可以打開線程視圖，搜索一下tomcat的工作線程，發(fā)現(xiàn)線程數(shù)量的確很多有401個(gè)，但是也只是800的一半：

再回到那些大數(shù)組的清單，按照堆分配大小排序，往下看：

可以發(fā)現(xiàn)除了有10008192字節(jié)的數(shù)組還有10000000字節(jié)的數(shù)組，查看引用路徑可以看到這個(gè)正好是10M的數(shù)組是output buffer，區(qū)別于之前看到的input buffer：

好吧，這就對(duì)了，一個(gè)線程分配了輸入輸出兩個(gè)buffer，占用20M內(nèi)存，一共401個(gè)線程，占用8GB，所以O(shè)OM了。
還引申出一個(gè)問題為啥有這么多工作線程，

再來看看問題2，這就需要來找一下源碼了，首先max-http-header-size是springboot定義的參數(shù)，查看springboot代碼可以看到這個(gè)參數(shù)對(duì)于tomcat設(shè)置的是MaxHttpHeaderSize：

然后來看看tomcat源碼：

進(jìn)一步看一下input buffer：

buffer大小是MaxHttpHeaderSize+ReadBuffer大小，這個(gè)默認(rèn)是8192字節(jié)：

 <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字節(jié)的。至于為什么分配的buffer需要是MaxHttpHeaderSize+ReadBuffer。顯然還有一批內(nèi)容是空的10000000字節(jié)的buffer應(yīng)該是output buffer，源碼可以印證這點(diǎn)：

嗯這是一個(gè)header buffer，所以正好是10000000字節(jié)。

至于問題3，顯然我們的應(yīng)用程序是配置過最大線程的（查看配置后發(fā)現(xiàn)的確，我們配置為了2000，好吧有點(diǎn)大），否則也不會(huì)有401個(gè)工作線程（默認(rèn)150），如果當(dāng)時(shí)并發(fā)并不大的話就一種可能，請(qǐng)求很慢，雖然并發(fā)不大，但是因?yàn)檎?qǐng)求執(zhí)行的慢就需要更多線程，比如TPS是100，但是平均RT是4s的話，就是400線程了。這個(gè)問題的答案還是可以通過MAT去找，隨便看幾個(gè)線程可以發(fā)現(xiàn)很多線程都在等待一個(gè)外部服務(wù)的返回，這說明外部服務(wù)比較慢，去搜索當(dāng)時(shí)的程序日志可以發(fā)現(xiàn)有很多"feign.RetryableException: Read timed out executing的日志"。。。。追殺下游去！慢點(diǎn)，我們的feign的timeout也需要再去設(shè)置一下，別被外部服務(wù)拖死了。

總結(jié)

以上就是這篇文章的全部?jī)?nèi)容了，希望本文的內(nèi)容對(duì)大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價(jià)值，謝謝大家對(duì)腳本之家的支持。

您可能感興趣的文章: