記一次線上FGC問題排查

来源:https://www.cnblogs.com/gugujifly/archive/2023/01/31/17079852.html
-Advertisement-
Play Games

本文記錄一次線上 GC 問題的排查過程與思路,希望對各位讀者有所幫助。過程中也走了一些彎路,現在有時間沉澱下來思考並總結出來分享給大家,希望對大家今後排查線上 GC 問題有幫助。 ...


引言

本文記錄一次線上 GC 問題的排查過程與思路,希望對各位讀者有所幫助。過程中也走了一些彎路,現在有時間沉澱下來思考並總結出來分享給大家,希望對大家今後排查線上 GC 問題有幫助。

背景

服務新功能發版一周後下午,突然收到 CMS GC 告警,導致單台節點被拉出,隨後集群內每個節點先後都發生了一次 CMS GC,拉出後的節點垃圾回收後接入流量恢復正常(事後排查發現被重啟了)。

告警信息如下(已脫敏):

多個節點幾乎同時發生 GC 問題,且排查自然流量監控後發現並未有明顯增高,基本可以確定是有 GC 問題的,需要解決。

排查過程

GC 日誌排查

GC 問題首先排查的應該是 GC 日誌,日誌能能夠清晰的判定發生 GC 的那一刻是什麼導致的 GC,通過分析 GC 日誌,能夠清晰的得出 GC 哪一部分在出問題,如下是 GC 日誌示例:

0.514: [GC (Allocation Failure) [PSYoungGen: 4445K->1386K(28672K)] 168285K->165234K(200704K), 0.0036830 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
0.518: [Full GC (Ergonomics) [PSYoungGen: 1386K->0K(28672K)] [ParOldGen: 163848K->165101K(172032K)] 165234K->165101K(200704K), [Metaspace: 3509K->3509K(1056768K)], 0.0103061 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
0.528: [GC (Allocation Failure) [PSYoungGen: 0K->0K(28672K)] 165101K->165101K(200704K), 0.0019968 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
0.530: [Full GC (Allocation Failure) [PSYoungGen: 0K->0K(28672K)] [ParOldGen: 165101K->165082K(172032K)] 165101K->165082K(200704K), [Metaspace: 3509K->3509K(1056768K)], 0.0108352 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]

如上 GC 日誌能很明顯發現導致 Full GC 的問題是:Full GC 之後,新生代記憶體沒有變化,老年代記憶體使用從 165101K 降低到 165082K (幾乎沒有變化)。這個程式最後記憶體溢出了,因為沒有可用的堆記憶體創建 70m 的大對象。

但是,生產環境總是有奇奇怪怪的問題,由於服務部署在 K8s 容器,且運維有對服務心跳檢測,當程式觸發 Full GC 時,整個系統 Stop World,連續多次心跳檢測失敗,則判定為當前節點可能出故障(硬體、網路、BUG 等等問題),則直接拉出當前節點,並立即重建,此時之前列印的 GC 日誌都是在當前容器捲內,一旦重建,所有日誌全部丟失,也就無法通過 GC 日誌排查問題了。

JVM 監控埋點排查

上述 GC 日誌丟失問題基本無解,發生 GC 則立即重建,除非人為干預,否則很難拿到當時的 GC 日誌,且很難預知下次發生 GC 問題時間(如果能上報 GC 日子就不會有這樣的問題,事後發現有,但是我沒找到。。)。

此時,另一種辦法就是通過 JVM 埋點監控來排查問題。企業應用都會配備完備的 JVM 監控看板,就是為了能清晰明瞭的看到“事故現場”,通過監控,可以清楚的看到 JVM 內部在時間線上是如何分配記憶體及回收記憶體的。

JVM 監控用於監控重要的 JVM 指標,包括堆記憶體、非堆記憶體、直接緩衝區、記憶體映射緩衝區、GC 累計信息、線程數等。

主要關註的核心指標如下:

  • GC(垃圾收集)瞬時和累計詳情
    • FullGC 次數
    • YoungGC 次數
    • FullGC 耗時
    • YoungGC 耗時
  • 堆記憶體詳情
    • 堆記憶體總和
    • 堆記憶體老年代位元組數
    • 堆記憶體年輕代 Survivor 區位元組數
    • 堆記憶體年輕代 Eden 區位元組數
    • 已提交記憶體位元組數
  • 元空間元空間位元組數
  • 非堆記憶體
    • 非堆記憶體提交位元組數
    • 非堆記憶體初始位元組數
    • 非堆記憶體最大位元組數
  • 直接緩衝區
    • DirectBuffer 總大小(位元組)
    • DirectBuffer 使用大小(位元組)
  • JVM 線程數
    • 線程總數量
    • 死鎖線程數量
    • 新建線程數量
    • 阻塞線程數量
    • 可運行線程數量
    • 終結線程數量
    • 限時等待線程數量
    • 等待中線程數量

發生 GC 問題,重點關註的就是這幾個指標,大致就能圈定 GC 問題了。

堆記憶體排查

首先查看堆記憶體,確認是否有記憶體溢出(指無法申請足夠的記憶體導致),對內監控如下:

可以看到發生 Full GC 後,堆記憶體明顯降低了很多,但是在未發生大量 Full GC 後也有記憶體回收到和全量 GC 同等位置,所以可以斷定堆記憶體是可以正常回收的,不是導致大量 Full GC 的元凶。

非堆記憶體排查

非堆記憶體指 Metaspace 區域,監控埋點如下:

可以看到發生告警後,非堆記憶體瞬間回收很多(因為伺服器被健康檢查判定失效後重建,相當於重新啟動,JVM 重新初始化),此處如果有 GC 排查經驗的人一定能立即篤定,metaspace 是有問題的。

Metaspace 是用來幹嘛的?JDK8 的到來,JVM 不再有 PermGen(永久代),但類的元數據信息(metadata)還在,只不過不再是存儲在連續的堆空間上,而是移動到叫做 “Metaspace” 的本地記憶體(Native memory)中。

那麼何時會載入類信息呢?

  • 程式運行時:當運行 Java 程式時,該程式所需的類和方法。
  • 類被引用時:當程式首次引用某個類時,載入該類。
  • 反射:當使用反射 API 訪問某個類時,載入該類。
  • 動態代理:當使用動態代理創建代理對象時,載入該對象所需的類。

由上得出結論,如果一個服務內沒有大量的反射或者動態代理等類載入需求時,講道理,程式啟動後,類的載入數量應該是波動很小的(不排除一些異常堆棧反射時也會載入類導致增加),但是如上監控顯示,GC 後,metaspace 的記憶體使用量一直緩步增長,即程式內不停地製造“類”。

查看 JVM 載入類監控如下:

由上監控,確實是載入了大量的類,數量趨勢和非堆使用量趨勢吻合。

查看當前 JVM 設置的非堆記憶體大小如下:

MetaspaceSize & MaxMetaspaceSize = 1024 M,由上面非堆記憶體使用監控得出,使用量已接近 1000 M,無法在分配足夠的記憶體來載入類,最終導致發生 Full GC 問題。

程式代碼排查

由上面排查得出的結論:程式內在大量的創建類導致非堆記憶體被打爆。結合當前服務記憶體在大量使用 Groovy 動態腳本功能,大概率應該是創建腳本出了問題,腳本創建動態類代碼如下:

public static GroovyObject buildGroovyObject(String script) {
    GroovyClassLoader classLoader = new GroovyClassLoader();
    try {
        Class<?> groovyClass = classLoader.parseClass(script);
        GroovyObject groovyObject = (GroovyObject) groovyClass.newInstance();
        classLoader.clearCache();

        log.info("groovy buildScript success: {}", groovyObject);
        return groovyObject;
    } catch (Exception e) {
        throw new RuntimeException("buildScript error", e);
    } finally {
        try {
            classLoader.close();
        } catch (IOException e) {
            log.error("close GroovyClassLoader error", e);
        }
    }
}

線上打開日誌,確實證明瞭在不停的創建類。

腳本創建類導致堆記憶體被打爆,之間也是踩過坑的,針對同一個腳本(MD5 值相同),則會直接拿緩存,不會重覆創建類,緩存 check 邏輯如下:

public static GroovyObject buildScript(String scriptId, String script) {
    Validate.notEmpty(scriptId, "scriptId is empty");
    Validate.notEmpty(scriptId, "script is empty");

    // 嘗試緩存獲取
    String currScriptMD5 = DigestUtils.md5DigestAsHex(script.getBytes());
    if (GROOVY_OBJECT_CACHE_MAP.containsKey(scriptId)
            && currScriptMD5.equals(GROOVY_OBJECT_CACHE_MAP.get(scriptId).getScriptMD5())) {
        log.info("groovyObjectCache hit, scriptId: {}", scriptId);
        return GROOVY_OBJECT_CACHE_MAP.get(scriptId).getGroovyObject();
    }

    // 創建
    try {
        GroovyObject groovyObject = buildGroovyObject(script);

        // 塞入緩存
        GROOVY_OBJECT_CACHE_MAP.put(scriptId, GroovyCacheData.builder()
                .scriptMD5(currScriptMD5)
                .groovyObject(groovyObject)
                .build());
    } catch (Exception e) {
        throw new RuntimeException(String.format("scriptId: %s buildGroovyObject error", scriptId), e);
    }

    return GROOVY_OBJECT_CACHE_MAP.get(scriptId).getGroovyObject();
}

此處代碼邏輯在之前的測試中都是反覆驗證過的,不會存在問題,即只有緩存 Key 出問題導致了類的重覆載入。結合最近修改上線的邏輯,排查後發現,scriptId 存在重覆的可能,導致不同腳本,相同 scriptId 不停重覆載入(載入的頻次 10 分鐘更新一次,所以非堆使用緩慢上升)。

此處埋了一個小坑:載入的類使用 Map 存儲的,即同一個 cacheKey 調用 Map.put() 方法,重覆載入的類會被後面載入的類給替換掉,即之前載入的類已經不在被 Map 所“持有”,會被垃圾回收器回收掉,按理來說 Metaspace 不應該一直增長下去!?

提示:類載入與 Groovy 類載入、Metaspace 何時會被回收。

由於篇幅原因,本文就不在此處細究原因了,感興趣的朋友自行 Google 或者關註一下我,後續我再專門開一章詳解下原因。

總結

知其然知其所以然。

想要系統性地掌握 GC 問題處理方法,還是得瞭解 GC 的基礎:基礎概念、記憶體劃分、分配對象、收集對象、收集器等。掌握常用的分析 GC 問題的工具,如 gceasy.io 線上 GC 日誌分析工具,此處筆者參照了美團技術團隊文章 Java 中 9 種常見的 CMS GC 問題分析與解決 收益匪淺,推薦大家閱讀。

往期精彩

歡迎關註公眾號:咕咕雞技術專欄
個人技術博客:https://jifuwei.github.io/ >


您的分享是我們最大的動力!

-Advertisement-
Play Games
更多相關文章
  • 聲明:文章僅用於學習交流,切勿用於非法用途。 一、autojs版本 使用autojs版本4.1,其餘版本對微信、qq、抖音有限制。 下載地址:關註【產品經理不是經理】gzh,回覆【autojs】即可下載。 官方文檔:https://pro.autojs.org/docs/zh/v8/ 學習要點:熟悉 ...
  • 一、 為什麼要多線程 CPU和IO設備之間的速度存在很大的差異,提高CPU利用率 提高服務端併發量 線程安全問題: 有共用數據的情況下使用多線程可能會導致線程安全問題 原子性:時間片輪轉導致 可見性:CPU和記憶體之間有緩存/工作記憶體和主記憶體 有序性:指令重排序 實現線程安全的方法: 互斥同步:悲觀 ...
  • 程式設計基礎 基礎知識 什麼是程式? 為進行某項活動的步驟,電腦的程式,為得到某種結果,通過電腦語言表達的指令序列。 什麼是程式設計? 計算思維,是運用電腦科學的基礎概念進行問題求解,系統設計,以及人類行為理解等涵蓋電腦科學之廣度的一系列思維活動。 計算思維的特點: 1.滿足電腦程式執行的 ...
  • Gin框架實戰——HTML渲染 最近使用Go的Gin框架做了個簡單的前端網頁,記錄一下細節~ 1.載入靜態文件 由於網頁需要使用css、圖片等渲染,而靜態文件必須先聲明:否則模板中調用載入不出來,這個很重要,即使你把文件放到對應路徑下,html中也寫了相應的路徑,但是開啟go服務端的網頁,會顯示不出 ...
  • 1、shutil高級文件操作模塊 shutil模塊提供了大量的文件的高級操作。特別針對文件拷貝和刪除,主要功能為目錄和文件操作以及壓縮操作。對單個文件的操作也可參見os模塊。 2、shutil模塊的拷貝方法 >>> import shutil >>> shutil.chown('test.txt', ...
  • 一、DDS工作原理 以正弦信號為例,DDS大概就是將M個點的一個周期的正弦序列存入ROM中,序列數據的地址就是正弦信號的相位; 通過修改頻率控制字(Fword)來改變每隔多少個地址取ROM里的數據進行輸出。頻率控制字越大,從ROM取出的數據點就越少,點數越少,輸出一個周期信號的時間就越短,從而改變了 ...
  • 在做SpringBoot項目的過程中,有時客戶會提出按照指定時間執行一次業務的需求。 在單一使用ScheduledTaskRegistrar類解決定時任務問題的時候,可能會達不到預期的動態調整定時任務的效果。 ...
  • 概要 前端時間做尺規作圖相關的動畫的時候,封裝了一個圓規的動畫,順便研究了下 manim 庫的動畫函數。 manim 本身就是做動畫的庫,所以,基於它封裝自定義的動畫非常方便。 動畫原理 對於單個的元素,manim本身就提供了非常多的動畫函數。 比如:創建/消除的動畫,移動元素的動畫,旋轉元素的動畫 ...
一周排行
    -Advertisement-
    Play Games
  • 下麵是一個標準的IDistributedCache用例: public class SomeService(IDistributedCache cache) { public async Task<SomeInformation> GetSomeInformationAsync (string na ...
  • 這個庫提供了在啟動期間實例化已註冊的單例,而不是在首次使用它時實例化。 單例通常在首次使用時創建,這可能會導致響應傳入請求的延遲高於平時。在註冊時創建實例有助於防止第一次Request請求的SLA 以往我們要在註冊的時候實例單例可能會這樣寫: //註冊: services.AddSingleton< ...
  • 最近公司的很多項目都要改單點登錄了,不過大部分都還沒敲定,目前立刻要做的就只有一個比較老的項目 先改一個試試手,主要目標就是最短最快實現功能 首先因為要保留原登錄方式,所以頁面上的改動就是在原來登錄頁面下加一個SSO登錄入口 用超鏈接寫的入口,頁面改造後如下圖: 其中超鏈接的 href="Staff ...
  • Like運算符很好用,特別是它所提供的其中*、?這兩種通配符,在Windows文件系統和各類項目中運用非常廣泛。 但Like運算符僅在VB中支持,在C#中,如何實現呢? 以下是關於LikeString的四種實現方式,其中第四種為Regex正則表達式實現,且在.NET Standard 2.0及以上平... ...
  • 一:背景 1. 講故事 前些天有位朋友找到我,說他們的程式記憶體會偶發性暴漲,自己分析了下是非托管記憶體問題,讓我幫忙看下怎麼回事?哈哈,看到這個dump我還是非常有興趣的,居然還有這種游戲幣自助機類型的程式,下次去大玩家看看他們出幣的機器後端是不是C#寫的?由於dump是linux上的程式,剛好win ...
  • 前言 大家好,我是老馬。很高興遇到你。 我們為 java 開發者實現了 java 版本的 nginx https://github.com/houbb/nginx4j 如果你想知道 servlet 如何處理的,可以參考我的另一個項目: 手寫從零實現簡易版 tomcat minicat 手寫 ngin ...
  • 上一次的介紹,主要圍繞如何統一去捕獲異常,以及為每一種異常添加自己的Mapper實現,並且我們知道,當在ExceptionMapper中返回非200的Response,不支持application/json的響應類型,而是寫死的text/plain類型。 Filter為二方包異常手動捕獲 參考:ht ...
  • 大家好,我是R哥。 今天分享一個爽飛了的面試輔導 case: 這個杭州兄弟空窗期 1 個月+,面試了 6 家公司 0 Offer,不知道問題出在哪,難道是杭州的 IT 崩盤了麽? 報名面試輔導後,經過一個多月的輔導打磨,現在成功入職某上市公司,漲薪 30%+,955 工作制,不咋加班,還不捲。 其他 ...
  • 引入依賴 <!--Freemarker wls--> <dependency> <groupId>org.freemarker</groupId> <artifactId>freemarker</artifactId> <version>2.3.30</version> </dependency> ...
  • 你應如何運行程式 互動式命令模式 開始一個互動式會話 一般是在操作系統命令行下輸入python,且不帶任何參數 系統路徑 如果沒有設置系統的PATH環境變數來包括Python的安裝路徑,可能需要機器上Python可執行文件的完整路徑來代替python 運行的位置:代碼位置 不要輸入的內容:提示符和註 ...