JVM 內存大對象監控和優化實踐

作者:

vivo 互聯網服務器團隊 - Liu Zhen、Ye Wenhao

服務器內存問題是影響應用程序性能和穩定性的重要因素之一,需要及時排查和優化。本文介紹了某核心服務內存問題排查與解決過程。首先在 JVM 與大對象優化上進行了有效的實踐,其次在故障轉移與大對象監控上提出了可靠的落地方案。最後,總結了內存優化需要考慮的其他問題。

一、問題描述

音樂業務中,core 服務主要提供歌曲、歌手等元數據與用戶資產查詢。隨着元數據與用戶資產查詢量的增長,一些 JVM 內存問題也逐漸顯露,例如 GC 頻繁、耗時長,在高峯期 RPC 調用超時等問題,導致業務核心功能受損。

圖 1 業務異常數量變化

二、分析與解決

通過對日誌,機器 CPU、內存等監控數據分析發現:

YGC 平均每分鐘次數 12 次,峯值爲 24 次,平均每次的耗時在 327 毫秒。FGC 平均每 10 分鐘 0.08 次,峯值 1 次,平均耗時 30 秒。可以看到 GC 問題較爲突出。

在問題期間,機器的 CPU 並沒有明顯的變化,但是堆內存出現較大異常。圖 2,黃色圓圈處,內存使用急速上升,FGC 變的頻繁,釋放的內存越來越少。

圖片

圖 2 老年代內存使用異常

因此,我們認爲業務功能異常是機器的內存問題導致的,需要對服務的內存做一次專項優化。

步驟 1  JVM 優化

以下是默認的 JVM 參數:

-Xms4096M -Xmx4096M -Xmn1024M -XX:MetaspaceSize=256M -Djava.security.egd=file:/dev/./urandom -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/data/{runuser}/logs/other

如果不指定垃圾收集器,那麼 JDK 8 默認採用的是 Parallel Scavenge(新生代) +Parallel Old(老年代),這種組合在多核 CPU 上充分利用多線程並行的優勢,提高垃圾回收的效率和吞吐量。但是,由於採用多線程並行方式,會造成一定的停頓時間,不適合對響應時間要求較高的應用程序。然而,core 這類的服務特點是對象數量多,生命週期短。在系統特點上,吞吐量較低,要求時延低。因此,默認的 JVM 參數並不適合 core 服務。

根據業務的特點和多次對照實驗,選擇瞭如下參數進行 JVM 優化(4 核 8G 的機器)。該參數將 young 區設爲原來的 1.5 倍,減少了進入老年代的對象數量。將垃圾回收器換成 ParNew+CMS,可以減少 YGC 的次數,降低停頓時間。此外還開啓了 CMSScavengeBeforeRemark,在 CMS 的重新標記階段進行一次 YGC,以減少重新標記的時間。

-Xms4096M -Xmx4096M -Xmn1536M -XX:MetaspaceSize=256M -XX:+UseConcMarkSweepGC -XX:+CMSScavengeBeforeRemark -Djava.security.egd=file:/dev/./urandom -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/data/{runuser}/logs/other

圖片

圖 3 JVM 優化前後的堆內存對比

優化後效果如圖 3,堆內存的使用明顯降低,但是 Dubbo 超時仍然存在。

我們推斷,在業務高峯期,該節點出現了大對象晉升到了老年代,導致內存使用迅速上升,並且大對象沒有被及時回收。那如何找到這個大對象及其產生的原因呢?爲了降低問題排查期間業務的損失,提出了臨時的故障轉移策略,儘量降低異常數量。

步驟 2  故障轉移策略

在 api 服務調用 core 服務出現異常時,將出現異常的機器 ip 上報給監控平臺。然後利用監控平臺的統計與告警能力,配置相應的告警規則與回調函數。當異常觸發告警,通過配置的回調函數將告警 ip 傳遞給 api 服務,此時 api 服務可以將 core 服務下的該 ip 對應的機器視爲 “故障”,進而通過自定義的故障轉移策略(實現 Dubbo 的 AbstractLoadBalance 抽象類,並且配置在項目),自動將該 ip 從提供者集羣中剔除,從而達到不去調用問題機器。圖 4 是整個措施的流程。在該措施上線前,每當有機器內存告警時,將會人工重啓該機器。

圖 4 故障轉移策略

步驟 3  大對象優化

大對象佔用了較多的內存,導致內存空間無法被有效利用,甚至造成 OOM(Out Of Memory)異常。在優化過程中,先是查看了異常期間的線程信息,然後對堆內存進行了分析,最終確定了大對象身份以及產生的接口。

(1) Dump Stack 查看線程

從監控平臺上 Dump Stack 文件,發現一定數量的如下線程調用。

Thread 5612: (state = IN_JAVA)
 - org.apache.dubbo.remoting.exchange.codec.ExchangeCodec.encodeResponse(org.apache.dubbo.remoting.Channel, org.apache.dubbo.remoting.buffer.ChannelBuffer, org.apache.dubbo.remoting.exchange.Response) @bci=11, line=282 (Compiled frame; information may be imprecise)
 - org.apache.dubbo.remoting.exchange.codec.ExchangeCodec.encode(org.apache.dubbo.remoting.Channel, org.apache.dubbo.remoting.buffer.ChannelBuffer, java.lang.Object) @bci=34, line=73 (Compiled frame)
 - org.apache.dubbo.rpc.protocol.dubbo.DubboCountCodec.encode(org.apache.dubbo.remoting.Channel, org.apache.dubbo.remoting.buffer.ChannelBuffer, java.lang.Object) @bci=7, line=40 (Compiled frame)
 - org.apache.dubbo.remoting.transport.netty4.NettyCodecAdapter$InternalEncoder.encode(io.netty.channel.ChannelHandlerContext, java.lang.Object, io.netty.buffer.ByteBuf) @bci=51, line=69 (Compiled frame)
 - io.netty.handler.codec.MessageToByteEncoder.write(io.netty.channel.ChannelHandlerContext, java.lang.Object, io.netty.channel.ChannelPromise) @bci=33, line=107 (Compiled frame)
 - io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(java.lang.Object, io.netty.channel.ChannelPromise) @bci=10, line=717 (Compiled frame)
 - io.netty.channel.AbstractChannelHandlerContext.invokeWrite(java.lang.Object, io.netty.channel.ChannelPromise) @bci=10, line=709 (Compiled frame)
...

state = IN_JAVA 表示 Java 虛擬機正在執行 Java 程序。從線程調用信息可以看到,Dubbo 正在調用 Netty,將輸出寫入到緩衝區。此時的響應可能是一個大對象,因而在對響應進行編碼、寫緩衝區時,需要耗費較長的時間,導致抓取到的此類線程較多。另外耗時長,也即是大對象存活時間長,導致 full gc 釋放的內存越來越小,空閒的堆內存變小,這又會加劇 full gc 次數。

這一系列的連鎖反應與圖 2 相吻合,那麼接下來的任務就是找到這個大對象。

(2)Dump Heap 查看內存

對 core 服務的堆內存進行了多次查看,其中比較有代表性的一次快照的大對象列表如下,

圖 5 core 服務的堆內存快照

整個 Netty 的 taskQueue 有 258MB。並且從圖中綠色方框處可以發現,單個的 Response 竟達到了 9M,紅色方框處,顯示了調用方的服務名以及 URI。

進一步排查,發現該接口會通過 core 服務查詢大量信息,至此基本排查清楚了大對象的身份以及產生原因。

(3)優化結果

在對接口進行優化後,整個 core 服務也出現了非常明顯的改進。YGC 全天總次數降低了 76.5%,高峯期累計耗時降低了 75.5%。FGC 三天才會發生一次,並且高峯期累計耗時降低了 90.1%。

圖 6 大對象優化後的 core 服務 GC 情況

儘管優化後,因內部異常導致獲取核心業務失敗的異常請求數顯著減少,但是依然存在。爲了找到最後這一點異常產生的原因,我們打算對 core 服務內存中的對象大小進行監控。

圖片

圖 7 系統內部異常導致核心業務失敗的異常請求數

步驟 4  無侵入式內存對象監控

Debug Dubbo 源碼的過程中,發現在網絡層,Dubbo 通過 encodeResponse 方法對響應進行編碼並寫入緩衝區,通過 checkPayload 方法去檢查響應的大小,當超過 payload 時,會拋出 ExceedPayloadLimitException 異常。在外層對異常進行了捕獲,重置 buffer 位置,而且如果是 ExceedPayloadLimitException 異常,重新發送一個空響應,這裏需要注意,空響應沒有原始的響應結果信息,源碼如下。

//org.apache.dubbo.remoting.exchange.codec.ExchangeCodec#encodeResponse
protected void encodeResponse(Channel channel, ChannelBuffer buffer, Response res) throws IOException {
    //...省略部分代碼
    try {
        //1、檢查響應大小是否超過 payload,如果超過,則拋出ExceedPayloadLimitException異常
        checkPayload(channel, len);
    } catch (Throwable t) {
        //2、重置buffer
        buffer.writerIndex(savedWriteIndex);
        //3、捕獲異常後,生成一個新的空響應
        Response r = new Response(res.getId(), res.getVersion());
        r.setStatus(Response.BAD_RESPONSE);
        //4、ExceedPayloadLimitException異常,將生成的空響應重新發送一遍
        if (t instanceof ExceedPayloadLimitException) {
            r.setErrorMessage(t.getMessage());
            channel.send(r);
            return;
        }
    }
}
//org.apache.dubbo.remoting.transport.AbstractCodec#checkPayload
protected static void checkPayload(Channel channel, long size) throws IOException {
    int payload = getPayload(channel);
    boolean overPayload = isOverPayload(payload, size);
    if (overPayload) {
        ExceedPayloadLimitException e = new ExceedPayloadLimitException("Data length too large: " + size + ", max payload: " + payload + ", channel: " + channel);
        logger.error(e);
        throw e;
    }
}

受此啓發,自定義了編解碼類(實現 org.apache.dubbo.remoting.Codec2 接口,並且配置在項目),去監控超出閾值的對象,並打印請求的詳細信息,方便排查問題。在具體實現中,如果特意去計算每個對象的大小,那麼勢必是對服務性能造成影響。經過分析,採取了和 checkPayload 一樣的方式,根據編碼前後 buffer 的 writerIndex 位置去判斷有沒有超過設定的閾值。代碼如下。

/**
 * 自定義dubbo編碼類
 **/
public class MusicDubboCountCodec implements Codec2 {
    /**
     * 異常響應池:緩存超過payload大小的responseId
     */
    private static Cache<Long, String> EXCEED_PAYLOAD_LIMIT_CACHE = Caffeine.newBuilder()
        // 緩存總條數
        .maximumSize(100)
        // 過期時間
        .expireAfterWrite(300, TimeUnit.SECONDS)
        // 將value設置爲軟引用,在OOM前直接淘汰
        .softValues()
        .build();
    @Override
    public void encode(Channel channel, ChannelBuffer buffer, Object message) throws IOException {
        //1、記錄數據編碼前的buffer位置
        int writeBefore = null == buffer ? 0 : buffer.writerIndex();
        //2、調用原始的編碼方法
        dubboCountCodec.encode(channel, buffer, message);
        //3、檢查&記錄超過payload的信息
        checkOverPayload(message);
        //4、計算對象長度
        int writeAfter = null == buffer ? 0 : buffer.writerIndex();    
        int length = writeAfter - writeBefore;
        //5、超過告警閾值,進行日誌打印處理
        warningLengthTooLong(length, message);
    }
    //校驗response是否超過payload,超過了,緩存id
    private void checkOverPayload(Object message){
        if(!(message instanceof Response)){
            return;
        }
        Response response = (Response) message;
        //3.1、新的發送過程:通過狀態碼BAD_RESPONSE與錯誤信息識別出空響應,並記錄響應id
        if(Response.BAD_RESPONSE == response.getStatus() && StrUtil.contains(response.getErrorMessage(), OVER_PAYLOAD_ERROR_MESSAGE)){          
            EXCEED_PAYLOAD_LIMIT_CACHE.put(response.getId(), response.getErrorMessage());
            return;
        }
        //3.2、原先的發送過程:通過異常池識別出超過payload的響應,打印有用的信息
        if(Response.OK == response.getStatus() &&  EXCEED_PAYLOAD_LIMIT_CACHE.getIfPresent(response.getId()) != null){      
            String responseMessage = getResponseMessage(response);
            log.warn("dubbo序列化對象大小超過payload,errorMsg is {},response is {}", EXCEED_PAYLOAD_LIMIT_CACHE.getIfPresent(response.getId()),responseMessage);
        }
    }
}

在上文中提到,當捕獲到超過 payload 的異常時,會重新生成空響應,導致失去了原始的響應結果,此時再去打印日誌,是無法獲取到調用方法和入參的,但是 encodeResponse 方法步驟 4 中,重新發送這個 Response,給了我們機會去獲取到想要的信息,因爲重新發送意味着會再去走一遍自定義的編碼類。

假設有一個超出 payload 的請求,執行到自定編碼類 encode 方法的步驟 2(Dubbo 源碼中的編碼方法),在這裏會調用 encodeResponse 方法重置 buffer,發送新的空響應。

(1)當這個新的空響應再次進入自定義 encode 方法,執行 checkOverPayload 方法的步驟 3.1 時,就會記錄異常響應的 id 到本地緩存。由於在 encodeResponse 中 buffer 被重置,無法計算對象的大小,所以步驟 4、5 不會起到實際作用,就此結束新的發送過程。

(2)原先的發送過程回到步驟 2 繼續執行,到了步驟 3.2 時,發現本地緩存的異常池中有當前的響應 id,這時就可以打印調用信息了。

綜上,對於大小在告警閾值和 payload 之間的對象,由於響應信息成功寫入了 buffer,可以直接進行大小判斷,並且打印響應中的關鍵信息;對於超過 payload 的對象,在重新發送中記錄異常響應 id 到本地,在原始發送過程中訪問異常 id 池識別是否是異常響應,進行關鍵信息打印。

在監控措施上線後,通過日誌很快速的發現了一部分產生大對象的接口,當前也正在根據接口特點做針對性優化。

三、總結

在對服務 JVM 內存進行調優時,要充分利用日誌、監控工具、堆棧信息等,分析與定位問題。儘量降低問題排查期間的業務損失,引入對象監控手段也不能影響現有業務。除此之外,還可以在定時任務、代碼重構、緩存等方面進行優化。優化服務內存不僅僅是 JVM 調參,而是一個全方面的持續過程。

本文由 Readfog 進行 AMP 轉碼,版權歸原作者所有。
來源https://mp.weixin.qq.com/s/qfsY7fk_-rMdXPGYb766PA