問題系統(tǒng)

日常巡檢發(fā)現(xiàn)，應(yīng)用線上出現(xiàn)頻繁full gc

現(xiàn)象

應(yīng)用線上出現(xiàn)頻繁full gc

排查過程

分析dump

拉dump文件：小插曲：dump時如果指定:live，則在dump前jvm會先進行一次full gc，并且gc log里會打印dump full gc，這種對非內(nèi)存泄漏導(dǎo)致的線上異常內(nèi)存情況排查反而會帶來不便，導(dǎo)致我們多dump了好幾次。

分析dump文件：

a. 發(fā)現(xiàn)大量long[]數(shù)組占用最大空間，有異常情況

b. 查看gc根節(jié)點，發(fā)現(xiàn)這些long[]數(shù)據(jù)大部分是被org.HdrHistogram.Histogram持有，每個Histogram對象會持有一個2048size的long[]

c. 查看Histogram實例的數(shù)量，竟然有5w個，對比下正常項目的堆棧，大約是100倍

d. 這里又有一個插曲，一開始習(xí)慣用mat分析，但是mat生成的報告對分析泄露比較有用，對于分析異常的內(nèi)存沒有jvisualvm.exe和idea的profiler好用

排查原因

本地啟動，可以復(fù)現(xiàn)這個類的內(nèi)存使用情況，于是本地起一個其他內(nèi)存正常的服務(wù)與有問題的應(yīng)用，分析內(nèi)存對比

這里用的是idea的profiler，很方便

發(fā)現(xiàn)差異：

對比正常的應(yīng)用，發(fā)現(xiàn)異常應(yīng)用的引用存在異常的來自

● rx.internal.operators.OnSubscribeReduceSeed$ReduceSeedSubscriber的引用，懷疑就是這個異常引用就是導(dǎo)致這些實例無法在新生代回收而是堆積到了老年代觸發(fā)full gc的原因

排查差異：

簡單看了下相關(guān)代碼，看不出個所以然，直接debug對比

系統(tǒng)確實走進了相關(guān)的代碼，增加了對Histogram的引用，而正常應(yīng)用沒有

但是光這樣也看不出來為什么，此時關(guān)注到了左下角的線程池，這個線程池比較奇怪，是Metric的線程池
Metric是Hystrix用來統(tǒng)計相關(guān)指標(biāo)，來供自己的dashboard或者用戶來獲取，以此來了解系統(tǒng)熔斷相關(guān)參數(shù)和指標(biāo)的功能
再看堆棧，走到這里的邏輯是

這個流用來統(tǒng)計單位時間內(nèi)的系統(tǒng)指標(biāo)，導(dǎo)致Hystrix使用Histogram的long數(shù)組實現(xiàn)類似滑動窗口的效果統(tǒng)計單位時間內(nèi)的指標(biāo)
Histogram本身是Hystrix用來實現(xiàn)類似桶+滑動窗口的功能，來統(tǒng)計單位時間內(nèi)的流量，但是因為開啟了指標(biāo)參數(shù)，導(dǎo)致hystrix為了統(tǒng)計更長時間范圍內(nèi)的指標(biāo)，新增了對象持有更多（單位時間內(nèi)）的Histogram引用來聚合，這部分引用因為是統(tǒng)計更長時間范圍周期的，就會因為引用持有時間長而到老年代，但是本質(zhì)并不是內(nèi)存泄漏，所以每次full gc后又可以得到回收

解決問題

看到上面的差異和怪異的線程池，第一反應(yīng)就是關(guān)閉metric使應(yīng)用不走到這段邏輯中增加引用，看官方文檔，該配置默認(rèn)是打開的，并且確認(rèn)該功能只影響指標(biāo)統(tǒng)計不影響斷路器本身功能，使用配置hystrix.metrics.enabled=false配置來關(guān)閉
新增配置后，驗證并查看堆棧，引用恢復(fù)正常，并且系統(tǒng)在一段時間后并沒有新增更多的Histogram實例，發(fā)布線上后觀察一段時間，full gc問題確實得到解決

根本原因

在當(dāng)時發(fā)現(xiàn)解決的辦法并驗證后，并沒有時間去研究hystrix.metrics.enabled默認(rèn)配置就是true但是其他應(yīng)用沒有出現(xiàn)這個full gc問題的原因， 先解決了之后后續(xù)再繼續(xù)跟進排查根本原因防止其他項目也出現(xiàn)相同問題

之前發(fā)現(xiàn)可疑的線程池是HystrixMetricsPoller ，經(jīng)過查看，該線程池由HystrixMetricsPollerConfiguration

類開啟，主要依靠hystrix.metrics.enabled開啟，但是默認(rèn)是true，為什么其他項目沒有開啟呢？

搜了下源碼，這個類的開啟還和一個注解有關(guān)

對比了一下代碼，果然只有異常的應(yīng)用使用了這個注解，這個注解的目的是開啟斷路器

但是研究之后發(fā)現(xiàn)，不使用這個注解，熔斷等功能依舊可用，原因是在spring-cloud高版本之后，spring通過使用hystrix封裝openfeign的方法來使用熔斷，而不是集成整個hystrix體系，可能spring-cloud也發(fā)現(xiàn)了hystrix內(nèi)存使用上的問題

所以在較高版本（起碼我們的版本），feign是通過feign.hystrix.enabled來開關(guān)斷路器的（這個開關(guān)是關(guān)閉的話，單純加@EnableCircuitBreaker注解斷路器是不會生效的）

其實在更高點版本的spring-cloud中，@EnableCircuitBreaker這個注解已經(jīng)被標(biāo)注為廢棄了，但是可能因為我們是中間版本，所以存在既沒有標(biāo)注廢棄其實又沒有什么用的情況

總而言之，feign的斷路功能只通過feign.hystrix.enabled來控制，增加@EnableCircuitBreaker注解之后僅僅只是會開啟Hystrix其他所有的指標(biāo)等功能

問題總結(jié)

問題根本原因

本次問題產(chǎn)生的根本原因是因為開啟了@EnableCircuitBreaker注解，開啟了Hystrix指標(biāo)功能，導(dǎo)致Histogram實例大量進入老年代，只有full gc才可以回收
Histogram本身是Hystrix用來實現(xiàn)類似桶+滑動窗口的功能，來統(tǒng)計單位時間內(nèi)的流量，但是因為開啟了指標(biāo)參數(shù)，導(dǎo)致hystrix為了統(tǒng)計更長時間范圍內(nèi)的指標(biāo)，新增了對象持有更多（單位時間內(nèi)）的Histogram引用來聚合，這部分引用因為是統(tǒng)計更長時間范圍周期的，在訪問量上升新生代復(fù)制速度變快時，就會因為引用持有時間長而到老年代，但是本質(zhì)并不是內(nèi)存泄漏，所以每次full gc后又可以得到回收

后續(xù)關(guān)注點 Spring-Cloud本身體系比較復(fù)雜，因為和Netfilx套件糾纏不清加上很多歷史原因，能用明白某一個版本的就很不錯了 開發(fā)本身并不了解這個版本斷路器到底怎么開啟，沒有仔細(xì)看過對應(yīng)版本的官方文檔就去使用注解，在老版本，斷路器確實是通過這個注解才能啟用的 解決方式

關(guān)閉metric功能或者去掉@EnableCircuitBreaker注解均可解決
百度spring-cloud教程和文檔時，一定一定一定要看對應(yīng)版本的，否則可能加一堆配置解決某個問題，結(jié)果開啟一大堆亂七八糟的功能

到此這篇關(guān)于java內(nèi)存異常使用導(dǎo)致full gc頻繁的文章就介紹到這了,更多相關(guān)java內(nèi)存異常導(dǎo)致full gc頻繁內(nèi)容請搜索腳本之家以前的文章或繼續(xù)瀏覽下面的相關(guān)文章希望大家以后多多支持腳本之家！

最新評論