問題系統(tǒng)

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

現(xiàn)象

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

排查過程

分析dump

拉dump文件：小插曲：dump時如果指定:live，則在dump前jvm會先進行一次full gc，并且gc log里會打印dump full gc，這種對非內(nèi)存泄漏導致的線上異常內(nèi)存情況排查反而會帶來不便，導致我們多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. 這里又有一個插曲，一開始習慣用mat分析，但是mat生成的報告對分析泄露比較有用，對于分析異常的內(nèi)存沒有jvisualvm.exe和idea的profiler好用

排查原因

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

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

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

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

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

排查差異：

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

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

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

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

解決問題

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

根本原因

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

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

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

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

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

但是研究之后發(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)被標注為廢棄了，但是可能因為我們是中間版本，所以存在既沒有標注廢棄其實又沒有什么用的情況

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

問題總結(jié)

問題根本原因

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

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

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

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

最新評論