Java SE 6 故障排除指南 – 附录C、JVM 致命错误日志格式

本文翻译自:http://www.oracle.com/technetwork/java/javase/felog-138657.html
本文内容基于 Java SE 6,HotSpot JVM。

当一个致命错误发生时,一个错误日志将被创建,存储了在致命错误发生时获取到的信息和状态。

注意:这个文件的格式可能随着版本的更新而改变。

C.1 致命错误日志位置

产品标志 -XX:ErrorFile=file 可以指定文件在哪里创建,file 表示了文件位置的完整路径。file 里的子字符串 %% 将被转换为 %%p 将被转换为进程ID。

在下面的例子里,错误日志文件将被写到 /var/log/java 目录、被命名为 java_errorPid.log :java -XX:ErrorFile=/var/log/java/java_error%p.log

如果 -XX:ErrorFile=file 标志没有指定,默认的文件名是 hs_err_pid.log,pid是进程ID。

另外,如果没有指定 -XX:ErrorFile=file 标志,系统尝试在进程的工作目录创建文件。万一不能在工作目录创建文件(空间不足、权限问题或其他问题),文件将在操作系统的临时目录里创建。在Solaris和Linux上临时目录是 /tmp。在Windows上临时目录由环境变量 TMP 指定;如果那个环境变量没有指定,将使用 TEMP 环境变量。

C.2 致命错误日志描述

错误日志包含在致命错误发生时获取到的信息,如果可能,包括下面的信息:

  • 操作异常或激起致命错误的信号
  • 版本信息和配置信息
  • 激起致命错误的线程细节和线程的栈痕迹trace
  • 正在运行的线程列表和它们的状态
  • 堆的概要信息
  • 已加载的本地类库(native libraries)列表
  • 命令行参数
  • 环境变量
  • 操作系统和CPU的细节

注意:在某些情况下,只有这些信息的子集会被输出到错误日志。这在致命错误非常严重以至于错误处理器没法回复并报告所有细节。

错误日志是一个文本文件保护下面的章节:

  • 一个头提供了崩溃的简要描述。
  • 一个章节描述了线程信息。
  • 一个章节描述了进程信息。
  • 一个章节描述了系统信息。

注意:这个致命错误日志描述的格式是基于Java SE 6。格式在不同的发布版之间可能不同。

继续阅读

GC 日志分析

不同的JVM及其选项会输出不同的日志。

GC 日志

生成下面日志使用的选项:-XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:d:/GClogs/tomcat6-gc.log

4.231: [GC 4.231: [DefNew: 4928K->512K(4928K), 0.0044047 secs] 6835K->3468K(15872K), 0.0045291 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
 
4.445: [Full GC (System) 4.445: [Tenured: 2956K->3043K(10944K), 0.1869806 secs] 4034K->3043K(15872K), [Perm : 3400K->3400K(12288K)], 0.1870847 secs] [Times: user=0.05 sys=0.00, real=0.19 secs] 

最前面的数字 4.2314.445 代表虚拟机启动以来的秒数。

[GC[Full GC 是垃圾回收的停顿类型,而不是区分是新生代还是年老代,如果有 Full 说明发生了 Stop-The-World 。如果是调用 System.gc() 触发的,那么将显示的是 [Full GC (System)

接下来的 [DefNew, [Tenured, [Perm 表示 GC 发生的区域,区域的名称与使用的 GC 收集器相关。
Serial 收集器中新生代名为 “Default New Generation”,显示的名字为 “[DefNew”。对于ParNew收集器,显示的是 “[ParNew”,表示 “Parallel New Generation”。 对于 Parallel Scavenge 收集器,新生代名为 “PSYoungGen”。年老代和永久代也相同,名称都由收集器决定。

方括号内部显示的 “4928K->512K(4928K)” 表示 “GC 前该区域已使用容量 -> GC 后该区域已使用容量 (该区域内存总容量) ”。

再往后的 “0.0044047 secs” 表示该区域GC所用时间,单位是秒。

再往后的 “6835K->3468K(15872K)” 表示 “GC 前Java堆已使用容量 -> GC后Java堆已使用容量 (Java堆总容量)”。

再往后的 “0.0045291 secs” 是Java堆GC所用的总时间。

最后的 “[Times: user=0.00 sys=0.00, real=0.00 secs]” 分别代表 用户态消耗的CPU时间、内核态消耗的CPU时间 和 操作从开始到结束所经过的墙钟时间。墙钟时间包括各种非运算的等待耗时,如IO等待、线程阻塞。CPU时间不包括等待时间,当系统有多核时,多线程操作会叠加这些CPU时间,所以user或sys时间会超过real时间。

堆的分代

JVM-heap-generations

在上图中:

  • young区域就是新生代,存放新创建对象;
  • tenured是年老代,存放在新生代经历多次垃圾回收后仍存活的对象;
  • perm是永生代,存放类定义信息、元数据等信息。

当GC发生在新生代时,称为Minor GC,次收集;当GC发生在年老代时,称为Major GC,主收集。 一般的,Minor GC的发生频率要比Major GC高很多。

JVM GC 相关的选项

-XX:+PrintGC 输出GC日志
-XX:+PrintGCDetails 输出GC的详细日志
-XX:+PrintGCTimeStamps 输出GC的时间戳(以基准时间的形式)
-XX:+PrintGCDateStamps 输出GC的时间戳(以日期的形式,如 2013-05-04T21:53:59.234+0800)
-XX:+PrintHeapAtGC 在进行GC的前后打印出堆的信息
-Xloggc:../logs/gc.log 日志文件的输出路径

欢迎关注我的微信公众号: coderbee笔记,可以更及时回复你的讨论。

JVM 类加载机制

虚拟机类加载机制:把描述类的数据从class文件加载到内存,并对数据进行校验、转换解析和初始化,最终形成可以被虚拟机直接使用的 Java 类型。

在Java语言里面,类型的加载、连接和初始化都是在程序运行期间完成的。

类加载的时机

类的整个生命周期包括:加载(loading)、验证(verification)、准备(preparation)、解析(resolution)、初始化(initialization)、使用(using)和卸载(unloading) 7个阶段。其中 验证、准备、解析 3个部分统称连接(linking)。

class life cycle

5种必须立即初始化的情况:

  1. 遇到new, getstatic, putstatic 或 invokestatic 这4挑字节码指令;
  2. 使用 java.lang.reflect 包的方法对类进行反射调用;
  3. 初始化一个类的时候,其父类还没有初始化,必须先触发其父类的初始化;(对于接口,只有在真正用到其父接口的时候才会初始化)
  4. 虚拟机启动时,用户指定要执行的主类;
  5. 当使用 JDK 1.7 的动态语言支持时,如果一个 java.lang.invoke.MethodHandle 实例最后的解析结果 REF_getStatic, REF_putStatic, REF_invokeStatic 的方法句柄,并且这个方法句柄锁对应的类没有进行出事,则需要先触发其初始化。

对于静态字段,只有直接定义这个字段的类才会被初始化。
继续阅读

HotSpot 垃圾回收算法实现

《深入理解Java虚拟机:JVM高级特性与最佳实践》-笔记

垃圾回收算法

枚举根结点

一致性

在可达性分析期间整个系统看起来就像被冻结在某个时间点上,不可以出现分析过程中对象引用关系还在不断变化的情况。

一致性要求导致GC进行时必须停顿所有Java执行线程。(Stop The World)
即使在号称不会发生停顿的CMS收集器中,枚举根节点时也是必须停顿的。

HotSpot使用的是准确式GC,当执行系统停顿下来后,并不需要一个不漏地检查完所有执行上下文和全局的引用位置,这是通过一组称为OopMap的数据结构来达到的。

在类加载完成后,HotSpot就把对象内什么偏移量上是什么类型的数据计算出来;在JIT编译过程中,也会在特定的位置记录下栈和寄存器中哪些位置是引用。
继续阅读