hs_err_pid.log简介
java程序崩溃以后,会在java程序的主目录(如果配置了参数-XX:ErrorFile,则在对应目录下)生成一个hs_err_pid.log的日志,该文件记载了本次程序奔溃的可能原因及崩溃时刻jvm的相关信息.
log的内容
一般hs_err_pid.log文件可以分为以下几个部分:
- 崩溃事件简要分析
- 崩溃时刻正在运行的线程
- jvm里面的所有线程
- 内存的使用情况
- GC日志
- JVM内存映射
- jvm参数
- 服务器信息
下面以我之前的一个项目为例:
崩溃事件简要分析
# 出现奔溃的直接原因
# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (malloc) failed to allocate 12288 bytes for committing reserved memory.
# 出现奔溃的底层原因或者可能原因
# 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.
# 奔溃时候执行到哪行Linux哪行代码
# Out of Memory Error (os_linux.cpp:2726), pid=41, tid=140554500867840
# jvm的情况
# JRE version: Java(TM) SE Runtime Environment (7.0_55-b13) (build 1.7.0_55-b13)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (24.55-b03 mixed mode linux-amd64 compressed oops)
# Core dump written. Default location: /opt/jetty/jetty/core or core.41
#
崩溃时刻正在运行的线程
Current thread (0x00007fd5cb683800): JavaThread "pool-97706-thread-1" [_thread_new, id=55726, stack(0x00007fd565148000,0x00007fd565189000)](从这里可以看出,此刻正在创建一个新线程,他的线程名为pool-97706-thread-1, id = 55726, 申请的栈地址为 0x00007fd565148000,0x00007fd565189000 )
Stack: [0x00007fd565148000,0x00007fd565189000], sp=0x00007fd565187780, free space=253k
(在我的jvm参数设置中,栈大小为256,但是这里剩余空间只有253,所以导致了OOM)
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code) [J:程序java代码 j:注释 V:jvm代码 C: 系统c代码]
V [libjvm.so+0x99305a] VMError::report_and_die()+0x2ea
V [libjvm.so+0x4931fb] report_vm_out_of_memory(char const, int, unsigned long, char const)+0x9b
V [libjvm.so+0x8134be] os::Linux::commit_memory_impl(char, unsigned long, bool)+0xfe
V [libjvm.so+0x81357c] os::pd_commit_memory(char, unsigned long, bool)+0xc
V [libjvm.so+0x80b76a] os::commit_memory(char, unsigned long, bool)+0x2a
V [libjvm.so+0x811a9d] os::pd_create_stack_guard_pages(char, unsigned long)+0x6d
V [libjvm.so+0x946cbe] JavaThread::create_stack_guard_pages()+0x5e
V [libjvm.so+0x94d754] JavaThread::run()+0x34
V [libjvm.so+0x815668] java_start(Thread*)+0x108
jvm里面的所有线程
Java Threads: ( => current thread )
=>0x00007fd5cb683800 JavaThread "pool-97706-thread-1" [_thread_new, id=55726, stack(0x00007fd565148000,0x00007fd565189000)]{刚刚上线分析的java线程}
0x00007fd5cb67f800 JavaThread "pool-97697-thread-1" [_thread_blocked, id=55724, stack(0x00007fd565391000,0x00007fd5653d2000)]{可以看出线程被锁}
0x00007fd5cb67e800 JavaThread "pool-97696-thread-1" [_thread_blocked, id=55723, stack(0x00007fd56520b000,0x00007fd56524c000)]
0x00007fd5cb67d000 JavaThread "pool-97686-thread-1" [_thread_blocked, id=55722, stack(0x00007fd565189000,0x00007fd5651ca000)]
0x00007fd5cb67b000 JavaThread "pool-97685-thread-1" [_thread_blocked, id=55721, stack(0x00007fd5651ca000,0x00007fd56520b000)]
...
0x00007fda7c443800 JavaThread "qtp1800203021-12-selector-ServerConnectorManager@5d59a011/2" [_thread_in_native, id=65, stack(0x00007fda56ccd000,0x00007fda56d0e000)]{线程正在运行}
内存的使用情况
Heap
par new generation total 655360K, used 250307K [0x00000006b0000000, 0x00000006e0000000, 0x00000006e0000000)[新生代]
eden space 524288K, 36% used [0x00000006b0000000, 0x00000006bba212c0, 0x00000006d0000000)[Eden区]
from space 131072K, 45% used [0x00000006d8000000, 0x00000006dba4fa68, 0x00000006e0000000)
to space 131072K, 0% used [0x00000006d0000000, 0x00000006d0000000, 0x00000006d8000000)[两个survivor区]
concurrent mark-sweep generation total 4456448K, used 271797K [0x00000006e0000000, 0x00000007f0000000, 0x00000007f0000000)[老年代]
concurrent-mark-sweep perm gen total 262144K, used 47058K [0x00000007f0000000, 0x0000000800000000, 0x0000000800000000)[永久代]
Card table byte_map: [0x00007fda7857f000,0x00007fda79000000] byte_map_base: 0x00007fda74fff000
[card table是jvm维护的一种数据结构，用于记录更改对象时的引用，以便gc时遍历更少的table和root。]
Code Cache [0x00007fda79000000, 0x00007fda79730000, 0x00007fda7c000000)
total_blobs=2413 nmethods=1929 adapters=436 free_code_cache=41943Kb largest_free_block=42851776
[存放本地代码缓存]
gc日志
GC Heap History (10 events):[最近10次gc事件]
Event: 93727.171 GC heap before [gc日志前]
{Heap before GC invocations=66 (full 0):
par new generation total 655360K, used 587162K [0x00000006b0000000, 0x00000006e0000000, 0x00000006e0000000)
eden space 524288K, 100% used [0x00000006b0000000, 0x00000006d0000000, 0x00000006d0000000)
from space 131072K, 47% used [0x00000006d0000000, 0x00000006d3d66b70, 0x00000006d8000000)
to space 131072K, 0% used [0x00000006d8000000, 0x00000006d8000000, 0x00000006e0000000)
concurrent mark-sweep generation total 4456448K, used 264278K [0x00000006e0000000, 0x00000007f0000000, 0x00000007f0000000)
concurrent-mark-sweep perm gen total 262144K, used 47008K [0x00000007f0000000, 0x0000000800000000, 0x0000000800000000)
Event: 93727.266 GC heap after [gc日志后]
Heap after GC invocations=67 (full 0):[程序启动以来第67次调用gc]
par new generation total 655360K, used 62286K [0x00000006b0000000, 0x00000006e0000000, 0x00000006e0000000)
eden space 524288K, 0% used [0x00000006b0000000, 0x00000006b0000000, 0x00000006d0000000)
from space 131072K, 47% used [0x00000006d8000000, 0x00000006dbcd3b10, 0x00000006e0000000)
to space 131072K, 0% used [0x00000006d0000000, 0x00000006d0000000, 0x00000006d8000000)
concurrent mark-sweep generation total 4456448K, used 265714K [0x00000006e0000000, 0x00000007f0000000, 0x00000007f0000000)
concurrent-mark-sweep perm gen total 262144K, used 47008K [0x00000007f0000000, 0x0000000800000000, 0x0000000800000000)
}
JVM内存映射
7fda82fdc000-7fda82ffc000[内存区域] r-xp[权限 r/w/x/p/s 读/写/执行/私有/共享] 00000000[文件内的偏移量] fd:0d[文件位置的majorID和minorID
] 5243254[索引节点号] /lib64/ld-2.12.so[文件位置]
7fda82ffc000-7fda82ffe000 r--s 00008000 fd:0d 5768906 /opt/jetty/jetty/lib/apache-jstl/org.apache.taglibs.taglibs-standard-spec-1.2.1.jar
7fda82ffe000-7fda8300d000 r--s 001a0000 fd:0d 5768901 /opt/jetty/jetty/lib/apache-jsp/org.eclipse.jetty.orbit.org.eclipse.jdt.core-3.8.2.v20130121.jar
7fda8300d000-7fda83016000 r--s 00251000 fd:0d 5506936 /opt/jdk/jre/lib/resources.jar
7fda83016000-7fda83018000 r--s 00019000 fd:0d 5375143 /opt/jetty/jetty/start.jar
7fda83018000-7fda83107000 rw-p 00000000 00:00 0
7fda83107000-7fda831aa000 rw-p 00000000 00:00 0
7fda831aa000-7fda831b2000 rw-s 00000000 fd:0d 5247511 /tmp/hsperfdata_root/41
7fda831b2000-7fda831b5000 ---p 00000000 00:00 0
7fda831b5000-7fda831f7000 rw-p 00000000 00:00 0
7fda831f7000-7fda831f8000 r--s 00002000 fd:0d 5768900 /opt/jetty/jetty/lib/apache-jsp/org.eclipse.jetty.apache-jsp-9.2.13.v20150730.jar
7fda831f8000-7fda831f9000 rw-p 00000000 00:00 0
7fda831f9000-7fda831fa000 r--p 00000000 00:00 0
7fda831fa000-7fda831fb000 rw-p 00000000 00:00 0
7fda831fb000-7fda831fc000 r--p 0001f000 fd:0d 5243254 /lib64/ld-2.12.so
7fda831fc000-7fda831fd000 rw-p 00020000 fd:0d 5243254 /lib64/ld-2.12.so
vm参数
VM Arguments:
jvm_args: -Djetty.home= -Djetty.base= -Dsun.rmi.transport.tcp.responseTimeout=1000 -Djava.io.tmpdir=/opt/jetty/jetty/webapps/tmp.d -Xloggc:/gc.log -Dfile.encoding=UTF-8 -Xms5120m -Xmx5120m -Xmn768m -XX:PermSize=256m -XX:MaxPermSize=256m -XX:SurvivorRatio=4 -Xss256k -Djava.net.preferIPv4Stack=true -XX:+UseParNewGC -XX:+UseAdaptiveSizePolicy -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=80 -XX:+CMSParallelRemarkEnabled -Djava.awt.headless=true -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:ParallelGCThreads=6 -XX:+DisableExplicitGC -Djetty.state=/opt/jetty/jetty/jetty.state -Djetty.logs=/opt/jetty/jetty/logs -Djetty.home=/opt/jetty/jetty -Djetty.base=/opt/jetty/jetty -Djava.io.tmpdir=/opt/jetty/jetty/webapps/tmp.d
java_command: /opt/jetty/jetty/start.jar jetty-logging.xml jetty-started.xml
Launcher Type: SUN_STANDARD
Environment Variables:
JAVA_HOME=/opt/jdk
CLASSPATH=.:/opt/jdk/lib/dt.jar:/opt/jdk/lib/tools.jar
PATH=/opt/jdk/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
此处不细述
系统信息
--------------- S Y S T E M ---------------
OS:CentOS release 6.7 (Final)[系统信息]
uname:Linux 4.9.39 #1 SMP Mon Mar 19 10:58:26 CST 2018 x86_64
libc:glibc 2.12 NPTL 2.12
rlimit: STACK 8192k, CORE infinity, NPROC 1048576, NOFILE 1048576, AS infinity
load average:0.72 0.90 1.07
/proc/meminfo:[内存信息]
MemTotal: 264033112 kB
MemFree: 188255128 kB
MemAvailable: 215839472 kB
Buffers: 2158028 kB
Cached: 26534044 kB
SwapCached: 0 kB
Active: 46946620 kB
Inactive: 25130056 kB
Active(anon): 42320448 kB
Inactive(anon): 1288664 kB
Active(file): 4626172 kB
Inactive(file): 23841392 kB
Unevictable: 0 kB
Mlocked: 0 kB
SwapTotal: 4194300 kB
SwapFree: 4194300 kB
Dirty: 8024 kB
Writeback: 0 kB
AnonPages: 43350948 kB
Mapped: 530880 kB
Shmem: 225328 kB
Slab: 1693536 kB
SReclaimable: 966800 kB
SUnreclaim: 726736 kB
KernelStack: 574464 kB
PageTables: 125512 kB
NFS_Unstable: 0 kB
Bounce: 0 kB
WritebackTmp: 0 kB
CommitLimit: 136210856 kB
Committed_AS: 91928692 kB
VmallocTotal: 34359738367 kB
VmallocUsed: 0 kB
VmallocChunk: 0 kB
HardwareCorrupted: 0 kB
AnonHugePages: 38322176 kB
ShmemHugePages: 0 kB
ShmemPmdMapped: 0 kB
CmaTotal: 0 kB
CmaFree: 0 kB
Hugepagesize: 2048 kB
DirectMap4k: 206916 kB
DirectMap2M: 18544640 kB
DirectMap1G: 251658240 kB
[cpu信息]
CPU:total 24 (6 cores per cpu, 2 threads per core) family 6 model 63 stepping 2, cmov, cx8, fxsr, mmx, sse, sse2, sse3, ssse3, sse4.1, sse4.2, popcnt, avx, avx2, aes, erms, ht, tsc, tscinvbit
/proc/cpuinfo:
processor : 0
vendor_id : GenuineIntel
cpu family : 6
model : 63
model name : Intel(R) Xeon(R) CPU E5-2620 v3 @ 2.40GHz
stepping : 2
microcode : 0x36
cpu MHz : 2294.238
cache size : 15360 KB
physical id : 0
siblings : 12
core id : 0
cpu cores : 6
apicid : 0
initial apicid : 0
fpu : yes
fpu_exception : yes
cpuid level : 15
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid dca sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm epb tpr_shadow vnmi flexpriority ept vpid fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid cqm xsaveopt cqm_llc cqm_occup_llc dtherm ida arat pln pts
bugs :
bogomips : 4788.85
clflush size : 64
cache_alignment : 64
address sizes : 46 bits physical, 48 bits virtual
power management:
processor : 1
vendor_id : GenuineIntel
cpu family : 6
