Java Crash分析

openkk 12年前發布 | 67K 次閱讀 Java

基于Oracle/Sun JDK與OpenJDK在Linux上的crash的幾個案例分析

Java Crash分析（2012-05-10）
View more PowerPoint from Kris Mok
</div>
  • 1. Kris Mok, Software Engineer, Taobao@rednaxelafx莫樞 /“撒迦”
  • 2. Java Crash分析 現象與對策 阿里巴巴集團-技術共享平臺- 核心系統研發-專用計算組 莫樞（撒迦） v0.1 2012-04-24 v0.2 2012-05-10
  • 3. 關于我…? 2009年畢業自南京大學軟件學院? 同年10月加入淘寶? 目前在淘寶核心系統部參與JVM相關研發? 編程語言的設計與實現愛好者? 希望與各位同好多交流！? – 博客：http://rednaxelafx.iteye.com/ – 新浪微博：http://weibo.com/rednaxelafx – 高級語言虛擬機群組：http://hllvm.group.iteye.com/ – JVM源碼閱讀活動微群：http://q.weibo.com/1823766
  • 4. JVM crash了！
  • 5. 真的是JVM crash了么…？
  • 6. 討論范圍? 表現為真的JVM crash的問題 – 實際原因可能是： ? JVM內部實現的bug ? native library的bug ? Java應用層代碼自身的bug ? native memory耗光了 ? 外部環境的影響? 遇到crash時的一些簡單可操作的處理辦法 – 篇幅所限，無法深入介紹；不能解決所有crash
  • 7. 非討論范圍? Java進程被人為kill掉 – 這是首先要檢查的情況 – 在多用戶共用的開發環境里特別容易出問題 ? 開發A要部署新代碼，重啟了服務器 ? 開發B正在用服務器做測試，發現進程突然消失了 ? 請協調好資源的使用
  • 8. 非討論范圍? Java應用失去響應 – 但并未crash，進程還在 – 有可能是 ? Java代碼陷入死循環 – 可參考例子 https://gist.github.com/1081908 ? 連續的GC – 可觀察GC日志或jstat -gccause ? 日志把磁盤打滿了 – 可用 df 觀察磁盤剩余空間 ? …等等 – 這次不詳細展開討論
  • 9. 非討論范圍? Java層面的異常 – Java級別的OutOfMemoryError – ClassNotFoundException – NoClassDefFoundError – StackOverflowError – NullPointerException – …其它異常 ? 可捕獲（已捕獲），并且進程還存在
  • 10. JVM Crash定義? Java進程意外消失? 通常伴隨著 – crash log：hs_err_pid<pid>.log（重要） – core dump: core.<pid> – 或系統日志 ? 主要是 /var/log/messages 里的異常信息
  • 11. # crash了# A fatal error has been detected by the Java Runtime Environment:## SIGSEGV (0xb) at pc=0x00002add2265d648, pid=2188, tid=1078282560## JRE version: 6.0_30-b12# Java VM: OpenJDK (Taobao) 64-Bit Server VM (20.0-b12-internal-fastdebugmixed mode linux-amd64 compressed oops)# Problematic frame:# V [libjvm.so+0xd05648] Unsafe_SetNativeInt+0xb8## An error report file with more information is saved as:# /home/sajia/hs_err_pid2188.log## If you would like to submit a bug report, please visit:# http://java.sun.com/webapps/bugreport/crash.jsp#Current thread is 1078282560Dumping core ...Aborted (core dumped) 有打出core dump， 位置通常在“當前工作目錄”
  • 12. # crash了但沒core dump# A fatal error has been detected by the Java Runtime Environment:## SIGSEGV (0xb) at pc=0x00002b4fb5a7a648, pid=20190, tid=1084868928## JRE version: 6.0_30-b12# Java VM: OpenJDK (Taobao) 64-Bit Server VM (20.0-b12-internal-fastdebugmixed mode linux-amd64 compressed oops)# Problematic frame:# V [libjvm.so+0xd05648] Unsafe_SetNativeInt+0xb8## An error report file with more information is saved as:# /home/sajia/hs_err_pid20190.log## If you would like to submit a bug report, please visit:# http://java.sun.com/webapps/bugreport/crash.jsp 沒打出core dump。# 如需要core dump，請確認：Current thread is 1084868928Dumping core ... 1、ulimit -c unlimitedAborted 2、該Java進程對“當前工作 目錄”有寫權限 3、磁盤剩余空間充足
  • 13. 被OOM Killer干掉了$ sudo cat /var/log/messages | grep -i "killed process"Aug 30 15:51:54 testmachine kernel: : Out of memory:Killed process 15605 (java). 這種情況下既不會有crash log也不會有core dump
  • 14. 事前準備Preparation
  • 15. 事前準備? 若要讓JVM在檢測到crash時執行外部命令 – 可使用 -XX:OnError=... – 其中可使用 %p 來指定pid – 例如： ? -XX:OnError=pstack %p > ~/pstack%p.log – 這樣指定的命令在執行時要從Java進程fork出 去，如果內存已經嚴重不足則無法成功fork ? 如發現指定的命令根本沒執行，請嘗試用后面提到 的-XX:+ShowMessageBoxOnError讓Java進程在退 出前先暫停，然后手動從外部執行需要的命令
  • 16. 事前準備? 若要讓JVM在檢測到crash后不立即退出， 而是提示打開調試器 – 可使用 -XX:+ShowMessageBoxOnError – 主要用于crash時的現場調試 – 通常不需要啟用 – 遇到很詭異的bug時可以靠該參數獲取更直接 的現場信息
  • 17. 事前準備? 為便于事后分析，最好能留下core dump – 注意 ulimit -c unlimited – 盡量在程序的當前工作目錄留出足夠磁盤空間 – 或配置core dump文件的路徑到合適的位置 ? kernel.core_uses_pid ? kernel.core_pattern ? 可在/etc/sysctl.conf文件中配置 ? 請參考文檔，例子1，例子2
  • 18. 保護現場Keep the Crash Site Intact
  • 19. 保護現場? 前面提到的crash相關日志、core dump都 盡量保持在原位置，或至少在事發機器上 – 如果磁盤空間不是特別緊張，別把它們刪了? 如果有core dump，最好保持程序運行時所 使用的可執行文件在原路徑上，如java、 libjvm.so、libc.so等 – 為便于事后分析，千萬別急于在卸載掉相關程 序（如JDK），或在原路徑覆蓋安裝新版本
  • 20. 急救措施First Aid
  • 21. 1. 觀察crash log? 最簡單的觀察方式： – 看文件開頭的錯誤概述 ? OutOfMemoryError？SIGSEGV？ EXCEPTION_ACCESS_VIOLATION？ ? 如果是訪問異常，異常的地址是？是不是空指針？ – 看出錯的線程名及其調用棧信息 ? 是JVM內部的線程還是應用的Java線程？ ? 執行到什么地方出的錯？ – 根據上面兩種信息總結出關鍵字 – 用Google搜一下bugs.sun.com或其它地方有沒 有類似的crash報告，有的話找出其說明 – 很可能是已知的VM bug或第三方庫的bug
  • 22. 1. 觀察crash log? 例： https://gist.github.com/2584513#file_java_error_28 522.short.log
  • 23. 1. 觀察crash log# A fatal error has been detected by the Java Runtime Environment:## SIGSEGV (0xb) at pc=0x00002aaf0d11c031, pid=28522, tid=1104951616 錯誤類型： SIGSEGV
  • 24. 1. 觀察crash log# A fatal error has been detected by the Java Runtime Environment:## SIGSEGV (0xb) at pc=0x00002aaf0d11c031, pid=28522, tid=1104951616 出錯時的程序指針的值： （該線程執行到哪里了？） 0x00002aaf0d11c031
  • 25. 1. 觀察crash log# A fatal error has been detected by the Java Runtime Environment:## SIGSEGV (0xb) at pc=0x00002aaf0d11c031, pid=28522, tid=1104951616 出錯的進程的ID： 28522
  • 26. 1. 觀察crash log# A fatal error has been detected by the Java Runtime Environment:## SIGSEGV (0xb) at pc=0x00002aaf0d11c031, pid=28522, tid=1104951616 這個可以忽略
  • 27. 1. 觀察crash log--------------- T H R E A D ---------------Current thread (0x0000000052109000): JavaThread "CompilerThread1"daemon [_thread_in_native, id=28538,stack(0x0000000041cc3000,0x0000000041dc4000)] 出錯的線程在HotSpot VM里的 C++層Thread對象的地址： 0x0000000052109000
  • 28. 1. 觀察crash log--------------- T H R E A D ---------------Current thread (0x0000000052109000): JavaThread "CompilerThread1"daemon [_thread_in_native, id=28538,stack(0x0000000041cc3000,0x0000000041dc4000)] 出錯的線程的類型： JavaThread
  • 29. 1. 觀察crash log--------------- T H R E A D ---------------Current thread (0x0000000052109000): JavaThread "CompilerThread1"daemon [_thread_in_native, id=28538,stack(0x0000000041cc3000,0x0000000041dc4000)] 出錯的線程的名字（如果有）： CompilerThread1
  • 30. 1. 觀察crash log--------------- T H R E A D ---------------Current thread (0x0000000052109000): JavaThread "CompilerThread1"daemon [_thread_in_native, id=28538,stack(0x0000000041cc3000,0x0000000041dc4000)] 出錯的線程的狀態： _thread_in_native
  • 31. 1. 觀察crash log--------------- T H R E A D ---------------Current thread (0x0000000052109000): JavaThread "CompilerThread1"daemon [_thread_in_native, id=28538,stack(0x0000000041cc3000,0x0000000041dc4000)] 出錯的線程的ID： 28538
  • 32. 1. 觀察crash log--------------- T H R E A D ---------------Current thread (0x0000000052109000): JavaThread "CompilerThread1"daemon [_thread_in_native, id=28538,stack(0x0000000041cc3000,0x0000000041dc4000)] 出錯的線程的調用棧 在內存中的地址范圍： (0x0000000041cc3000, 0x0000000041dc4000)
  • 33. 1. 觀察crash logsiginfo:si_signo=SIGSEGV: si_errno=0,si_code=1 (SEGV_MAPERR),si_addr=0x0000000000000008 錯誤類型： SIGSEGV
  • 34. 1. 觀察crash logsiginfo:si_signo=SIGSEGV: si_errno=0,si_code=1 (SEGV_MAPERR),si_addr=0x0000000000000008 錯誤子類型： SEGV_MAPERR
  • 35. 1. 觀察crash logsiginfo:si_signo=SIGSEGV: si_errno=0,si_code=1 (SEGV_MAPERR),si_addr=0x0000000000000008 錯誤地址（重要）： 0x0000000000000008 這是對空指針解引用的表現
  • 36. 1. 觀察crash logInstructions: (pc=0x00002aaf0d11c031)0x00002aaf0d11c021: 8b 97 e0 09 00 00 44 89 c7 48 8b 0c fa 49 89 d00x00002aaf0d11c031: 4c 8b 49 08 49 83 39 00 75 2b 8b 73 08 66 90 8b crash地點附近的代碼： （十六進制表示的機器碼） pc表示當前指令指針的值 淘寶JDK6u30開始直接在crash log 里顯示這部分代碼的反匯編
  • 37. 1. 觀察crash logStack: [0x0000000041cc3000,0x0000000041dc4000], sp=0x0000000041dbd480, freespace=1001kNative frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)V [libjvm.so+0x593031]V [libjvm.so+0x592cf2]V [libjvm.so+0x590001]V [libjvm.so+0x2d5bc2]V [libjvm.so+0x2d2cbc]V [libjvm.so+0x25b0de]V [libjvm.so+0x2dc468]V [libjvm.so+0x2dbd6e]V [libjvm.so+0x72d159]V [libjvm.so+0x7268c1]V [libjvm.so+0x623e1f] native級別的調用棧記錄 老JDK6上libjvm.so里的符號不會顯示， JDK6u25或更高版本則會顯示
  • 38. 1. 觀察crash log// First letter indicates type of the frame:// J: Java frame (compiled)// j: Java frame (interpreted)// V: VM frame (C/C++)// v: Other frames running VM generated code (e.g. stubs, adapters, etc.)// C: C/C++ frame
  • 39. 1. 觀察crash logStack: [0x0000000041cc3000,0x0000000041dc4000], sp=0x0000000041dbd480, freespace=1001kNative frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)V [libjvm.so+0x593031]V [libjvm.so+0x592cf2]V [libjvm.so+0x590001]V [libjvm.so+0x2d5bc2]V [libjvm.so+0x2d2cbc]V [libjvm.so+0x25b0de]V [libjvm.so+0x2dc468]V [libjvm.so+0x2dbd6e]V [libjvm.so+0x72d159]V [libjvm.so+0x7268c1]V [libjvm.so+0x623e1f] 有些crash log里， 后面還會有Java級別的棧幀
  • 40. 1. 觀察crash logCurrent CompileTask:C2:2554 !com.taobao.rate.ratesearch.RateSearchAdaptor.adaptRateDoToSchemaDO(Lcom/taobao/ratecenter/domain/dataobject/FeedRateDO;ZLjava/util/Set;)Lcom/taobao/rate/ratesearch/dataobject/RateSearchSchemaDO; (504 bytes) （編譯器線程） 當前正在編譯的Java方法的簽名
  • 41. 1. 觀察crash logCurrent CompileTask:C2:2554 !com.taobao.rate.ratesearch.RateSearchAdaptor.adaptRateDoToSchemaDO(Lcom/taobao/ratecenter/domain/dataobject/FeedRateDO;ZLjava/util/Set;)Lcom/taobao/rate/ratesearch/dataobject/RateSearchSchemaDO; (504 bytes) 編譯器類型： C1是Client Compiler C2是Server Compiler
  • 42. 1. 觀察crash logCurrent CompileTask:C2:2554 !com.taobao.rate.ratesearch.RateSearchAdaptor.adaptRateDoToSchemaDO(Lcom/taobao/ratecenter/domain/dataobject/FeedRateDO;ZLjava/util/Set;)Lcom/taobao/rate/ratesearch/dataobject/RateSearchSchemaDO; (504 bytes) 編譯任務的編號： 第2554個編譯任務
  • 43. 1. 觀察crash logCurrent CompileTask:C2:2554 !com.taobao.rate.ratesearch.RateSearchAdaptor.adaptRateDoToSchemaDO(Lcom/taobao/ratecenter/domain/dataobject/FeedRateDO;ZLjava/util/Set;)Lcom/taobao/rate/ratesearch/dataobject/RateSearchSchemaDO; (504 bytes) 該被編譯的方法里有異常處理代碼
  • 44. 1. 觀察crash logCurrent CompileTask:C2:2554 !com.taobao.rate.ratesearch.RateSearchAdaptor.adaptRateDoToSchemaDO(Lcom/taobao/ratecenter/domain/dataobject/FeedRateDO;ZLjava/util/Set;)Lcom/taobao/rate/ratesearch/dataobject/RateSearchSchemaDO; (504 bytes) 該被編譯的方法的字節碼大小： 504字節
  • 45. 1. 觀察crash log--------------- P R O C E S S ---------------Java Threads: ( => current thread ) ... 0x000000005210b800 JavaThread "Low Memory Detector" daemon [_thread_blocked, id=28539, stack(0x0000000041dc4000,0x0000000041ec5000)]=>0x0000000052109000 JavaThread "CompilerThread1" daemon [_thread_in_native, id=28538, stack(0x0000000041cc3000,0x0000000041dc4000)] 0x0000000052104000 JavaThread "CompilerThread0" daemon [_thread_blocked, id=28537, stack(0x0000000041bc2000,0x0000000041cc3000)] 0x0000000052102000 JavaThread "Signal Dispatcher" daemon [_thread_blocked, id=28536, stack(0x0000000040bec000,0x0000000040ced000)] 線程列表中=>表明當前線程
  • 46. 1. 觀察crash logtime: Mon Apr 9 21:44:28 2012elapsed time: 355 seconds 該進程啟動時刻： 2012-04-09 21:44:28
  • 47. 1. 觀察crash logtime: Mon Apr 9 21:44:28 2012elapsed time: 355 seconds 該進程運行時間長度： 355秒 可用于判斷程序運行階段，特別是程序重啟時區分新老進程
  • 48. 1. 觀察crash log? （續上例）? 只看crash log如何知道crash地點附近的代碼是 怎樣的？? 用udis庫里帶的udcli工具來反匯編 – echo <code> | udcli -intel -x -[32|64] -o <addr>? 使用例： https://gist.github.com/2584513#file_udcli_example.log? （如有core dump則直接用gdb的disassemble 命令更方便）
  • 49. 1. 觀察crash log? （續上例）? 看不到調用棧里libjvm.so的函數的符號信息怎么 辦？ – objdump -C -d --start-address=<addr> libjvm.so | egrep >:$ -m 1? 一個簡單的shell腳本來獲取crash log里 libjvm.so的函數的符號信息 – https://gist.github.com/2584416? 把符號信息放回到crash log里 – https://gist.github.com/2584513#file_java_error_28522.s hort.extra.log
  • 50. 1. 觀察crash log? （續上例）? 用關鍵字搜索 – SIGSEGV PhaseIdealLoop::build_loop_late_post? 搜到若干個bug ID，其中包括7068051 – 但仔細觀察“Release Fixed”與“Related Bugs”可知該 bug從JDK7/HS21才開始存在，也只在JDK7與JDK8 發布了修正。而本案例在JDK6u23上。? 實際上更可能是7070134 – 可惜該bug詳情不公開 – 從郵件列表的討論可以一窺端倪 – 從JDK的release note可知它在JDK6u29已修復
  • 51. 1. 觀察crash log? （續上例）? 如在老版本JDK上遇到crash，且能穩定重現? 然后能找到已知的JDK bug，并且確認官方已在 新版JDK提供修復? 那…趕緊找個測試環境升級到新JDK再跑跑回歸 測試吧?? 廣告：該案例在淘寶JDK6u32上測試運行無問題
  • 52. 1. 觀察crash log? （續上例）? 如果碰到編譯器問題但沒找到已知的JDK bug 怎么辦？? 可針對部分Java方法禁用JIT編譯 – -XX:CompileCommand=exclude,class/name,methodName – 參考例子
  • 53. 1. 觀察crash log? 如果有已知bug，但暫時無法升級JDK – 請參考bug report中給出的workaround
  • 54. 2. 用jstack/gdb看棧的狀況? 為定位問題原因，可先查看線程棧的狀況? jstack與gdb皆可從core dump獲取棧信息? （如果有core dump但無crash log，看棧的狀 況是第一著手點）
  • 55. 2. 用jstack/gdb看棧的狀況? jstack <java_executable_path> <core_dump_path>? gdb <java_executable_path> <core_dump_path>
  • 56. 2. 用jstack/gdb看棧的狀況? jstack可看到Java與native棧幀的符號信息? gdb可看到更準確的native棧幀的符號信息 – gdb的backtrace（簡寫bt）命令查看當前線程棧 – gdb的info threads命令查看線程列表 – gdb的thread <n>切換線程
  • 57. 2. 用jstack/gdb看棧的狀況? 例：https://gist.github.com/2574440? 可見jstack的輸出中有一個線程在深度遞 歸，且該線程最頂上的方法是native方法? 用gdb打開core dump確定出問題的線程正 是在上面看到的在深度遞歸的線程? 此可推斷該crash雖然表現為native crash， 但根本問題在Java代碼中（遞歸條件不完 善導致無限遞歸）
  • 58. 2. 用jstack/gdb看棧的狀況? （續上例）? 如果既沒crash log又沒core dump怎么辦？? $ sudo cat /var/log/messages | grep -i java? May 2 14:08:47 testmachine kernel: : java[2089]: segfault at 0000000041a2efa8 rip 00002aaab81e2507 rsp 0000000041a2f018 error 6? 通過上面的系統日志也可以看到是爆棧了 – 出錯地址與棧頂指針（rsp）很接近? 還是需要core dump來定位根本問題 – ulimit -c unlimited
  • 59. 3. 連續在不固定位置遇到native OutOfMemoryError? 老版本JDK在JVM需要分配native memory 無法得到滿足時 – 報告java.lang.OutOfMemoryError – 并打出crash log，然后退出? 例： https://gist.github.com/2575866#file_command_prompt
  • 60. 3. 連續在不固定位置遇到native OutOfMemoryError# A fatal error has been detected by the Java Runtime Environment:## java.lang.OutOfMemoryError: requested 4092 bytes for char in/BUILD_AREA/jdk6_24/hotspot/src/share/vm/utilities/stack.inline.hpp. Out ofswap space?## Internal Error (allocation.inline.hpp:39), pid=15553, tid=1325374352# Error: char in/BUILD_AREA/jdk6_24/hotspot/src/share/vm/utilities/stack.inline.hpp
  • 61. 3. 連續在不固定位置遇到native OutOfMemoryError? 新版本JDK（JDK6u25或更高版本）的提 示信息更為友善? 例： https://gist.github.com/2575866#file_command_prompt2
  • 62. 3. 連續在不固定位置遇到native OutOfMemoryError# There is insufficient memory for the Java Runtime Environment to continue.# Native memory allocation (malloc) failed to allocate 4092 bytes for charin /BUILD_AREA/jdk6_32/hotspot/src/share/vm/utilities/stack.inline.hpp# Possible reasons:# The system is out of physical RAM or swap space# In 32 bit mode, the process size limit was hit# Possible solutions:# Reduce memory load on the system# Increase physical memory or swap space# Check if swap backing store is full# Use 64 bit Java on a 64 bit OS# Decrease Java heap size (-Xmx/-Xms)# Decrease number of Java threads# Decrease Java thread stack sizes (-Xss)# Set larger code cache with -XX:ReservedCodeCacheSize=# This output file may be truncated or incomplete.## Out of Memory Error (allocation.inline.hpp:44), pid=16388,tid=1325312912
  • 63. 3. 連續在不固定位置遇到native OutOfMemoryError? 如果native memory吃緊，則JVM可能在一 些需要多用native memory的地方遇到問題 – 動態編譯過程中需要使用臨時內存 – GC過程中需要使用GC堆之外額外的臨時內存? 寫得不好的native庫也可能出問題 – 不檢查malloc()結果是否為NULL就直接使用的? 實際表現為不固定位置的native OutOfMemoryError
  • 64. 3. 連續在不固定位置遇到native OutOfMemoryError? 例：https://gist.github.com/2575866? 演示場景： – 將native memory用到接近極限，然后觸發GC， 讓GC因無法分配到臨時內存而報native OOME
  • 65. 3. 連續在不固定位置遇到native OutOfMemoryError? （續上例）? 實驗方法： – 在64位Linux上運行32位JDK – 分別使用JDK6u24與JDK6u32進行兩次實驗 – 使用較大的GC堆 ? -Xmx2g –XX:MaxPermSize=512m – 創建82個、每個占用16MB native memory的 DirectByteBuffer，保證它們存活 – 此時32位尋址空間已經快被耗盡 – 然后觸發GC；JVM嘗試為GC分配輔助數據結構的 內存空間時失敗，報native OOME
  • 66. 3. 連續在不固定位置遇到native OutOfMemoryError 用戶態尋址空間的默認大小 32位程序 64位程序 32位Linux 3GB 64位Linux 4GB 很大…32位Windows 2GB 無論“物理內存”有多大， 進程在用戶態可尋址的空間就這么大， 如果native memory的需求超過了尋址 空間的限制就會分配不出內存
  • 67. 3. 連續在不固定位置遇到native OutOfMemoryError 用戶態尋址空間的默認大小 32位程序 64位程序 32位Linux 3GB 64位Linux 4GB 很大…32位Windows 2GB 如果對native memory需求大， 但受到了32位尋址空間的限制， 請升級到64位系統+64位JDK
  • 68. 3. 連續在不固定位置遇到native OutOfMemoryError? （續上例）? 如在64位JDK上遇到native OOME? 通常不是尋址空間不足，而是整個虛擬內 存的資源不足了 – 物理內存+交換空間
  • 69. 3. 連續在不固定位置遇到native OutOfMemoryError? 已知native memory使用過多，如何排查？? 從簡單的情況開始 – 先檢查是不是NIO direct memory造成的問題 – 然后看是否遇到別的已知容易導致native memory泄漏的情況 – 還不行…試試掛上perftools或valgrind之類? 請參考畢玄的經驗帖
  • 70. 3. 連續在不固定位置遇到native OutOfMemoryError? NIO direct memory – 一部分在GC堆內 ? DirectByteBuffer自身是普通Java對象 ? 大小固定 ? 32位HotSpot VM上：56字節 ? 64位HotSpot VM上（開壓縮指針）：64字節 ? 64位HotSpot VM上（不開壓縮指針）：80字節 – 一部分在GC堆外的native memory中 ? malloc()得到，大小由用戶指定（外加一個內存頁） ? DirectByteBuffer.address字段記錄著地址
  • 71. 3. 連續在不固定位置遇到native OutOfMemoryErrorhsdb> inspect 0xe366e730instance of Oop for java/nio/DirectByteBuffer @ 0xe366e730 (size = 56)_mark: 5_metadata._klass: InstanceKlass for java/nio/DirectByteBuffer @0xba1a9a40mark: -1position: 0limit: 128capacity: 128 32位HotSpot VMaddress: 3092664320hb: nulloffset: 0isReadOnly: falsebigEndian: truenativeByteOrder: falsefd: nullatt: nullcleaner: Oop for sun/misc/Cleaner @ 0xe366e7a0
  • 72. 3. 連續在不固定位置遇到native OutOfMemoryErrorhsdb> inspect 0x00000000ee9a34f8instance of Oop for java/nio/DirectByteBuffer @ 0x00000000ee9a34f8(size = 64)_mark: 5_metadata._compressed_klass: InstanceKlass forjava/nio/DirectByteBuffer @ 0x00000000c443ee38mark: -1position: 0limit: 128capacity: 128 64位HotSpot VMaddress: 46912657712128 （開壓縮指針）hb: nulloffset: 0isReadOnly: falsebigEndian: truenativeByteOrder: falsefd: nullatt: nullcleaner: Oop for sun/misc/Cleaner @ 0x00000000ee9a3600
  • 73. 3. 連續在不固定位置遇到native OutOfMemoryErrorhsdb> inspect 0x00002aaad7f14650instance of Oop for java/nio/DirectByteBuffer @ 0x00002aaad7f14650(size = 80)_mark: 1_metadata._klass: InstanceKlass for java/nio/DirectByteBuffer @0x00002aaaae6388a8mark: -1position: 0limit: 128capacity: 128 64位HotSpot VMaddress: 46913730187408 （不開壓縮指針）hb: nulloffset: 0isReadOnly: falsebigEndian: truenativeByteOrder: falsefd: nullatt: nullcleaner: Oop for sun/misc/Cleaner @ 0x00002aaad7f147d0
  • 74. 3. 連續在不固定位置遇到native OutOfMemoryError? NIO direct memory釋放native memory – 通過sun.misc.Cleaner ? 是PhantomReference ? 釋放DirectByteBuffer關聯的native memory – 需要借助GC來觸發Cleaner的清理動作 – 詳細介紹請參考這帖： ? http://hllvm.group.iteye.com/group/topic/27945
  • 75. 3. 連續在不固定位置遇到native OutOfMemoryError? NIO direct memory釋放native memory – 如果GC不頻繁，則已死的DirectByteBuffer所 關聯的native memory可能得不到及時釋放 – 從而導致“內存泄漏”的表象 – 可能進而引發JVM crash
  • 76. 3. 連續在不固定位置遇到native OutOfMemoryError? 判斷是否有已死DirectByteBuffer堆積？? 對運行中的Java進程使用工具： – jmap -histo <pid> | grep DirectByteBuffer$Deallocator ? 可獲得通過Java的ByteBuffer.allocateDirect() 創建的DirectByteBuffer對象的個數 – DirectMemorySize ? 可獲得當前NIO direct memory所申請的native memory的大小（reserved size） ? 可選的-e -v參數可提供更詳細信息 – 但加這倆參數會大幅降低該工具的運行速度，請謹慎使用
  • 77. 3. 連續在不固定位置遇到native OutOfMemoryError? 操作步驟 – jmap -histo <pid> | grep DirectByteBuffer$Deallocator – java -cp .:$JAVA_HOME/lib/sa-jdi.jar DirectMemorySize <pid> – jmap -histo:live <pid> 2>&1 1>/dev/null – jmap -histo:live <pid> | grep DirectByteBuffer$Deallocator – java -cp .:$JAVA_HOME/lib/sa-jdi.jar DirectMemorySize <pid>
  • 78. 3. 連續在不固定位置遇到native OutOfMemoryError? 操作步驟 – jmap -histo <pid> | grep DirectByteBuffer$Deallocator – java -cp .:$JAVA_HOME/lib/sa-jdi.jar DirectMemorySize <pid> – jmap -histo:live <pid> 2>&1 1>/dev/null 先看當前在GC堆內的 – jmap -histo:live <pid> | grep DirectByteBuffer DirectByteBuffer$Deallocator 對象的個數 – java -cp .:$JAVA_HOME/lib/sa-jdi.jar （不論死活） DirectMemorySize <pid>
  • 79. 3. 連續在不固定位置遇到native OutOfMemoryError? 操作步驟 – jmap -histo <pid> | grep DirectByteBuffer$Deallocator – java -cp .:$JAVA_HOME/lib/sa-jdi.jar DirectMemorySize <pid> – jmap -histo:live <pid> 2>&1 1>/dev/null 看當前NIO direct – jmap -histo:live <pid> | grep memory所占用的 DirectByteBuffer$Deallocator native memory大小 – java -cp .:$JAVA_HOME/lib/sa-jdi.jar （地址空間意義上） DirectMemorySize <pid>
  • 80. 3. 連續在不固定位置遇到native OutOfMemoryError? 操作步驟 從外部強行觸發一次 – jmap -histo <pid> | grep full GC DirectByteBuffer$Deallocator （不需關心它的輸出） – java -cp .:$JAVA_HOME/lib/sa-jdi.jar DirectMemorySize <pid> – jmap -histo:live <pid> 2>&1 1>/dev/null – jmap -histo:live <pid> | grep DirectByteBuffer$Deallocator – java -cp .:$JAVA_HOME/lib/sa-jdi.jar DirectMemorySize <pid>
  • 81. 3. 連續在不固定位置遇到native OutOfMemoryError? 操作步驟 再觸發一次full GC， – jmap -histo <pid> | grep 并觀察GC后還存活的 DirectByteBuffer DirectByteBuffer$Deallocator – 對象的個數 java -cp .:$JAVA_HOME/lib/sa-jdi.jar DirectMemorySize <pid> – jmap -histo:live <pid> 2>&1 1>/dev/null – jmap -histo:live <pid> | grep DirectByteBuffer$Deallocator – java -cp .:$JAVA_HOME/lib/sa-jdi.jar DirectMemorySize <pid>
  • 82. 3. 連續在不固定位置遇到native OutOfMemoryError? 操作步驟 最后觀察兩次full GC – jmap -histo <pid> | grep 后NIO direct memory 所占用的native DirectByteBuffer$Deallocator – memory的大小 java -cp .:$JAVA_HOME/lib/sa-jdi.jar DirectMemorySize <pid> – jmap -histo:live <pid> 2>&1 1>/dev/null – jmap -histo:live <pid> | grep DirectByteBuffer$Deallocator – java -cp .:$JAVA_HOME/lib/sa-jdi.jar DirectMemorySize <pid>
  • 83. 3. 連續在不固定位置遇到native OutOfMemoryError? 經過上述操作 – 如發現一開始DirectByteBuffer對象個數較 多，且NIO direct memory占用的內存也是大頭 – 且在兩次full GC后，這兩個數值都有顯著降低 – 那么可以斷定native memory使用量大與NIO direct memory占用的內存未及時清理相關
  • 84. 3. 連續在不固定位置遇到native OutOfMemoryError? 對策： – 檢查是否使用了-XX:+DisableExplicitGC ? 如有，去掉它 ? 如在使用CMS GC，可改為使用： ? -XX:+ExplicitGCInvokesConcurrent
  • 85. 3. 連續在不固定位置遇到native OutOfMemoryError? 對策： – 檢查是否使用-XX:MaxDirectMemorySize ? 如沒有，請將其設置到一個合理的值 ? -Xmx + -XX:MaxPermSize + ? -XX:ReservedCodeCacheSize + ? (-Xss * 線程數) + ? -XX:MaxDirectMemorySize ? 的總和應保持在物理內存的大小以下 ? 并應留出緩沖的余度 – 詳細仍請參考前面提到的參數經驗帖
  • 86. 4. 進一步分析? 需要更多的底層知識 – 這里不展開講 – 需要對HotSpot VM和JDK有深入的了解 – 能夠熟練使用gdb調試C或C++寫的程序 ? 或其它native debugger – 能夠借助HotSpot VM自帶的CLHSDB工具來輔 助調試
  • 87. 4. 進一步分析? for 阿里系的同事 – 遇到crash請先自救 – 在前面介紹的方法都無法分析出crash的原因時 ? 確認已保存好現場 ? 歡迎向核心系統研發-專用計算組咨詢?
  • 88. QUESTIONS?
  • 89. Kris Mok, Software Engineer, Taobao@rednaxelafx莫樞 /“撒迦”
  • 90. 以下是未使用內容
  • 91. hs_err_pid<pid>.log文件的解析CRASH LOG的結構
  • 92. instructions段Instructions: (pc=0x00002b4fb5a7a648)0x00002b4fb5a7a628: 48 8b 07 ff 50 20 66 90 48 8b 43 48 48 8b 40 080x00002b4fb5a7a638: 83 40 30 01 e8 bf 2f c4 ff c6 80 9c 02 00 00 010x00002b4fb5a7a648: 45 89 2e c6 80 9c 02 00 00 00 48 8b 5b 48 48 8b0x00002b4fb5a7a658: 7b 10 4c 8b 63 08 48 83 7f 08 00 74 09 e8 66 4d crash地點附近 的機器碼
  • 93. instructions段Instructions: (pc=0x00002b4fb5a7a648)0x00002b4fb5a7a628: 48 8b 07 ff 50 20 66 90 48 8b 43 48 48 8b 40 080x00002b4fb5a7a638: 83 40 30 01 e8 bf 2f c4 ff c6 80 9c 02 00 00 010x00002b4fb5a7a648: 45 89 2e c6 80 9c 02 00 00 00 48 8b 5b 48 48 8b0x00002b4fb5a7a658: 7b 10 4c 8b 63 08 48 83 7f 08 00 74 09 e8 66 4d[Disassembling for mach=i386:x86-64] 0x00002b4fb5a7a628: mov (%rdi),%rax 0x00002b4fb5a7a62b: callq *0x20(%rax) 0x00002b4fb5a7a62e: xchg %ax,%ax 0x00002b4fb5a7a630: mov 0x48(%rbx),%rax 0x00002b4fb5a7a634: mov 0x8(%rax),%rax 0x00002b4fb5a7a638: addl $0x1,0x30(%rax) 淘寶JDK6u30開始 0x00002b4fb5a7a63c: callq 0x00002b4fb56bd600 帶有的附加信息： 0x00002b4fb5a7a641: movb $0x1,0x29c(%rax) 0x00002b4fb5a7a648: mov %r13d,(%r14) 匯編指令 0x00002b4fb5a7a64b: movb $0x0,0x29c(%rax) 0x00002b4fb5a7a652: mov 0x48(%rbx),%rbx 0x00002b4fb5a7a656: mov 0x10(%rbx),%rdi 0x00002b4fb5a7a65a: mov 0x8(%rbx),%r12 0x00002b4fb5a7a65e: cmpq $0x0,0x8(%rdi) 0x00002b4fb5a7a663: je 0x00002b4fb5a7a66e 0x00002b4fb5a7a665: .byte 0xe8 0x00002b4fb5a7a666: data16 0x00002b4fb5a7a667: rex.WRB
  • 94. 棧幀類型// First letter indicates type of the frame:// J: Java frame (compiled)// j: Java frame (interpreted)// V: VM frame (C/C++)// v: Other frames running VM generated code (e.g. stubs, adapters, etc.)// C: C/C++ frame
  • 95. TODO? SIGSEGV? SIGBUS? SIGILL? EXCEPTION_ACCESS_VIOLATION? Internal Error
  • 96. CLHSDB TODOCLHSDB

 本文由用戶 openkk 自行上傳分享，僅供網友學習交流。所有權歸原作者，若您的權利被侵害，請聯系管理員。
 轉載本站原創文章，請注明出處，并保留原始鏈接、圖片水印。
 本站是一個以用戶分享為主的開源技術平臺，歡迎各類分享！
  本文地址：http://www.baiduhome.net/news/view/1aa26de

相關資訊

相關經驗

相關文檔