JVM緻命錯誤日志(hs_err_pid.log)分析JVM緻命錯誤日志(hs_err_pid.log)分析日志頭檔案導緻crash的線程資訊所有線程資訊安全點和鎖資訊堆資訊本地代碼緩存編譯事件gc相關記錄jvm記憶體映射 jvm啟動參數伺服器資訊

發表于5天前(2015-08-28 17:10)

當jvm出現緻命錯誤時，會生成一個錯誤檔案 hs_err_pid<pid>.log，其中包括了導緻jvm crash的重要資訊，可以通過分析該檔案定位到導緻crash的根源，進而改善以保證系統穩定。當出現crash時，該檔案預設會生成到工作目錄下，然而可以通過jvm參數指定生成路徑（JDK6中引入）：

<code>-XX:ErrorFile=./hs_err_pid<pid>.log</code>

該檔案包含如下幾類關鍵資訊：

日志頭檔案

導緻crash的線程資訊

所有線程資訊

安全點和鎖資訊

堆資訊

本地代碼緩存

編譯事件

gc相關記錄

jvm記憶體映射

jvm啟動參數

伺服器資訊

下面用一個crash demo檔案逐漸解讀這些資訊，以便大家以後碰到crash時友善分析。

日志頭檔案包含概要資訊，簡述了導緻crash的原因。而導緻crash的原因很多，常見的原因有jvm自身的bug，應用程式錯誤，jvm參數配置不當，伺服器資源不足，jni調用錯誤等。

現在參考下如下描述：

<code># A fatal error has been detected by the Java Runtime Environment:</code>

<code># SIGSEGV (</code><code>0xb</code><code>) at pc=</code><code>0x00007fb8b18fdc6c</code><code>, pid=</code><code>191899</code><code>, tid=</code><code>140417770411776</code>

<code># JRE version: Java(TM) SE Runtime Environment (</code><code>7</code><code>.0_55-b13) (build </code><code>1.7</code><code>.0_55-b13)</code>

<code># Java VM: Java HotSpot(TM) </code><code>64</code><code>-Bit Server VM (</code><code>24.55</code><code>-b03 mixed mode linux-amd64 compressed oops)</code>

<code># Problematic frame:</code>

<code># J org.apache.http.impl.cookie.BestMatchSpec.formatCookies(Ljava/util/List;)Ljava/util/List;</code>

<code># Failed to write core dump. Core dumps have been disabled. To enable core dumping, </code><code>try</code> <code>"ulimit -c unlimited"</code> <code>before starting Java again</code>

<code># If you would like to submit a bug report, please visit:</code>

<code># http:</code><code>//bugreport.sun.com/bugreport/crash.jsp</code>

這裡一個重要資訊是“SIGSEGV(0xb)”表示jvm crash時正在執行jni代碼，而不是在執行java或者jvm的代碼，如果沒有在應用程式裡手動調用jni代碼，那麼很可能是JIT動态編譯時導緻的該錯誤。其中SIGSEGV是信号名稱，0xb是信号碼，pc=0x00007fb8b18fdc6c指的是程式計數器的值，pid=191899是程序号，tid=140417770411776是線程号。

PS：除了“SIGSEGV(0xb)”以外，常見的描述還有“EXCEPTION_ACCESS_VIOLATION”，該描述表示jvm crash時正在執行jvm自身的代碼，這往往是因為jvm的bug導緻的crash；另一種常見的描述是“EXCEPTION_STACK_OVERFLOW”，該描述表示這是個棧溢出導緻的錯誤，這往往是應用程式中存在深層遞歸導緻的。

還有一個重要資訊是：

# Problematic frame:

# J org.apache.http.impl.cookie.BestMatchSpec.formatCookies(Ljava/util/List;)Ljava/util/List;

這表示出現crash時jvm正在執行的代碼，這裡的“J”表示正在執行java代碼，後面的表示執行的方法棧。除了“J”外，還有可能是“C”、“j”、“V”、“v”，它們分别表示：

C: Native C frame

j: Interpreted Java frame

V: VMframe

v: VMgenerated stub frame

J: Other frame types, including compiled Java frames

加上前面對SIGSEGV(0xb)”的分析，現在可以斷定是JIT動态編譯導緻的該錯誤。

查閱資料發現：

此異常是由于jdk JIT compiler optimization 導緻，bug id 8021898，官網描述如下：

<code>The JIT compiler optimization leads to a SIGSEGV or an NullPointerException at a place it must not happen.</code>

到這裡該問題已經分析出原因了，但是咱們可以再深入一步，分析下其它資訊。

檔案下面是導緻crash的線程資訊和該線程棧資訊，描述資訊如下：

<code>Current thread (</code><code>0x00007fb7b4014800</code><code>): JavaThread </code><code>"catalina-exec-251"</code> <code>daemon [_thread_in_Java, id=</code><code>205044</code><code>, stack(</code><code>0x00007fb58f435000</code><code>,</code><code>0x00007fb58f536000</code><code>)]</code>

<code>siginfo:si_signo=SIGSEGV: si_errno=</code><code>0</code><code>, si_code=</code><code>1</code> <code>(SEGV_MAPERR), si_addr=</code><code>0x0000003f96dc9c6c</code>

以上表示導緻出錯的線程是0x00007fb7b4014800（指針），線程類型是JavaThread，JavaThread表示執行的是java線程，關于該線程其它類型還可能是：

VMThread：jvm的内部線程

CompilerThread：用來調用JITing，實時編譯裝卸class 。通常，jvm會啟動多個線程來處理這部分工作，線程名稱後面的數字也會累加，例如：CompilerThread1

GCTaskThread：執行gc的線程

WatcherThread：jvm周期性任務排程的線程，是一個單例對象。該線程在JVM内使用得比較頻繁，比如：定期的記憶體監控、JVM運作狀況監控，還有我們經常需要去執行一些jstat 這類指令檢視gc的情況

ConcurrentMarkSweepThread：jvm在進行CMS GC的時候，會建立一個該線程去進行GC，該線程被建立的同時會建立一個SurrogateLockerThread（簡稱SLT）線程并且啟動它，SLT啟動之後，處于等待階段。CMST開始GC時，會發一個消息給SLT讓它去擷取Java層Reference對象的全局鎖：Lock

後面的"catalina-exec-251"表示線程名，帶有catalina字首的線程一般是tomcat啟動的線程，“daemon”表示該線程為守護線程，再後面的“[_thread_in_Java”表示線程正在執行解釋或者編譯後的Java代碼，關于該描述其它類型還可能是：

_thread_in_native：線程目前狀态

_thread_uninitialized：線程還沒有建立，它隻在記憶體原因崩潰的時候才出現

_thread_new：線程已經被建立，但是還沒有啟動

_thread_in_native：線程正在執行本地代碼，一般這種情況很可能是本地代碼有問題

_thread_in_vm：線程正在執行虛拟機代碼

_thread_in_Java：線程正在執行解釋或者編譯後的Java代碼

_thread_blocked：線程處于阻塞狀态

…_trans：以_trans結尾，線程正處于要切換到其它狀态的中間狀态

最後的“id=205044”表示線程ID，stack(0x00007fb58f435000,0x00007fb58f536000)表示棧區間。

“siginfo:si_signo=SIGSEGV: si_errno=0, si_code=1 (SEGV_MAPERR), si_addr=0x0000003f96dc9c6c”這部分是導緻虛拟機終止的非預期的信号資訊：其中si_errno和si_code是Linux下用來鑒别異常的，Windows下是一個ExceptionCode。

再下面是線程資訊：

<code>Java Threads: ( => current thread )</code>

<code> </code><code>0x00007fb798015800</code> <code>JavaThread </code><code>"catalina-exec-280"</code> <code>daemon [_thread_blocked, id=</code><code>206093</code><code>, stack(</code><code>0x00007fb58d718000</code><code>,</code><code>0x00007fb58d819000</code><code>)]</code>

<code> </code><code>0x00007fb7a4016800</code> <code>JavaThread </code><code>"catalina-exec-279"</code> <code>daemon [_thread_blocked, id=</code><code>206091</code><code>, stack(</code><code>0x00007fb58d819000</code><code>,</code><code>0x00007fb58d91a000</code><code>)]</code>

<code> </code><code>Other Threads:</code>

<code> </code><code>0x00007fb8b4231000</code> <code>VMThread [stack: </code><code>0x00007fb854eb6000</code><code>,</code><code>0x00007fb854fb7000</code><code>] [id=</code><code>192015</code><code>]</code>

<code> </code><code>0x00007fb8b4321000</code> <code>WatcherThread [stack: </code><code>0x00007fb835e6c000</code><code>,</code><code>0x00007fb835f6d000</code><code>] [id=</code><code>192414</code><code>]</code>

資訊和上面介紹的類似，其中[_thread_blocked表示線程阻塞。

再下面是安全點和鎖資訊：

<code>VM state:not at safepoint (normal execution)</code>

<code>VM Mutex/Monitor currently owned by a thread: None</code>

安全線資訊為正常運作，其它可能得描述還有：

not at a safepoint：正常運作狀态

at safepoint：所有線程都因為虛拟機等待狀态而阻塞，等待一個虛拟機操作完成

synchronizing：一個特殊的虛拟機操作，要求虛拟機内的其它線程保持等待狀态

鎖資訊為未被線程持有，Mutex是虛拟機内部的鎖，而Monitor則是synchronized鎖或者其它關聯到的Java對象。

再下面是堆資訊：

<code> </code><code>par </code><code>new</code> <code>generation total 2293760K, used 1537284K [</code><code>0x00000006f0000000</code><code>, </code><code>0x0000000790000000</code><code>, </code><code>0x0000000790000000</code><code>)</code>

<code> </code><code>eden space 1966080K, </code><code>78</code><code>% used [</code><code>0x00000006f0000000</code><code>, </code><code>0x000000074dc97aa8</code><code>, </code><code>0x0000000768000000</code><code>)</code>

<code> </code><code>from space 327680K, </code><code>0</code><code>% used [</code><code>0x0000000768000000</code><code>, </code><code>0x00000007680a9580</code><code>, </code><code>0x000000077c000000</code><code>)</code>

<code> </code><code>to space 327680K, </code><code>0</code><code>% used [</code><code>0x000000077c000000</code><code>, </code><code>0x000000077c000000</code><code>, </code><code>0x0000000790000000</code><code>)</code>

<code> </code><code>concurrent mark-sweep generation total 1572864K, used 49449K [</code><code>0x0000000790000000</code><code>, </code><code>0x00000007f0000000</code><code>, </code><code>0x00000007f0000000</code><code>)</code>

<code> </code><code>concurrent-mark-sweep perm gen total 262144K, used 49857K [</code><code>0x00000007f0000000</code><code>, </code><code>0x0000000800000000</code><code>, </code><code>0x0000000800000000</code><code>)</code>

<code> </code><code>Card table byte_map: [</code><code>0x00007fb8b8fa8000</code><code>,</code><code>0x00007fb8b9829000</code><code>] byte_map_base: </code><code>0x00007fb8b5828000</code>

堆資訊包括：新生代、老生代、永久代資訊。這裡辨別了使用CMS垃圾收集器。

下面的“Card table”表示一種卡表，是jvm維護的一種資料結構，用于記錄更改對象時的引用，以便gc時周遊更少的table和root。

再下面是本地代碼緩存資訊：

<code>Code Cache [</code><code>0x00007fb8b1000000</code><code>, </code><code>0x00007fb8b1a60000</code><code>, </code><code>0x00007fb8b4000000</code><code>)</code>

<code> </code><code>total_blobs=</code><code>3580</code> <code>nmethods=</code><code>3111</code> <code>adapters=</code><code>421</code> <code>free_code_cache=38857Kb largest_free_block=</code><code>39469312</code>

這是一塊用于編譯和儲存本地代碼的記憶體；注意是本地代碼，它和PermGen（永久代）是不一樣的，永久代是用來存放jvm和java類的中繼資料的。

再下面是本地代碼編譯資訊：

<code>Compilation events (</code><code>10</code> <code>events):</code>

<code>Event: </code><code>110587.798</code> <code>Thread </code><code>0x00007fb8b425a800</code> <code>3338</code> <code>java.util.HashSet::remove (</code><code>20</code> <code>bytes)</code>

<code>Event: </code><code>110587.804</code> <code>Thread </code><code>0x00007fb8b425a800</code> <code>nmethod </code><code>3338</code> <code>0x00007fb8b168a9d0</code> <code>code [</code><code>0x00007fb8b168ab60</code><code>, </code><code>0x00007fb8b168afa8</code><code>]</code>

<code>Event: </code><code>112147.387</code> <code>Thread </code><code>0x00007fb8b425a800</code> <code>3342</code> <code>org.apache.http.impl.cookie.BestMatchSpec::formatCookies (</code><code>116</code> <code>bytes)</code>

<code>Event: </code><code>112147.465</code> <code>Thread </code><code>0x00007fb8b425a800</code> <code>nmethod </code><code>3342</code> <code>0x00007fb8b18fcd50</code> <code>code [</code><code>0x00007fb8b18fd1a0</code><code>, </code><code>0x00007fb8b18ff338</code><code>]</code>

可以看到，一共編譯了10次；其中包含org.apache.http.impl.cookie.BestMatchSpec::formatCookies的編譯；這和前面的結論相吻合。

再下面是gc執行記錄：

<code>GC Heap History (</code><code>10</code> <code>events):</code>

<code>Event: </code><code>110665.975</code> <code>GC heap before</code>

<code>{Heap before GC invocations=</code><code>255</code> <code>(full </code><code>31</code><code>):</code>

<code> </code><code>par </code><code>new</code> <code>generation total 2293760K, used 1966777K [</code><code>0x00000006f0000000</code><code>, </code><code>0x0000000790000000</code><code>, </code><code>0x0000000790000000</code><code>)</code>

<code> </code><code>eden space 1966080K, </code><code>100</code><code>% used [</code><code>0x00000006f0000000</code><code>, </code><code>0x0000000768000000</code><code>, </code><code>0x0000000768000000</code><code>)</code>

<code> </code><code>from space 327680K, </code><code>0</code><code>% used [</code><code>0x0000000768000000</code><code>, </code><code>0x00000007680ae480</code><code>, </code><code>0x000000077c000000</code><code>)</code>

<code> </code><code>concurrent mark-sweep generation total 1572864K, used 49237K [</code><code>0x0000000790000000</code><code>, </code><code>0x00000007f0000000</code><code>, </code><code>0x00000007f0000000</code><code>)</code>

<code> </code><code>concurrent-mark-sweep perm gen total 262144K, used 49856K [</code><code>0x00000007f0000000</code><code>, </code><code>0x0000000800000000</code><code>, </code><code>0x0000000800000000</code><code>)</code>

<code>Event: </code><code>110665.981</code> <code>GC heap after</code>

<code>Heap after GC invocations=</code><code>256</code> <code>(full </code><code>31</code><code>):</code>

<code> </code><code>par </code><code>new</code> <code>generation total 2293760K, used 693K [</code><code>0x00000006f0000000</code><code>, </code><code>0x0000000790000000</code><code>, </code><code>0x0000000790000000</code><code>)</code>

<code> </code><code>eden space 1966080K, </code><code>0</code><code>% used [</code><code>0x00000006f0000000</code><code>, </code><code>0x00000006f0000000</code><code>, </code><code>0x0000000768000000</code><code>)</code>

<code> </code><code>from space 327680K, </code><code>0</code><code>% used [</code><code>0x000000077c000000</code><code>, </code><code>0x000000077c0ad6f8</code><code>, </code><code>0x0000000790000000</code><code>)</code>

<code> </code><code>to space 327680K, </code><code>0</code><code>% used [</code><code>0x0000000768000000</code><code>, </code><code>0x0000000768000000</code><code>, </code><code>0x000000077c000000</code><code>)</code>

可以看到gc次數為10次（full gc），然後後面描述了每次gc前後的記憶體資訊；看一看到并沒有記憶體不足等問題。

再下面是jvm加載的庫資訊：

<code>Dynamic libraries:</code>

<code>00400000</code><code>-</code><code>00401000</code> <code>r-xp </code><code>00000000</code> <code>08</code><code>:</code><code>02</code> <code>39454583</code> <code>/home/service/jdk1.</code><code>7</code><code>.0_55/bin/java</code>

<code>00600000</code><code>-</code><code>00601000</code> <code>rw-p </code><code>00000000</code> <code>08</code><code>:</code><code>02</code> <code>39454583</code> <code>/home/service/jdk1.</code><code>7</code><code>.0_55/bin/java</code>

<code>3056400000</code><code>-</code><code>3056416000</code> <code>r-xp </code><code>00000000</code> <code>08</code><code>:</code><code>02</code> <code>57409539</code> <code>/lib64/libgcc_s-</code><code>4.4</code><code>.</code><code>7</code><code>-</code><code>20120601</code><code>.so.</code><code>1</code>

<code>3056416000</code><code>-</code><code>3056615000</code> <code>---p </code><code>00016000</code> <code>08</code><code>:</code><code>02</code> <code>57409539</code> <code>/lib64/libgcc_s-</code><code>4.4</code><code>.</code><code>7</code><code>-</code><code>20120601</code><code>.so.</code><code>1</code>

<code>3056615000</code><code>-</code><code>3056616000</code> <code>rw-p </code><code>00015000</code> <code>08</code><code>:</code><code>02</code> <code>57409539</code> <code>/lib64/libgcc_s-</code><code>4.4</code><code>.</code><code>7</code><code>-</code><code>20120601</code><code>.so.</code><code>1</code>

這些資訊是虛拟機崩潰時的虛拟記憶體清單區域。它可以告訴你崩潰原因時哪些類庫正在被使用，位置在哪裡，還有堆棧和守護頁資訊。以清單中第一條為例介紹下：

00400000-00401000：記憶體區域

r-xp：權限，r/w/x/p/s分别表示讀/寫/執行/私有/共享

00000000：檔案内的偏移量

08:02：檔案位置的majorID和minorID

39454583：索引節點号

/home/service/jdk1.7.0_55/bin/java：檔案位置

再下面是jvm啟動參數資訊：

<code>VM Arguments:</code>

<code>jvm_args: -Djava.util.logging.config.file=/home/service/tomcat7007-account-web/conf/logging.properties -Xmx4096m -Xms4096m -Xmn2560m -XX:SurvivorRatio=</code><code>6</code> <code>-XX:PermSize=256m -XX:MaxPermSize=256m -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+PrintGCDetails -Xloggc:/home/work/webdata/logs/tomcat7007-account-web/develop/gc.log -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home/work/webdata/logs/tomcat7007-account-web/develop/ -Dtomcatlogdir=/home/work/webdata/logs/tomcat7007-account-web/develop -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=</code><code>7407</code> <code>-Dcom.sun.management.jmxremote.authenticate=</code><code>false</code> <code>-Dcom.sun.management.jmxremote.ssl=</code><code>false</code> <code>-Djava.endorsed.dirs=/home/service/tomcat7007-account-web/endorsed -Dcatalina.base=/home/service/tomcat7007-account-web -Dcatalina.home=/home/service/tomcat7007-account-web -Djava.io.tmpdir=/home/service/tomcat7007-account-web/temp </code>

<code>java_command: org.apache.catalina.startup.Bootstrap start</code>

<code>Launcher Type: SUN_STANDARD</code>

<code>Environment Variables:</code>

<code>JAVA_HOME=/home/service/jdk1.</code><code>7</code><code>.0_55</code>

<code>PATH=/opt/zabbix/bin:/opt/zabbix/sbin:/home/service/jdk1.</code><code>7</code><code>.0_55/bin:/home/work/bin:/usr/local/bin:/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/sbin:/home/work/bin</code>

<code>SHELL=/bin/bash</code>

上面是jvm參數，下面是系統的環境配置。

再下面是伺服器資訊：

<code>/proc/meminfo:</code>

<code>MemTotal: </code><code>65916492</code> <code>kB</code>

<code>MemFree: </code><code>14593468</code> <code>kB</code>

<code>Buffers: </code><code>222452</code> <code>kB</code>

<code>Cached: </code><code>28502452</code> <code>kB</code>

<code>SwapTotal: </code><code>0</code> <code>kB</code>

<code>SwapFree: </code><code>0</code> <code>kB</code>

<code>/proc/cpuinfo:</code>

<code>processor : </code><code>0</code>

<code>vendor_id : GenuineIntel</code>

<code>cpu family : </code><code>6</code>

<code>model : </code><code>62</code>

<code>model name : Intel(R) Xeon(R) CPU E5-</code><code>2420</code> <code>v2 @ </code><code>2</code><code>.20GHz</code>

<code>stepping : </code><code>4</code>

上面是記憶體資訊，主要關注下swap資訊，看看有沒有使用虛拟記憶體；下面是cpu資訊。

轉自 http://my.oschina.net/xionghui/blog/498785

JVM緻命錯誤日志(hs_err_pid.log)分析JVM緻命錯誤日志(hs_err_pid.log)分析日志頭檔案導緻crash的線程資訊所有線程資訊安全點和鎖資訊堆資訊本地代碼緩存編譯事件gc相關記錄jvm記憶體映射 jvm啟動參數伺服器資訊

繼續閱讀

nginx location中斜線的位置的重要性

Apache2.4.x 配置檔案詳解Apache配置需要了解如下：開始講解：

配置apache支援PHP（win7）

27 Best Free Eclipse Plug-ins for Java Developer to be ProductiveCode Quality PluginsText Editor PluginsDependency ManagementVersion Control Integration PluginsFramework Development Continuous Integration Related PluginsOther Utility Plugins

Java String.format方法的簡單使用

neo4j之cypher使用文檔

GitHub連夜封殺！這份阿裡 10W 字内部 Java 字面試手冊到底有多強？

spark/scala關于【資源檔案】加載方法概述外部檔案加載方案測試資源檔案打包入jar包中小結

mybatis_入門程式Mybatis入門

AOP程式設計_Android優雅權限架構(1)概念基礎，2021金三銀四前言正文大綱正文

Effective Java 8:通用程式設計

OOM三種類型

工廠模式-三種類型

【遞歸】高效率求2的n次幂

win10本地scala和spark安裝安裝scala安裝spark

scala (3) Function 和 Method

JVM緻命錯誤日志(hs_err_pid.log)分析JVM緻命錯誤日志(hs_err_pid.log)分析日志頭檔案導緻crash的線程資訊所有線程資訊安全點和鎖資訊堆資訊本地代碼緩存編譯事件gc相關記錄jvm記憶體映射 jvm啟動參數 伺服器資訊

繼續閱讀

JVM緻命錯誤日志(hs_err_pid.log)分析JVM緻命錯誤日志(hs_err_pid.log)分析日志頭檔案導緻crash的線程資訊所有線程資訊安全點和鎖資訊堆資訊本地代碼緩存編譯事件gc相關記錄jvm記憶體映射 jvm啟動參數伺服器資訊