一次gc異常排查

近期公司公網(wǎng)接口被頻發(fā)攻擊刷垃圾數(shù)據(jù)，某些不常用接口一晚上被刷了幾十萬次，此背景下接口項(xiàng)目頻繁出現(xiàn)OOM的情況，主要表現(xiàn)如下圖：


gc異常.png

如圖所示，每次fgc都無法回收內(nèi)存，很明顯項(xiàng)目代碼中有內(nèi)存泄漏的情況存在，只能重啟項(xiàng)目臨時(shí)救急。隨后看近期代碼變動(dòng)記錄也未發(fā)現(xiàn)明顯問題，只得讓運(yùn)維協(xié)助導(dǎo)出內(nèi)存dump來分析具體原因了。

分析問題前先明確下內(nèi)存異常的概念：
內(nèi)存溢出 out of memory，是指程序在申請(qǐng)內(nèi)存時(shí)，沒有足夠的內(nèi)存空間供其使用，出現(xiàn)out of memory；
內(nèi)存泄露 memory leak，是指程序在申請(qǐng)內(nèi)存后，無法釋放已申請(qǐng)的內(nèi)存空間，一次內(nèi)存泄露危害可以忽略，但內(nèi)存泄露堆積后果很嚴(yán)重，無論多少內(nèi)存,遲早會(huì)被占光。
memory leak最終會(huì)導(dǎo)致out of memory！

第一次排查

第一次導(dǎo)出使用的命令是jmap -dump:format=b,file=heap.bin <pid>。沒有選在內(nèi)存占用最高的時(shí)候?qū)С?，所以文件只?G多大小，這不會(huì)影響實(shí)例占用內(nèi)存的比例情況因?yàn)閷?duì)象占用是逐漸遞增成比例的。不過這個(gè)命令有個(gè)問題就是導(dǎo)出的內(nèi)存不是fullgc以后的內(nèi)存情況，因?yàn)閮?nèi)存溢出的出現(xiàn)是fullgc后無法回收的那些對(duì)象有問題，當(dāng)時(shí)心知這個(gè)命令會(huì)有問題但是當(dāng)時(shí)文件已經(jīng)導(dǎo)出不想太麻煩運(yùn)維再導(dǎo)一次也就沒有太在意，事實(shí)證明嫌麻煩的后果就是事情會(huì)變得更麻煩了。

  1. 拿到dump文件后使用jdk中自帶的jvisualvm進(jìn)行分析，單看內(nèi)存占用情況如下：


    內(nèi)存類信息.png

  2. 內(nèi)存中hashMap對(duì)象實(shí)例數(shù)最多且占用內(nèi)存也是最多的，我們雙擊map對(duì)象查看詳情，一般這種實(shí)例數(shù)較多的我們很容易就能找到問題對(duì)象，如下圖所示，通過查看多個(gè)對(duì)象實(shí)例發(fā)現(xiàn)key是X509CertImpl的Map對(duì)象有很多，我們點(diǎn)擊查看垃圾回收根結(jié)點(diǎn)查看


    最近的垃圾回收節(jié)點(diǎn).png

  3. 查看根結(jié)點(diǎn)后會(huì)把對(duì)象調(diào)用路徑完整的展示出來，我們把根路徑復(fù)制出來看看具體是哪些調(diào)用。如下圖點(diǎn)擊復(fù)制從根開始的路徑


    復(fù)制從根開始的路徑.png
  1. 最后得到如下的一個(gè)完整路徑，發(fā)現(xiàn)是阿里云 oss的引用，初步發(fā)現(xiàn)問題后就結(jié)合項(xiàng)目代碼一起比對(duì)檢查。
this     - value: java.util.HashMap$Node #335002
 <- [22]     - class: java.util.HashMap$Node[], value: java.util.HashMap$Node #335002
  <- table     - class: java.util.HashMap, value: java.util.HashMap$Node[] #28817
   <- map     - class: java.util.HashSet, value: java.util.HashMap #32007
    <- trustedCerts     - class: sun.security.ssl.X509TrustManagerImpl, value: java.util.HashSet #12745
     <- trustManager     - class: org.apache.http.ssl.SSLContextBuilder$TrustManagerDelegate, value: sun.security.ssl.X509TrustManagerImpl #2346
      <- tm     - class: sun.security.ssl.AbstractTrustManagerWrapper, value: org.apache.http.ssl.SSLContextBuilder$TrustManagerDelegate #2357
       <- trustManager     - class: sun.security.ssl.SSLContextImpl$TLSContext, value: sun.security.ssl.AbstractTrustManagerWrapper #2358
        <- context     - class: sun.security.ssl.SSLSocketFactoryImpl, value: sun.security.ssl.SSLContextImpl$TLSContext #2343
         <- socketfactory     - class: org.apache.http.conn.ssl.SSLConnectionSocketFactory, value: sun.security.ssl.SSLSocketFactoryImpl #2363
          <- val     - class: java.util.concurrent.ConcurrentHashMap$Node, value: org.apache.http.conn.ssl.SSLConnectionSocketFactory #2345
           <- [11]     - class: java.util.concurrent.ConcurrentHashMap$Node[], value: java.util.concurrent.ConcurrentHashMap$Node #162146
            <- table     - class: java.util.concurrent.ConcurrentHashMap, value: java.util.concurrent.ConcurrentHashMap$Node[] #13097
             <- map     - class: org.apache.http.config.Registry, value: java.util.concurrent.ConcurrentHashMap #22642
              <- socketFactoryRegistry     - class: org.apache.http.impl.conn.DefaultHttpClientConnectionOperator, value: org.apache.http.config.Registry #7070
               <- connectionOperator     - class: org.apache.http.impl.conn.PoolingHttpClientConnectionManager, value: org.apache.http.impl.conn.DefaultHttpClientConnectionOperator #2345
                <- [2073]     - class: java.lang.Object[], value: org.apache.http.impl.conn.PoolingHttpClientConnectionManager #2342
                 <- elementData     - class: java.util.ArrayList, value: java.lang.Object[] #156896
                  <- connectionManagers     - class: com.aliyun.oss.common.comm.IdleConnectionReaper, value: java.util.ArrayList #74889
                   <- <class> (thread object)     - class: com.aliyun.oss.common.comm.IdleConnectionReaper, value: com.aliyun.oss.common.comm.IdleConnectionReaper class IdleConnectionReaper
  1. 排查代碼發(fā)現(xiàn)項(xiàng)目中上傳頭像的功能使用到了oss，代碼如下
    public static boolean fileUploadToOSS(InputStream uploadFilePath, String objectKey){
        URL url = null;
        // 使用默認(rèn)的OSS服務(wù)器地址創(chuàng)建OSSClient對(duì)象,不叫OSS_ENDPOINT代表使用杭州節(jié)點(diǎn)，青島節(jié)點(diǎn)要加上不然包異常
        OSSClient client = new OSSClient(OSSConfigure.getInstance().getOssEndPoint()
                , OSSConfigure.getInstance().getAccessId(), OSSConfigure.getInstance().getAccessKey());
        try {
            ObjectMetadata objectMeta = new ObjectMetadata();
            objectMeta.setCacheControl("no-cache");
            objectMeta.setHeader("Pragma", "no-cache");
            objectMeta.setContentEncoding("utf-8");
            objectMeta.setContentType("image/png");
            client.putObject(bucketName, Objectkey, file, objectMeta);
            return true;
        } catch (FileNotFoundException e) {
            log.error("文件圖片OSS上傳失??！", e);
        }
        return false;
    }
  1. 代碼中發(fā)現(xiàn)每次上傳頭像都會(huì)new一個(gè)新的OssClient，而且圖片上傳完之后還沒有手動(dòng)關(guān)閉鏈接，并且圖片流也沒有進(jìn)行關(guān)閉，另一個(gè)關(guān)鍵點(diǎn)是導(dǎo)出這個(gè)dump那段時(shí)間上傳頭像的接口正在被刷，OssClient的對(duì)象創(chuàng)建了很多并且沒有關(guān)閉，種種跡象告訴我這肯定是問題的根源。
    正確的使用方式參考：https://bbs.aliyun.com/simple/t257085.html，
    其他人也有同樣的問題：https://blog.csdn.net/ashur619/article/details/82835662，這個(gè)情況和我們極相似。

最后修改完代碼并上線，自此我天真的以為問題已經(jīng)得到了徹底解決，但是沒有過幾天同樣的問題又出現(xiàn)了，當(dāng)時(shí)感覺滿腦子問號(hào)??
?.png

沒辦法問題來了就接著找吧 !

第二次排查

  1. 因?yàn)橹笆褂玫膉map命令有問題這次加個(gè)histo:live參數(shù)，完整命令jmap -dump:format=b,live,file=heap.bin <pid>,這個(gè)命令會(huì)執(zhí)行一次fgc，并導(dǎo)出gc后的內(nèi)存情況，并且下載了mat來更清晰的解析dump文件。首次打開文件mat會(huì)生成自己的泄漏建議報(bào)告，我們可以打開看一下它提供的分析報(bào)告，選Leak Suspects Report點(diǎn)finish即可，分析后生成圖表和問題報(bào)告，problem a幾乎把1.6的內(nèi)存快占滿了，并且也準(zhǔn)確指出了問題出現(xiàn)在哪
    The memory is accumulated in one instance of com.alibaba.fastjson.util.IdentityHashMap$Entry[]

    report.png

  2. 點(diǎn)擊details進(jìn)去后查看具體情況，我們發(fā)現(xiàn)對(duì)象ParseConfig占用了93%的內(nèi)存空間，而ParseConfig下引用了N多個(gè)fastjson自定義的IdentityHashMap


    image.png

  3. 我們?cè)倏聪聝?nèi)存空間中整體的對(duì)象實(shí)例情況，到overview頁面點(diǎn)histogram查看實(shí)例直方圖如下：


    image.png

  4. ParserConfig只有一個(gè)實(shí)例 ，我們結(jié)合fastjson源碼看下這個(gè)ParserConfig和IdentityHashMap的具體關(guān)系


    image.png

  5. ParseConfig是一個(gè)單例，IdentityHashMap是用來存放json對(duì)象反序列化器的，并且key是一個(gè)反射類Type類型，我們?cè)倏聪聻槭裁磿?huì)存放這么多的反序列化器呢，因?yàn)樵瓌t上一種類型的對(duì)象（一種Type對(duì)象）只需要一個(gè)反序列化器就可以了。下面我們看下這個(gè)deserializers里都存了哪些對(duì)象,點(diǎn)擊ParserConfig對(duì)象java Basics Open In Dominator Tree,查看依賴樹


    image.png

  6. 打開后如下，分析發(fā)現(xiàn)IdentityHashMap的key是一個(gè)gson的對(duì)象，而需要反序列化的類是我們項(xiàng)目中自定義的，我又打開了其他的IdentityHashMap發(fā)現(xiàn)里面的結(jié)構(gòu)和反序列化對(duì)象都是一樣的，同對(duì)象為什么會(huì)生成如此多個(gè)反序列化器呢，Map存了這么多對(duì)象說明map的key都是不一樣的，因?yàn)閙ap的key是不能重復(fù)的，IdentityHashMap同樣也是，再查看了這些IdentityHashMap的key發(fā)現(xiàn)每個(gè)key的類型都是ParameterizedTypeImpl，但是內(nèi)存地址值都是不一樣的，說明key每次都是new的一個(gè)新ParameterizedTypeImpl對(duì)象。


    image.png

  7. 再看了下IdentityHashMap的put方法，key是直接拿對(duì)象的hash值做運(yùn)算并存放到buckets指定坐標(biāo)上的，如此我們可以確定這跟key的生成是有關(guān)系的，我們結(jié)合上面查到的RespVipBaseDTO再看下key對(duì)象到底是怎么生成的，代碼中JSON.parseObject()的時(shí)候會(huì)到ParserConfig中按key尋找對(duì)應(yīng)的反序列化器，沒有的話就會(huì)新創(chuàng)建一個(gè)新的。

RespBaseDTO<RecommendContentDTO> result = 
JSON.parseObject(resultString, new TypeToken<RespVipBaseDTO<RecommendContentDTO>>() {}.getType());
  1. 如上代碼會(huì)用new TypeToken(){}.getType()當(dāng)作key去查找合適的反序列化器,那我們看下這個(gè)key是怎么生成的。這里只貼出創(chuàng)建時(shí)的代碼，如下代碼，我們發(fā)現(xiàn)ParameterizedTypeImpl都是通過new創(chuàng)建的，說明每次使用TypeToken時(shí)都會(huì)創(chuàng)建一個(gè)新的，這也是為什么IdentityHashMap越來越多的根本原因。
if (type instanceof ParameterizedType) {
      ParameterizedType p = (ParameterizedType) type;
      return new ParameterizedTypeImpl(p.getOwnerType(), p.getRawType(), p.getActualTypeArguments());
}
  1. 其實(shí)原因還是開發(fā)人員在使用json時(shí)串用了不同廠商的json工具，TypeToken是谷歌gson的類，使用的JSONObject卻是阿里fastjson的，正確的使用方法應(yīng)該是使用TypeReference，TypeReference.getType()時(shí)同樣會(huì)返回一個(gè)Type類型，但是這個(gè)Type類型是通過java反射獲取到的類的基本信息，以此Type作為key是不會(huì)有這樣的問題的：
BaseReqDTO<CommonReqDTO> baseReqDTO = parseRequest(request, new TypeReference<BaseReqDTO<CommonReqDTO>>() {}.getType());
  1. 可以簡單寫一些驗(yàn)證代碼做個(gè)簡單的驗(yàn)證，運(yùn)行后發(fā)現(xiàn)使用TypeToken創(chuàng)建Type會(huì)造成程序運(yùn)行緩慢并最終造成OOM異常，TypeToken換成TypeReference后沒有此問題出現(xiàn)：
        for(int i = 0;i < 1000000; i++){
            JSON.parseObject("\"userId\":\"213\"",
                    new TypeToken<RespVipBaseDTO<OqsChoicenessProducts>>() {
                    }.getType());
            MemoryMXBean memorymbean = ManagementFactory.getMemoryMXBean();
            MemoryUsage usage = memorymbean.getHeapMemoryUsage();
            if(i % 1000 == 0){
                System.out.println("第：" + i + "次");
                System.out.println("INIT HEAP: " + usage.getInit());
                System.out.println("MAX HEAP: " + usage.getMax());
                System.out.println("USE HEAP: " + usage.getUsed());
            }
            if(i% 50000 == 0){
                System.gc();
                System.out.println("第：" + i + "次");
                System.out.println("INIT HEAP: " + usage.getInit());
                System.out.println("MAX HEAP: " + usage.getMax());
                System.out.println("USE HEAP: " + usage.getUsed());
            }
        }

總結(jié)：

  1. 發(fā)現(xiàn)問題可以先看代碼最近是否有大的變動(dòng)，有沒有使用不合理的地方，結(jié)合系統(tǒng)最近情況作出判斷，沒發(fā)現(xiàn)明顯問題就果斷導(dǎo)dump文件開始做分析。
  2. 這次排查中看代碼的時(shí)間要比看dump分析的時(shí)間多得多，要單從分析工具中找到具體問題是不可能的，或者是因?yàn)槲疫€沒掌握到更深的使用方法。
  3. 代碼質(zhì)量問題亟待解決
最后編輯于 ：
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請(qǐng)聯(lián)系作者
【社區(qū)內(nèi)容提示】社區(qū)部分內(nèi)容疑似由AI輔助生成，瀏覽時(shí)請(qǐng)結(jié)合常識(shí)與多方信息審慎甄別。
平臺(tái)聲明：文章內(nèi)容（如有圖片或視頻亦包括在內(nèi)）由作者上傳并發(fā)布，文章內(nèi)容僅代表作者本人觀點(diǎn)，簡書系信息發(fā)布平臺(tái)，僅提供信息存儲(chǔ)服務(wù)。

友情鏈接更多精彩內(nèi)容