JVM致命錯誤日誌(hs_err_pid.log)分析

xionghuiCoder發表於2015-08-31

致命錯誤出現的時候,JVM 生成了 hs_err_pid<pid>.log 這樣的檔案,其中往往包含了虛擬機器崩潰原因的重要資訊。因為經常遇到,在這篇文章裡,我挑選了一個,並且逐段分析它包含的內容(檔案可以在文章最後下載)。預設情況下檔案是建立在工作目錄下的(如果沒許可權建立的話 JVM 會嘗試把檔案寫到/tmp 這樣的臨時目錄下面去),當然,檔案格式和路徑也可以通過引數指定,比如:

1

java -XX:ErrorFile=/var/log/java/java_error%p.log

這個檔案將包括:

  • 觸發致命錯誤的操作異常或者訊號;
  • 版本和配置資訊;
  • 觸發致命異常的執行緒詳細資訊和執行緒棧;
  • 當前執行的執行緒列表和它們的狀態;
  • 堆的總括資訊;
  • 載入的本地庫;
  • 命令列引數;
  • 環境變數;
  • 作業系統 CPU 的詳細資訊。

首先,看到的是對問題的概要介紹:

1

#  SIGSEGV (0xb) at pc=0x03568cf4, pid=16819, tid=3073346448

一個非預期的錯誤被 JRE 檢測到,其中:

  • SIGSEGV 是訊號名稱
  • 0xb 是訊號碼
  • pc=0x03568cf4 指的是程式計數器的值
  • pid=16819 是程式號
  • tid=3073346448 是執行緒號

如果你對 JVM 有了解,應該不會對這些東西陌生。

接下來是 JRE 和 JVM 的版本資訊:

1

2

3

# JRE version: 6.0_32-b05

 

# Java VM: Java HotSpot(TM) Server VM (20.7-b02 mixed mode linux-x86 )

執行在 mixed 模式下。

然後是問題幀的資訊:

1

2

3

# Problematic frame:

 

# C  [libgtk-x11-2.0.so.0+0x19fcf4]  __float128+0x19fcf4

  • C:幀型別為本地幀,幀的型別包括:
    • C:本地 C 幀
    • j:解釋的 Java 幀
    • V:虛擬機器幀
    • v:虛擬機器生成的存根棧幀
    • J:其他幀型別,包括編譯後的 Java 幀
  • libgtk-x11-2.0.so.0+0x19fcf4:和程式計數器(pc)表達的含義一樣,但是用的是本地 so 庫+偏移量的方式。

接下去第一部分是執行緒資訊:

1

Current thread (0x09f30c00):  JavaThread "main" [_thread_in_native, id=16822, stack(0xb72a8000,0xb72f9000)]

當前執行緒的:

  • 0x09f30c00:指標
  • JavaThread:執行緒型別,可能的型別包括:
    • JavaThread
    • VMThread
    • CompilerThread
    • GCTaskThread
    • WatcherThread
    • ConcurrentMarkSweepThread
  • main:名字
    • _thread_in_native:執行緒當前狀態,狀態列舉包括:
    • _thread_uninitialized:執行緒還沒有建立,它只在記憶體原因崩潰的時候才出現
    • _thread_new:執行緒已經被建立,但是還沒有啟動
    • _thread_in_native:執行緒正在執行原生程式碼,一般這種情況很可能是原生程式碼有問題
    • _thread_in_vm:執行緒正在執行虛擬機器程式碼
    • _thread_in_Java:執行緒正在執行解釋或者編譯後的 Java 程式碼
    • _thread_blocked:執行緒處於阻塞狀態
    • …_trans:以_trans 結尾,執行緒正處於要切換到其它狀態的中間狀態
  • id=16822:執行緒 ID
  • 0xb72a8000,0xb72f9000:棧區間

1

siginfo:si_signo=SIGSEGV: si_errno=0, si_code=1 (SEGV_MAPERR), si_addr=0x00000010

這部分是導致虛擬機器終止的非預期的訊號資訊,含義前面已經大致提到過了。其中 si_errno 和 si_code 是 Linux 下用來鑑別異常的,Windows 下是一個 ExceptionCode。

1

2

3

EAX=0x00000000, EBX=0x0375dd84, ECX=0x00000000, EDX=0x00000000

ESP=0xb72f0fa0, EBP=0xb72f0fb8, ESI=0x00000000, EDI=0x0a6c1800

EIP=0x03568cf4, EFLAGS=0x00010246, CR2=0x00000010

這是暫存器上下文。

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

Top of Stack: (sp=0xb72f0fa0)

0xb72f0fa0:   00000000 00402250 0040217f 0375dd84

0xb72f0fb0:   00000000 0a6c1800 b72f0fe8 0356c2c0

0xb72f0fc0:   00000000 0a6c1800 b72f0fe8 003b3e77

0xb72f0fd0:   003e6c8b 0a1a70d0 0a193358 0375dd84

0xb72f0fe0:   0a276418 0a276418 b72f1048 03536c56

0xb72f0ff0:   0acad000 0b3ca978 0000000c 00dd0674

0xb72f1000:   00000003 0a2c7d50 b72f1038 0000330c

0xb72f1010:   ffffffff ffffffff 00000001 00000001

 

Instructions: (pc=0x03568cf4)

0x03568cd4:   89 14 24 89 75 f8 89 d6 89 7d fc 89 c7 e8 7e 1b

0x03568ce4:   ea ff 89 34 24 89 87 d4 02 00 00 e8 30 00 ea ff

0x03568cf4:   8b 40 10 89 3c 24 c7 44 24 08 00 00 00 00 89 87

0x03568d04:   d0 02 00 00 8b 83 88 24 00 00 89 44 24 04 e8 dd

棧頂程式計數器旁的操作碼,它們可以被反彙編成系統崩潰前執行的指令。

1

2

3

4

5

6

7

8

9

10

Register to memory mapping:

 

EAX=0x00000000 is an unknown value

EBX=0x0375dd84: <offset 0x394d84> in /usr/lib/libgtk-x11-2.0.so.0 at 0x033c9000

ECX=0x00000000 is an unknown value

EDX=0x00000000 is an unknown value

ESP=0xb72f0fa0 is pointing into the stack for thread: 0x09f30c00

EBP=0xb72f0fb8 is pointing into the stack for thread: 0x09f30c00

ESI=0x00000000 is an unknown value

EDI=0x0a6c1800 is an unknown value

暫存器和記憶體對映資訊。

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

Stack: [0xb72a8000,0xb72f9000],  sp=0xb72f0fa0,  free space=291k

Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)

C  [libgtk-x11-2.0.so.0+0x19fcf4]  __float128+0x19fcf4

C  [libgtk-x11-2.0.so.0+0x1a32c0]  __float128+0xc0

... ...

C  [libswt-pi-gtk-3738.so+0x33f6a]  Java_org_eclipse_swt_internal_gtk_OS__1Call+0xf

J  org.eclipse.swt.internal.gtk.OS._Call(III)I

J  org.eclipse.swt.internal.gtk.OS.Call(III)I

 

Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)

J  org.eclipse.swt.internal.gtk.OS._Call(III)I

J  org.eclipse.swt.internal.gtk.OS.Call(III)I

j  org.eclipse.swt.widgets.Widget.fixedSizeAllocateProc(II)I+5

j  org.eclipse.swt.widgets.Display.fixedSizeAllocateProc(II)I+17

v  ~StubRoutines::call_stub

... ...

執行緒棧。包含了地址、棧頂、棧計數器和執行緒尚未使用的棧資訊,由於棧可能非常長,列印的長度有限制,但是至少本地棧和 Java 棧都列印出來了(很多時候本地棧列印不出來,但是 Java 棧一般都能列印出來)。從中可以看到,Eclipse 的虛擬機器崩潰了。

1

2

3

4

Java Threads: ( => current thread )

  0x0b4c1000 JavaThread "Worker-247" [_thread_blocked, id=25417, stack(0x741bc000,0x7420d000)]

  0x0a300c00 JavaThread "Worker-246" [_thread_blocked, id=25235, stack(0x7d30c000,0x7d35d000)]

... ...

執行緒資訊。一目瞭然,不解釋了。

1

VM state:not at safepoint (normal execution)

虛擬機器狀態。包括:

  • not at a safepoint:正常執行狀態;
  • at safepoint:所有執行緒都因為虛擬機器等待狀態而阻塞,等待一個虛擬機器操作完成;
  • synchronizing:一個特殊的虛擬機器操作,要求虛擬機器內的其它執行緒保持等待狀態。

1

VM Mutex/Monitor currently owned by a thread: None

虛擬機器的 Mutex 和 Monitor 目前沒有被執行緒持有。Mutex 是虛擬機器內部的鎖,而 Monitor 則關聯到了 Java 物件。

1

2

3

4

5

6

7

8

9

Heap

 PSYoungGen      total 149056K, used 125317K [0xa9700000, 0xb41a0000, 0xb41a0000)

  eden space 123520K, 95% used [0xa9700000,0xb0ac0de0,0xb0fa0000)

  from space 25536K, 26% used [0xb28b0000,0xb2f50748,0xb41a0000)

  to   space 25600K, 0% used [0xb0fa0000,0xb0fa0000,0xb28a0000)

 PSOldGen        total 261248K, used 239964K [0x941a0000, 0xa40c0000, 0xa9700000)

  object space 261248K, 91% used [0x941a0000,0xa2bf7018,0xa40c0000)

 PSPermGen       total 163328K, used 130819K [0x841a0000, 0x8e120000, 0x941a0000)

  object space 163328K, 80% used [0x841a0000,0x8c160c40,0x8e120000)

堆資訊。新生代、老生代、永久代。對 JVM 有了解的人應該都清楚,不解釋了。

1

2

Code Cache  [0xb4262000, 0xb5ac2000, 0xb7262000)

 total_blobs=5795 nmethods=5534 adapters=209 free_code_cache=25103616 largest_free_block=38336

程式碼快取(Code Cache)。這是一塊用於編譯和儲存原生程式碼的記憶體,注意是原生程式碼,它和 PermGen(永久代)是不一樣的,永久帶是用來存放 Java 類定義的。

1

2

3

4

5

6

Dynamic libraries:

00101000-00122000 r-xp 00000000 08:01 3483560    /usr/lib/libjpeg.so.62.0.0

00122000-00123000 rwxp 00020000 08:01 3483560    /usr/lib/libjpeg.so.62.0.0

00125000-00130000 r-xp 00000000 08:01 9093202    /lib/libgcc_s-4.1.2-20080825.so.1

00130000-00131000 rwxp 0000a000 08:01 9093202    /lib/libgcc_s-4.1.2-20080825.so.1

... ...

記憶體對映。這些資訊是虛擬機器崩潰時的虛擬記憶體列表區域。在定位崩潰原因的時候,它可以告訴你哪些類庫正在被使用,位置在哪裡,還有堆疊和守護頁資訊。就以列表中第一條為例說明:

  • 00101000-00122000:記憶體區域
  • r-xp:許可權,r/w/x/p/s 分別表示讀/寫/執行/私有/共享
  • 00000000:檔案內的偏移量
  • 08:01:檔案位置的 majorID 和 minorID
  • 3483560:索引節點號
  • /usr/lib/libjpeg.so.62.0.0:檔案位置

每一個 lib 都有兩塊虛擬記憶體區域—— 程式碼和資料,它們的許可權不同,程式碼區域是 r-xp;資料區域是 rwxp。守護頁(guard page)由許可權為–xp 和 rwxp 的一對組成。

1

2

3

4

5

6

7

8

VM Arguments:

jvm_args: -Dosgi.requiredJavaVersion=1.5 -XX:MaxPermSize=256m -Xms40m -Xmx512m -Dorg.eclipse.swt.browser.XULRunnerPath=''

java_command: /.../eclipse/plugins/org.eclipse.equinox.launcher_1.2.0.v20110502.jar -os linux -ws gtk -arch x86 -showsplash -launcher /.../eclipse/eclipse -name Eclipse ...

Launcher Type: SUN_STANDARD

 

Environment Variables:

PATH=...

DISPLAY=:0.0

虛擬機器引數和環境變數。

1

2

3

4

Signal Handlers:

SIGSEGV: [libjvm.so+0x726440], sa_mask[0]=0x7ffbfeff, sa_flags=0x10000004

SIGBUS: [libjvm.so+0x726440], sa_mask[0]=0x7ffbfeff, sa_flags=0x10000004

... ...

訊號控制程式碼。對於 Linux 下的訊號機制,參閱 wiki 百科, 連結 。

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

OS:Red Hat Enterprise Linux Client release 5.4 (Tikanga)

 

uname:Linux 2.6.18-164.el5 #1 SMP Tue Aug 18 15:51:54 EDT 2009 i686

libc:glibc 2.5 NPTL 2.5

rlimit: STACK 10240k, CORE 0k, NPROC 65536, NOFILE 1024, AS infinity

load average:1.78 1.58 1.54

 

/proc/meminfo:

...

 

CPU:total 4 (4 cores per cpu, 1 threads per core) family 6 model 42 stepping 7, cmov, cx8, fxsr, mmx, sse, sse2, sse3, ssse3

 

/proc/cpuinfo:

...

 

Memory: 4k page, physical 3631860k(155144k free), swap 5124724k(5056452k free)

系統資訊。

感謝您的關注!可加QQ1群:135430763,QQ2群:454796847,QQ3群:187424846。QQ群進群密碼:xttblog,想加微信群的朋友,可以微信搜尋:xmtxtt,備註:“xttblog”,新增助理微信拉你進群。備註錯誤不會同意好友申請。再次感謝您的關注!後續有精彩內容會第一時間發給您!原創文章投稿請傳送至532009913@qq.com郵箱。商務合作可新增助理微信進行溝通! 

相關文章