Understanding hs_err_pid.log

Liao Jiayi Liao Jiayi #Memory#Linux#JVM

A guide to JVM fatal-error logs, including thread states, native frames, and memory information.

Translated from Chinese with AI · Read the original

# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (mmap) failed to map 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.
#
# Out of Memory Error (os_linux.cpp:2673), pid=13016, tid=140682742126336
#
# JRE version: Java(TM) SE Runtime Environment (8.0_40-b25) (build 1.8.0_40-b25)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (25.40-b25 mixed mode linux-amd64 compressed oops)
# Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again

The first section describes the crash cause and possible solutions.

Current thread (0x00007ff2d8001000): JavaThread "flink-akka.remote.default-remote-dispatcher-15" daemon [_thread_new, id=31925, stack(0x00007ff340ced000,0x00007ff340dee000)]
Stack: [0x00007ff340ced000,0x00007ff340dee000], sp=0x00007ff340dec9a0, free space=1022k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V [libjvm.so+0xaaca9a] VMError::report_and_die()+0x2ba
V [libjvm.so+0x4f333b] report_vm_out_of_memory(char const*, int, unsigned long, VMErrorType, char const*)+0x8b
V [libjvm.so+0x90e8c3] os::Linux::commit_memory_impl(char*, unsigned long, bool)+0x103
V [libjvm.so+0x90e98c] os::pd_commit_memory(char*, unsigned long, bool)+0xc
V [libjvm.so+0x90772a] os::commit_memory(char*, unsigned long, bool)+0x2a
V [libjvm.so+0x90c97f] os::pd_create_stack_guard_pages(char*, unsigned long)+0x7f
V [libjvm.so+0xa52b4e] JavaThread::create_stack_guard_pages()+0x5e
V [libjvm.so+0xa5c9b4] JavaThread::run()+0x34
V [libjvm.so+0x910ee8] java_start(Thread*)+0x108
C [libpthread.so.0+0x7dc5] start_thread+0xc5

Current Thread identifies the thread running when the crash occurred. Thread type: JavaThread is one of several types:

  • JavaThread
  • VMThread: Performs VM operations, including GC.
  • CompilerThread
  • GCTaskThread
  • WatcherThread
  • ConcurrentMarkSweepThread

Thread state: _thread_new

Thread State | Description

  • | - _thread_uninitialized | Thread has not been created _thread_new | Created but not yet running _thread_in_native | Executing native code _thread_in_vm | Executing VM code _thread_in_java | Executing Java code _thread_blocked | Blocked thread

Native frames: Stack information mainly from JVM native libraries; an important part of crash analysis.

Java Threads: ( => current thread )
=>0x00007ff2d8001000 JavaThread "flink-akka.remote.default-remote-dispatcher-15" daemon [_thread_new, id=31925, stack(0x00007ff340ced000,0x00007ff340dee000)]
0x00007ff2ec053800 JavaThread "Hashed wheel timer #1" daemon [_thread_blocked, id=14219, stack(0x00007ff33bdfe000,0x00007ff33beff000)]
0x00007ff2dc130800 JavaThread "New I/O server boss #6" daemon [_thread_in_native, id=14218, stack(0x00007ff33beff000,0x00007ff33c000000)]
0x00007ff2dc119800 JavaThread "New I/O worker #5" daemon [_thread_in_native, id=14217, stack(0x00007ff3400e3000,0x00007ff3401e4000)]
0x00007ff2dc0b6000 JavaThread "New I/O worker #4" daemon [_thread_in_native, id=14216, stack(0x00007ff3401e4000,0x00007ff3402e5000)]
0x00007ff2dc0bb800 JavaThread "New I/O boss #3" daemon [_thread_in_native, id=14215, stack(0x00007ff3402e5000,0x00007ff3403e6000)]
0x00007ff2dc05c000 JavaThread "New I/O worker #2" daemon [_thread_in_native, id=14214, stack(0x00007ff3403e6000,0x00007ff3404e7000)]
0x00007ff2dc052000 JavaThread "New I/O worker #1" daemon [_thread_in_native, id=14213, stack(0x00007ff3404e7000,0x00007ff3405e8000)]
0x00007ff2c8009800 JavaThread "flink-akka.remote.default-remote-dispatcher-7" daemon [_thread_in_vm, id=14206, stack(0x00007ff3407e8000,0x00007ff3408e9000)]
0x00007ff2c800c000 JavaThread "flink-akka.remote.default-remote-dispatcher-6" daemon [_thread_in_native, id=14202, stack(0x00007ff3408e9000,0x00007ff3409ea000)]
0x00007ff2cc020000 JavaThread "flink-akka.actor.default-dispatcher-5" daemon [_thread_blocked, id=14147, stack(0x00007ff3409ea000,0x00007ff340aeb000)]
0x00007ff36222a800 JavaThread "flink-akka.actor.default-dispatcher-4" daemon [_thread_blocked, id=14136, stack(0x00007ff340aeb000,0x00007ff340bec000)]
0x00007ff362229000 JavaThread "flink-akka.actor.default-dispatcher-3" daemon [_thread_blocked, id=14135, stack(0x00007ff340bec000,0x00007ff340ced000)]
0x00007ff362183000 JavaThread "flink-scheduler-1" daemon [_thread_blocked, id=14044, stack(0x00007ff340fee000,0x00007ff3410ef000)]
0x00007ff3614b4000 JavaThread "Timer for 'phoenix' metrics system" daemon [_thread_blocked, id=14032, stack(0x00007ff342dfa000,0x00007ff342efb000)]
0x00007ff360fc1000 JavaThread "main-EventThread" daemon [_thread_blocked, id=14031, stack(0x00007ff3431fc000,0x00007ff3432fd000)]
0x00007ff360faf000 JavaThread "main-SendThread(cnzk2:2181)" daemon [_thread_in_native, id=14030, stack(0x00007ff3432fd000,0x00007ff3433fe000)]
0x00007ff360471000 JavaThread "Thread-80" daemon [_thread_blocked, id=14029, stack(0x00007ff3430fb000,0x00007ff3431fc000)]
0x00007ff3608a7000 JavaThread "IPC Parameter Sending Thread #0" daemon [_thread_blocked, id=13178, stack(0x00007ff3437fe000,0x00007ff3438ff000)]
0x00007ff3608a4000 JavaThread "IPC Client (1508059488) connection to cnhm0/10.0.1.222:8032 from apps" daemon [_thread_blocked, id=13177, stack(0x00007ff348923000,0x00007ff348a24000)]
0x00007ff3600df800 JavaThread "Service Thread" daemon [_thread_blocked, id=13172, stack(0x00007ff3498c5000,0x00007ff3499c6000)]
0x00007ff3600d2000 JavaThread "C1 CompilerThread2" daemon [_thread_in_native, id=13171, stack(0x00007ff3499c6000,0x00007ff349ac7000)]
0x00007ff3600d0000 JavaThread "C2 CompilerThread1" daemon [_thread_blocked, id=13170, stack(0x00007ff349ac7000,0x00007ff349bc8000)]
0x00007ff3600cd000 JavaThread "C2 CompilerThread0" daemon [_thread_blocked, id=13169, stack(0x00007ff349bc8000,0x00007ff349cc9000)]
0x00007ff3600cb000 JavaThread "JDWP Event Helper Thread" daemon [_thread_blocked, id=13168, stack(0x00007ff349cc9000,0x00007ff349dca000)]
0x00007ff3600c7000 JavaThread "JDWP Transport Listener: dt_socket" daemon [_thread_in_native, id=13167, stack(0x00007ff349dca000,0x00007ff349ecb000)]
0x00007ff3600b8000 JavaThread "Signal Dispatcher" daemon [_thread_blocked, id=13166, stack(0x00007ff34a0cf000,0x00007ff34a1d0000)]
0x00007ff36008c000 JavaThread "Finalizer" daemon [_thread_blocked, id=13165, stack(0x00007ff34a1d0000,0x00007ff34a2d1000)]
0x00007ff36008a000 JavaThread "Reference Handler" daemon [_thread_blocked, id=13164, stack(0x00007ff34a2d1000,0x00007ff34a3d2000)]
0x00007ff360017000 JavaThread "main" [_thread_blocked, id=13158, stack(0x00007ff369c7a000,0x00007ff369d7b000)]
Other Threads:
0x00007ff360085000 VMThread [stack: 0x00007ff34a3d2000,0x00007ff34a4d3000] [id=13163]
0x00007ff3600e2000 WatcherThread [stack: 0x00007ff3497c4000,0x00007ff3498c5000] [id=13173]

This section lists all Java threads at the time of the crash. Analyze it similarly to the previous section.

VM state:not at safepoint (normal execution)
VM Mutex/Monitor currently owned by a thread: None

VM state:

State | Description

  • | :-: | not at a safepoint | Normal execution at safepoint | All VM threads are blocked, waiting for a VM operation to finish synchronizing | The VM is waiting for all threads to block before a special operation
Heap:
PSYoungGen total 39424K, used 31166K [0x0000000771a00000, 0x0000000774780000, 0x00000007c0000000)
eden space 38912K, 79% used [0x0000000771a00000,0x000000077384faf0,0x0000000774000000)
from space 512K, 25% used [0x0000000774680000,0x00000007746a0000,0x0000000774700000)
to space 512K, 0% used [0x0000000774700000,0x0000000774700000,0x0000000774780000)
ParOldGen total 124928K, used 67043K [0x00000006d4e00000, 0x00000006dc800000, 0x0000000771a00000)
object space 124928K, 53% used [0x00000006d4e00000,0x00000006d8f78d18,0x00000006dc800000)
Metaspace used 54122K, capacity 54748K, committed 54912K, reserved 1097728K
class spaceused 6562K, capacity 6716K, committed 6784K, reserved 1048576K
Card table byte_map: [0x00007ff3664db000,0x00007ff366c35000] byte_map_base: 0x00007ff362e34000
Marking Bits: (ParMarkBitMap*) 0x00007ff3691426c0
Begin Bits: [0x00007ff324a70000, 0x00007ff328538000)
End Bits: [0x00007ff328538000, 0x00007ff32c000000)
Polling page: 0x00007ff369d84000
CodeCache: size=245760Kb used=17958Kb max_used=18385Kb free=227801Kb
bounds [0x00007ff34aad9000, 0x00007ff34bd29000, 0x00007ff359ad9000]
total_blobs=6019 nmethods=5425 adapters=516
compilation: enabled
  • Card Table: A JVM structure tracking reference changes to support GC.
  • CodeCache: Stores native code and is separate from PermGen.
Compilation events (10 events):
GC Heap History (10 events):
Deoptimization events (10 events):
Internal exceptions (10 events):
Events (10 events):
Dynamic libraries:

These entries describe recent JVM activity before the crash. For example:

Events (10 events):
Event: 2603309.010 Thread 0x00007ff2c800c000 DEOPT UNPACKING pc=0x00007ff34aaddf69 sp=0x00007ff3409e88a8 mode 2
Event: 2603310.108 Thread 0x00007ff362229000 DEOPT PACKING pc=0x00007ff34b25ce6c sp=0x00007ff340ceb660
Event: 2603310.122 Thread 0x00007ff2c8009800 Uncommon trap: trap_request=0xffffff65 fr.pc=0x00007ff34b890e40
Event: 2603310.124 Thread 0x00007ff2c8009800 DEOPT PACKING pc=0x00007ff34b890e40 sp=0x00007ff3408e7790
Event: 2603310.124 Thread 0x00007ff2c8009800 DEOPT UNPACKING pc=0x00007ff34aaddf69 sp=0x00007ff3408e7680 mode 2
Event: 2603310.125 Thread 0x00007ff2c8009800 Uncommon trap: trap_request=0xffffff65 fr.pc=0x00007ff34b850fe4
Event: 2603310.125 Thread 0x00007ff2c8009800 DEOPT PACKING pc=0x00007ff34b850fe4 sp=0x00007ff3408e7560
Event: 2603310.125 Thread 0x00007ff2c8009800 DEOPT UNPACKING pc=0x00007ff34aaddf69 sp=0x00007ff3408e72d8 mode 2
Event: 2603310.126 Thread 0x00007ff362229000 DEOPT UNPACKING pc=0x00007ff34aaddf69 sp=0x00007ff340ceb628 mode 2
Event: 2603310.935 Thread 0x00007ff2d8001000 Thread added: 0x00007ff2d8001000

The example shows the latest ten runtime VM events. In the first entry, 2603309.010 is seconds since VM startup, pc is the program counter, and sp is the stack pointer. This issue explains DEOPT and uncommon traps. Broadly, deoptimization occurs when runtime behavior invalidates a compiler optimization.

--------------- S Y S T E M ---------------
OS:Amazon Linux AMI release 2016.03
uname:Linux 4.4.11-23.53.amzn1.x86_64 #1 SMP Wed Jun 1 22:22:50 UTC 2016 x86_64
libc:glibc 2.17 NPTL 2.17
rlimit: STACK 8192k, CORE 0k, NPROC 65536, NOFILE 65536, AS infinity
load average:10.84 2.76 1.17
/proc/meminfo:
MemTotal: 15403948 kB
MemFree: 2637700 kB
MemAvailable:2571132 kB
Buffers: 304 kB
Cached:13784 kB
SwapCached:0 kB
Active: 12625320 kB
Inactive: 7684 kB
Active(anon): 12619252 kB
Inactive(anon): 336 kB
Active(file): 6068 kB
Inactive(file): 7348 kB
Unevictable: 0 kB
Mlocked: 0 kB
SwapTotal: 0 kB
SwapFree: 0 kB
Dirty:16 kB
Writeback:56 kB
AnonPages: 12606968 kB
Mapped:10896 kB
Shmem: 356 kB
Slab: 46004 kB
SReclaimable: 22384 kB
SUnreclaim:23620 kB
KernelStack:9856 kB
PageTables:38084 kB
NFS_Unstable: 0 kB
Bounce:0 kB
WritebackTmp: 0 kB
CommitLimit: 7701972 kB
Committed_AS: 18337652 kB
VmallocTotal: 34359738367 kB
VmallocUsed: 0 kB
VmallocChunk: 0 kB
AnonHugePages: 0 kB
HugePages_Total: 0
HugePages_Free:0
HugePages_Rsvd:0
HugePages_Surp:0
Hugepagesize: 2048 kB
DirectMap4k: 12288 kB
DirectMap2M:15716352 kB

System memory information:

Term | Description | Term | Description | Term | Description

  • | :-: | :-: | :-: | :-: | :- MemToal | Total memory | MemFree | Unused memory | MemAvailable | Available memory Buffers | File I/O buffers | Cached | Cache | SwapCached | Cached swap Active | Recently used memory | Inactive | Memory not recently used | Active(anon) | .. Inactive(anon) | .. | Active(file) | .. | Inactive(file) | .. Unevictable | .. | Unevictable | .. | Mlocked | .. SwapTotal | Total swap | SwapFree | Available swap | Dirty | Memory awaiting disk write Writeback | Memory being written to disk | AnonPages | .. | Mapped | .. Shmem | .. | Slab | Kernel allocation | Sreclaimable | .. SUnreclaim | .. | KernelStack | .. | PageTables | Page-table memory NFS_Unstable | .. | Bounce | .. | WritebackTmp | .. CommitLimit | .. | Committed_AS | Worst-case memory commitment for the workload | VmallocTotal | .. VmallocUsed | Mappable virtual address space | VmallocUsed | Used virtual mappings | VmallocChunk | Largest available virtual-memory block AnonHugePages | .. | HugePages_Total | .. | HugePages_Free | .. HugePages_Rsvd | .. | HugePages_Surp | .. | Hugepagesize | .. DirectMap4k | .. | DirectMap2M | ..