記一次堆外內存泄漏排查過程

一、項目介紹

lz_rec_push_kafka_consume
該項目通過kafka與算法進行交互，通過push推薦平台（lz_rec_push_platform）預生成消息體。

二、問題背景

發現項目的k8s容器會出現重啟現象，重啟時間剛好是push擴量，每小時push數據量擴大5倍左右。
發生問題時，容器配置：CPU：4個，內存：堆內3G，堆外1G。

三、問題排查流程：望-聞-問-切

望：查看監控系統，觀察重啟發生時，容器實例的資源情況

注：容器重啟機制：k8s監控發現“實例”內存使用超過申請時，會對容器進行重啟。該動作是直接使用kill -9的，而非通過jvm指令對虛擬機進行重啟，所以此處別想dump堆。

一開始懷疑是內存，但是內存不足的話，應該是出現oom的情況。所以先排除堆內內存不足的問題。將實例內存擴大至：6G，堆內5G，堆外1G。發現重啟現象沒有絲毫改善。

聞：檢查項目的健康情況：線程、堆內內存使用、堆外內存使用。

1. 通過jstack、jstat二連，查看項目線程情況及垃圾回收情況，無線程突增情況，無fullGC及頻繁youngGC情況。

2. 通過top命令發現res使用比jstat命令顯示的堆大小大許多（忘了保留現場了），此時懷疑是堆外內存泄漏導致的。為了確定是堆外泄漏而非堆內，分析GC日志文件。

   • 借助easygc對GC日志進行分析：無fullGC情況（圖中四次fullGC為手動觸發測試的：jmap -histo:live ），且每次youngGC能正常回收對象。

3. 修改啟動腳本，將-Xmx參數和-Xms參數置為4G，且增加dump堆參數（-XX:+HeapDumpOnOutOfMemoryError  -XX:HeapDumpPath=/data/logs/  ），如果堆內發生oom則能拿到我們心心念念的堆文件進行分析。
   但是事與願違，容器多次發生重啟的時候，並沒有發生項目堆內oom，也就是說，並沒有dump下堆現場。此時更加確定，應該是堆外內存泄漏。

4. 配置堆外參數：-XX:MaxDirectMemorySize 用於限制堆外內存的使用，但是實例的內存使用還是膨脹到11G。網上的小伙伴都說這個參數可以用來限制堆外內存使用，難道是我沒用好。原本是想用這個參數來觸發堆外內存不足的錯誤，好驗證堆外內存泄漏這個方向。
   既然這個方向走不通，那就擴大堆外看看是否堆外的泄漏能否回收，還是永久泄漏。

5. 堆外內存泄漏一般由堆內對象引用（最常見由NIO引起，但是這次NIO表示不背鍋），且堆內引用無法被回收引起的（我猜的）。通過第四點圖，自然情況下的youngGC或者手動觸發fullGC后，垃圾回收都能試堆回到正常水平。此處判斷，泄漏的內存由可回收的引用所值向。
   那么問題來了，該部分引用在垃圾回收前就已經大量堆積，導致堆外內存空間不足，觸發k8s容器被kill。我猜的，接下來驗證這個想法。

   • 讓運維大佬將k8s實例調整到12G，因為每次重啟時，容器的內存占用幾乎穩定在11g左右。（好吧其實是運維大佬看容器一直重啟，主動要求擴容協助排查，贊一個）
   • 將堆內內存限制在7G，堆內使用6G，留給堆外盡可能大的空間。

6. 實例內存調整后，項目的三個實例在持續運行兩天過程中，沒有再出現重啟情況，且每次“預生成數據”后內存能正常回收。由此確定，泄漏的堆外內存是可回收的，而非永久泄漏，且在堆內引用被回收后即可完成回收。

7. 上圖為k8s實例資源監控圖，僅能體現容器資源情況，而非容器內項目的堆情況，該圖只能證明堆外內存能正常回收，而不是永久泄漏。既然不再重啟了，那么問題解決了，搞定走人？天真，一個節點12G，沒必要的浪費，運維大佬會殺人祭天的。
   通過jstat命令可觀察，且GC日志可以得出，堆內存使用基本可穩定在4G以內，沒必要浪費12G的空間。
   

問：目前需要解決的問題是找出堆外內存泄漏的原因。

1. 通過Google查找堆內存排查的文章：今咱們來聊聊JVM 堆外內存泄露的BUG是如何查找的    一次堆外內存泄露的排查過程
2. 借用arthas觀察，當Eden區膨脹到85%+的時候會進行一輪youngGC。所以盯着監控在Eden使用達到80%的時候將堆dump下來（jmap -dump:format=b,file=heap.hprof ）。

切：通過對分析工具對堆文件進行分析：JProfiler（后面會用到）、MemoryAnalyzer

1. 借助Memory Analyzer (MAT)工具將堆文件開。具體使用流程可自行百度，這里不細講。
   • 首先打開堆文件
     
   • 進入后看到對分析結果中出現三個明顯的錯誤，問題一跟問題二是由於引入了arthas導致的，直接跳過。
     
   • 看到第三個問題是否眼前一亮，小時候我們學java的時候就知道java.lang.ref.Finalizer是干嘛的，有興趣的可自行Google，也可看一下：JVM finalize實現原理與由此引發的血案
     

• java.lang.ref.Finalizer基本確定回收階段出現問題，進入搜索待回收的對象。此時我們不是糾結有多少對象沒有被回收，為什么沒有回收。而是這些沒有回收的對象是否由指向堆外內存。
  
  • 點開實例查看所屬類，此處看到這里出現3500+的未回收對象指向java.util.zip.ZipFile$ZipFileInflaterInputStream，趕緊Google發現還是有許多小伙伴碰到相同的問題，例如：Java壓縮流GZIPStream導致的內存泄露 。
    
  • 看到ZipFileInflaterInputStream馬上想起該壓縮在哪使用：push消息在預生成后存儲redis，批量生成后將消息進行壓縮再存儲，采用的正是zip壓縮，代碼示例如下：
    遺憾的是項目中使用的壓縮工具為jdk自帶的zip壓縮，有興趣的孩子可以了解一下基於Deflater 和 Inflater的zip壓縮。 （具體使用方法直接參照這兩個類上的示例注釋，應該是最權威的使用方式了）以下是本人在項目中的使用：

        byte[] input = log.getBytes();

        try (final ByteArrayOutputStream outputStream = new ByteArrayOutputStream(input.length)) {
            final Deflater compressor = new Deflater();
            compressor.setInput(input);
            compressor.finish();

            byte[] buffer = new byte[1024];
            int offset = 0;
            for (int length = compressor.deflate(buffer, offset, buffer.length); length > 0; length = compressor.deflate(buffer, offset, buffer.length)) {
                outputStream.write(buffer, 0, length);
                outputStream.flush();
            }
            //compressor.end();
            return Base64Utils.encodeToString(outputStream.toByteArray());
        }
    }

    public static String zipDecompress(final String str) throws Exception {

        byte[] input = Base64Utils.decodeFromString(str);

        try (final ByteArrayOutputStream byteArrayOutputStream = new ByteArrayOutputStream(input.length)) {

            final Inflater decompressor = new Inflater();
            decompressor.setInput(input);

            byte[] buffer = new byte[1024];
            for (int length = decompressor.inflate(buffer); length > 0 || !decompressor.finished(); length = decompressor.inflate(buffer)) {
                byteArrayOutputStream.write(buffer, 0, length);
            }
            //decompressor.end();
            return new String(byteArrayOutputStream.toByteArray());
        }
    }

1. 奇怪的是，壓縮與解壓縮的預發都是采用try with resource的格式進行編寫，講道理是會進行流關閉的。網上部分小伙伴推薦使用snapy代替zip，但是我就不~~還是要搞清楚為什么此處沒有在方法棧彈出之后馬上做資源回收。
2. 點擊進入Deflater的deflate方法或者Inflater的inflate方法可以發現，二者都是調用了“native”方法，詳細代碼請參照源碼。兩個工具類均持有end()方法，其注釋如下：

/**
     * Closes the compressor and discards any unprocessed input.
     * This method should be called when the compressor is no longer
     * being used, but will also be called automatically by the
     * finalize() method. Once this method is called, the behavior
     * of the Deflater object is undefined.
     */

3. 所以以上代碼中將注釋掉的兩行end()方法的調用放開即可（這兩行是鎖定問題后加上的）。end()方法在調用后即可對堆外使用的內存進行釋放，而不是等待jvm垃圾回收來臨之后，將引用回收時再間接使堆外的緩沖區回收。繼續翻看源碼，不難發現Deflater和Inflater確實重寫了finalize方法，而該方法的實現正是調用end方法，這就驗證了我們上面的猜想。眾所周知finalize方法會在對象被回收的時候被調用且只會被調用一次。所以在對象回收之前，被引用的堆外的空間是無法被回收的。

 /**
     * Closes the compressor and discards any unprocessed input.
     * This method should be called when the compressor is no longer
     * being used, but will also be called automatically by the
     * finalize() method. Once this method is called, the behavior
     * of the Deflater object is undefined.
     */
    public void end() {
        synchronized (zsRef) {
            long addr = zsRef.address();
            zsRef.clear();
            if (addr != 0) {
                end(addr);
                buf = null;
            }
        }
    }

    /**
     * Closes the compressor when garbage is collected.
     */
    protected void finalize() {
        end();
    }

4. 翻看redis的存儲空間，好吧即使是高峰期的數據也不是很多，是我考慮太多了。

思考：項目發生重啟是在kafka數據擴量后才出現的，那為何擴量前沒有這個問題的出現呢？其實問題一直是存在的，只是數據量小的情況下，引用都在垃圾回收后能正常釋放堆外內存。但是擴量后，瞬間的流量增高，產生大量的堆外內存使用引用。在下一次垃圾回收之前ReferenceQueue隊列已經堆積了大量的引用，將容器內的堆外內存撐爆。

葯：去除壓縮解壓縮動作

去除壓縮與解壓縮動作后，發版觀察。項目的k8s實例資源監控處在合理范圍。

至此，堆外內存問題已經解決了。

五、思考與復盤

問題：使用資源時，保持着資源使用后及時釋放的習慣。該問題便是由壓縮使用有誤引起的，應該也算是低級錯誤了。

由於第一次排查堆外內存泄漏的問題，沒有豐富的經驗去鎖定問題點達到快速排查，走了不着彎路。該文章略顯啰嗦，但是主要目的還是想記錄下排查問題的過程。第一次發博客，寫作思路上有點紊亂，請多多包涵。如果有什么措辭不當的，還望指出。有什么好的建議也希望能指點一二。