暂无图片
暂无图片
1
暂无图片
暂无图片
暂无图片
首页 / JVM Crash日志分析

JVM Crash日志分析

IT那活儿 2021-07-31
8432
JVM Crash即JAVA应用程序在运行过程中因为某些致命错误导致JVM崩溃，JAVA进程非正常退出。应用程序错误，JVM参数设置不当，服务资源不足，jni调用错误，java虚拟机自身bug等等，都可能是导致JVM Crash的元凶。那么如何分析此类故障呢?

hs_err_pid<pid>.log日志文件获取

当JVM Crash发生时，Java虚拟机会自动产生一个快照，记录故障时刻系统的各类运行信息，即hs_err_pid<pid>.log日志。缺省情况下该日志文件会产生在工作目录下，当然我们也可以通过JVM参数指定文件生成路径：
-XX:ErrorFile=./hs_err_pid<pid>.log

Carsh日志文件分析

日志文件记录了11类关键信息，如果在不是很熟悉日志结构的情况下，往往不容易抓住重点。下面用一个实际的crash日志来逐步揭开它的面纱。
  • 日志头
日志头文件包含概要信息，简述了导致crash的原因。
如上图为一个日志投文件信息，此处有一个重要信息” SIGBUS (0x7)”,SIGBUS(Bus error)意味着指针所对应的地址是有效地址，但总线不能正常使用该指针，通常是未对齐的数据访问所致。其中SIGBUG为信号名，0x7是信号码，pc=0x0000003267c8995b指的是程序计数器的值，pid=60801是进程号，tid=0x00002b5e1ab2a700是线程号。另外，还有一个重要信息，问题帧的信息：
这表示Crash时JVM正在从那个库文件执行代码，这里”C”表示Native C frame，除此之外，还有可能是“j”、“V”、“v”，它们分别表示：
j: Interpreted Java frame
V: VMframe
v: VMgenerated stub frame
J: Other frame types, including compiled Java frames
  • 导致crash的线程信息
文件下面是导致crash的线程信息和该线程栈信息，这部分内容包含触发 JVM 致命错误的线程详细信息和线程栈。
以上表示导致出错的线程是0x00002b62e8028000（指针），线程类型是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
后面的"HsfServerHandler-xx.xxx.x.xx:10250-thread-300"表示线程名，“daemon”表示该线程为守护线程，再后面的“[_thread_in_native”表示线程当前状态，关于该描述其它类型还可能是：
  • _thread_uninitialized：
    线程还没有创建，它只在内存原因崩溃的时候才出现
  • _thread_new：
    线程已经被创建，但是还没有启动
  • _thread_in_native：
    线程正在执行本地代码，一般这种情况很可能是本地代码有问题
  • _thread_in_vm：
    线程正在执行虚拟机代码
  • _thread_in_Java：
    线程正在执行解释或者编译后的Java代码
  • _thread_blocked：
    线程处于阻塞状态
  • …_trans：
    以_trans结尾，线程正处于要切换到其它状态的中间状态
最后的“id=56005”表示线程ID，stack(0x00002b5e1aa2a000,0x00002b5e1ab2b000)表示栈区间。“siginfo:si_signo=SIGBUS: si_errno=0, si_code=2 (BUS_ADRERR), si_addr=0x00002b5de3cda000”这部分是导致虚拟机终止的非预期的信号信息：其中si_errno和si_code是Linux下用来鉴别异常的，Windows下是一个ExceptionCode。
上图为栈顶程序计数器旁的操作码，它们可以被反汇编成系统崩溃前执行的指令。
上图为线程栈信息。包含了地址、栈顶、栈计数器和线程尚未使用的栈信息。到这里就基本上已经确定了问题所在原因了。
  • 全量线程信息
所有线程信息，其中_thread_blocked表示阻塞。
  • 安全点和锁信息
虚拟机状态。not at safepoint 表示正常运行。其余状态：- at safepoint：所有线程都因为虚拟机等待状态而阻塞，等待一个虚拟机操作完成；- synchronizing：一个特殊的虚拟机操作，要求虚拟机内的其它线程保持等待状态。
虚拟机的 Mutex 和 Monito r目前没有被线程持有。Mutex 是虚拟机内部的锁，而 Monitor 则关联到了 Java 对象。
  • 堆信息
新生代、老年代、持久代空间间一目了然。
  • 本地代码缓存
一块用于编译和保存本地代码的内存。
  • 编译事件
记录10次编译事件。
  • gc相关记录
记录10次 JVM堆GC情况。
  • jvm内存映射
这些信息是虚拟机崩溃时的虚拟内存列表区域。它可以告诉你崩溃时哪些类库正在被使用，位置在哪里，还有堆栈和守护页信息。
  • 00400000-00401000：内存区域
  • r-xp：权限，r/w/x/p/s分别表示读/写/执行/私有/共享
  • 00000000：文件内的偏移量
  • c7:427a：文件位置的majorID和minorID
  • 2130：索引节点号
  • /weblogic/jdk1.7.0_141/bin/java：文件位置
  • jvm启动参数
jvm 虚拟机参数和环境变量信息。
  • 服务器信息
服务器CPU、MEM相关信息。
至此，一份JVM Crash日志就拆解完了，触发致命错误的操作异常或者信号信息，版本和配置信息，触发致命异常的线程详细信息和线程栈，当前运行的线程列表和它们的状态，堆信息，加载的本地库信息，JVM参数信息，操作系统 C信息……可以看到日志信息丰富、详尽。了解和掌握Crash日志内容了，那么此类问题追因溯源，自然也就得心应手了。
END

更多精彩干货分享

点击下方名片关注

IT那活儿

数据库
文章转载自IT那活儿，如果涉嫌侵权，请发送邮件至：contact@modb.pro进行举报，并提供相关证据，一经查实，墨天轮将立刻删除相关内容。

评论