JVM 堆日志查看，参数，快照

作者: dinel | 来源:发表于2020-03-31 11:24 被阅读0次

JVM 堆日志查看，参数，快照
JVM性能监控工具介绍
JVM常用参数配置
垃圾回收机制算法分析
代码验证手动触发 Full GC
JVM-3 虚拟机性能监控和故障处理工具
JVM配置说明&查看和修改JVM某线程的各种配置值
JVM性能调优实战(一) - 基于JDK命令行的监控
《深入理解JVM虚拟机》 - VM性能分析工具与案例分析
常用JVM调优命令

1. 初始运行时VM

-Xmx2m -Xms2m -XX:+PrintGCDetails -XX:+PrintHeapAtGC -XX:+HeapDumpOnOutOfMemoryError  -XX:+PrintCommandLineFlags

说明: 此处尝试给1M 但是最小
totalMemory(-Xms) = 1.9375MB
maxMemory(-Xmx) = 1.9375MB

1.1 JVM堆参数列表

参数	含义
-Xms	初始堆大小（默认物理内存的64分之一）
-Xmx	最大堆空间（默认物理内存的4分之一）
-Xmn	设置新生代大小
-XX:SurvivorRatio	设置新生代eden空间和from/to空间的比例关系
-XX:PermSize	方法区初始大小
-XX:MaxPermSize	方法区最大大小
-XX:MetaspaceSize	元空间GC阈值（JDK1.8）
-XX:MaxMetaspaceSize	最大元空间大小（JDK1.8）
-Xss	栈大小
-XX:MaxDirectMemorySize	直接内存大小，默认为最大堆空间
-XX:MaxTenuringThreshold=15	新生代每次GC之后如果对象没有被回收，则年龄加1，默认情况下为15（一般用不到）

1.1.1 非JDK1.8参数说明

图片.png

参数说明:
Yong Generation Space 新生区： Young/New
eden space 伊甸区
from space 幸存0区
to space 幸存1区
Tenure Generation Space 养老区：Old/Tenure
Permanent Space 永久区：Perm

1.1.2 堆内存所占比例

图片.png

1.1.3 jdk1.7中堆包含内容情况(永久代是在堆中的)

图片.png

1.1.4 jdk1.8中堆包含内容情况(元空间替代了永久代)

图片.png

1.1.5 JVM堆空间说明

{Heap before GC invocations=1 (full 0):
 def new generation   total 576K, used 470K [0x04e00000, 0x04ea0000, 0x04ea0000)
  eden space 512K,  79% used [0x04e00000, 0x04e65938, 0x04e80000)
  from space 64K, 100% used [0x04e90000, 0x04ea0000, 0x04ea0000)
  to   space 64K,   0% used [0x04e80000, 0x04e80000, 0x04e90000)
 tenured generation   total 1408K, used 374K [0x04ea0000, 0x05000000, 0x05000000)
   the space 1408K,  26% used [0x04ea0000, 0x04efdb40, 0x04efdc00, 0x05000000)
 Metaspace       used 78K, capacity 2242K, committed 2368K, reserved 4480K

def new generation：新生代
eden space ：新生代中的伊甸区
from space ：新生代中的幸存0区
to space ：新生代中的幸存1区
tenured generation ：养老区
Metaspace ：元空间
used：加载的类的空间量。
capacity：当前分配块的元数据的空间。
committed：空间块的数量。
reserved：元数据的空间保留的量。

在java8中，永久代已经被移除，被一个称为元空间的区域所取代。元空间的本质和永久代类似。
元空间与永久代之间最大的区别在于：
永久代使用的JVM的堆内存，但是java8以后的元空间并不在虚拟机中而是使用本机物理内存。
因此，默认情况下，元空间的大小仅受本地内存限制。类的元数据放入native memory，字符串常量池和类的静态变量放入java堆中，这样可以加载多少类的元数据就不在由MaxPermSize控制，而由系统的实际可以空间来控制。

1.1.6 MinorGC的过程

1.eden、SurvivorFrom复制到SurvivorTo，年龄+1
首先，当Eden区满的时候会触发第一次GC，把还活着的对象拷贝到SurvivorFrom区，当Eden区再次出发GC的时候会扫描Eden区和From区域，对这两个区域进行垃圾回收，经过这次回收后还存货的对象，则直接复制到To区域（如果有对象年龄已经达到了老年的标准，则复制到老年代），同时把这些对象的年龄+1.

2.清空eden、SurvivorFrom：
然后，清空Eden和SurivorFrom中的对象，也即复制之后有交换，谁空谁是to。

3.SurvivorTo和SurvivorFrom互换：
随后，SurvivorTo和SurvivorFrom互换，原SurvivorTo成为下一次GC时的SurvivorFrom区。部分对象会在From和To区域中复制来复制区，如此交换15次（由JVM参数MaxTenuringThreshold决定，这个参数默认为15），最终如果还是存活，就存入到老年代。

说明: 每次轻GC后From 与TO的角色互换，TO用来保存存活下来的对象，15次后依然存活的进入养老区，此处有个问题，其实JVM 对幸存区分配的空间不大，如果对象比较大，JVM就不按照上面的流程处理。

图片.png

说明:上图没看懂，但是大对象如果无法保存在新生代，将会保存在养老区，如果养老区无法保存，将执行Full GC,对养老区进行清理。

1.2 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	日志文件的输出路径
-XX:+HeapDumpOnOutOfMemoryError	生成快照文件
-XX:+PrintFlagsInitial	打印JVM初始化参数。（看不懂）
-XX:+PrintFlagsFinal	标记人为修改过的参数。
-XX:+PrintCommandLineFlags	查看默认垃圾回收器。

1.3 JVM计算内存分配情况

计算内存情况	含义
2048kb * 2/3 =1365kb	老年代
2048kb 1/3 8/10 = 546kb	伊甸园
2048kb 1/3 1/10 = 68kb	from to

1.3.1测试代码

public class HeapTest {
    public static void main(String[] args) {
        List<String> list = new ArrayList<String>();
        long totalMemory = Runtime.getRuntime().totalMemory();
        long maxMemory = Runtime.getRuntime().maxMemory();
        System.out.println("totalMemory(-Xms) = "+ (totalMemory/(double)1024/1024) +"MB");
        System.out.println("maxMemory(-Xmx) = "+ (maxMemory/(double)1024/1024) +"MB");
        while(true){
            list.add("test");
        }
    }
}

1.3.2 日志输出结果

-XX:+HeapDumpOnOutOfMemoryError -XX:InitialHeapSize=2097152 -XX:MaxHeapSize=2097152 -XX:+PrintCommandLineFlags -XX:+PrintGCDetails -XX:+PrintHeapAtGC -XX:-UseLargePagesIndividualAllocation 
{Heap before GC invocations=0 (full 0):
 def new generation   total 576K, used 512K [0x04e00000, 0x04ea0000, 0x04ea0000)
  eden space 512K, 100% used [0x04e00000, 0x04e80000, 0x04e80000)
  from space 64K,   0% used [0x04e80000, 0x04e80000, 0x04e90000)
  to   space 64K,   0% used [0x04e90000, 0x04e90000, 0x04ea0000)
 tenured generation   total 1408K, used 0K [0x04ea0000, 0x05000000, 0x05000000)
   the space 1408K,   0% used [0x04ea0000, 0x04ea0000, 0x04ea0200, 0x05000000)
 Metaspace       used 64K, capacity 2240K, committed 2240K, reserved 4480K
[GC (Allocation Failure) [DefNew: 512K->64K(576K), 0.0014505 secs] 512K->438K(1984K), 0.0015239 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=1 (full 0):
 def new generation   total 576K, used 64K [0x04e00000, 0x04ea0000, 0x04ea0000)
  eden space 512K,   0% used [0x04e00000, 0x04e00000, 0x04e80000)
  from space 64K, 100% used [0x04e90000, 0x04ea0000, 0x04ea0000)
  to   space 64K,   0% used [0x04e80000, 0x04e80000, 0x04e90000)
 tenured generation   total 1408K, used 374K [0x04ea0000, 0x05000000, 0x05000000)
   the space 1408K,  26% used [0x04ea0000, 0x04efdb40, 0x04efdc00, 0x05000000)
 Metaspace       used 64K, capacity 2240K, committed 2240K, reserved 4480K
}
totalMemory(-Xms) = 1.9375MB
maxMemory(-Xmx) = 1.9375MB
{Heap before GC invocations=1 (full 0):
 def new generation   total 576K, used 470K [0x04e00000, 0x04ea0000, 0x04ea0000)
  eden space 512K,  79% used [0x04e00000, 0x04e65938, 0x04e80000)
  from space 64K, 100% used [0x04e90000, 0x04ea0000, 0x04ea0000)
  to   space 64K,   0% used [0x04e80000, 0x04e80000, 0x04e90000)
 tenured generation   total 1408K, used 374K [0x04ea0000, 0x05000000, 0x05000000)
   the space 1408K,  26% used [0x04ea0000, 0x04efdb40, 0x04efdc00, 0x05000000)
 Metaspace       used 78K, capacity 2242K, committed 2368K, reserved 4480K
[GC (Allocation Failure) [DefNew: 470K->64K(576K), 0.0007815 secs] 845K->618K(1984K), 0.0008024 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=2 (full 0):
 def new generation   total 576K, used 64K [0x04e00000, 0x04ea0000, 0x04ea0000)
  eden space 512K,   0% used [0x04e00000, 0x04e00000, 0x04e80000)
  from space 64K, 100% used [0x04e80000, 0x04e90000, 0x04e90000)
  to   space 64K,   0% used [0x04e90000, 0x04e90000, 0x04ea0000)
 tenured generation   total 1408K, used 554K [0x04ea0000, 0x05000000, 0x05000000)
   the space 1408K,  39% used [0x04ea0000, 0x04f2aa20, 0x04f2ac00, 0x05000000)
 Metaspace       used 78K, capacity 2242K, committed 2368K, reserved 4480K
}
{Heap before GC invocations=2 (full 0):
 def new generation   total 576K, used 382K [0x04e00000, 0x04ea0000, 0x04ea0000)
  eden space 512K,  62% used [0x04e00000, 0x04e4fbc8, 0x04e80000)
  from space 64K, 100% used [0x04e80000, 0x04e90000, 0x04e90000)
  to   space 64K,   0% used [0x04e90000, 0x04e90000, 0x04ea0000)
 tenured generation   total 1408K, used 554K [0x04ea0000, 0x05000000, 0x05000000)
   the space 1408K,  39% used [0x04ea0000, 0x04f2aa20, 0x04f2ac00, 0x05000000)
 Metaspace       used 78K, capacity 2242K, committed 2368K, reserved 4480K
[GC (Allocation Failure) [DefNew: 382K->0K(576K), 0.0007340 secs] 937K->803K(1984K), 0.0007492 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=3 (full 0):
 def new generation   total 576K, used 0K [0x04e00000, 0x04ea0000, 0x04ea0000)
  eden space 512K,   0% used [0x04e00000, 0x04e00000, 0x04e80000)
  from space 64K,   0% used [0x04e90000, 0x04e90000, 0x04ea0000)
  to   space 64K,   0% used [0x04e80000, 0x04e80000, 0x04e90000)
 tenured generation   total 1408K, used 803K [0x04ea0000, 0x05000000, 0x05000000)
   the space 1408K,  57% used [0x04ea0000, 0x04f68ef8, 0x04f69000, 0x05000000)
 Metaspace       used 78K, capacity 2242K, committed 2368K, reserved 4480K
}
{Heap before GC invocations=3 (full 0):
 def new generation   total 576K, used 277K [0x04e00000, 0x04ea0000, 0x04ea0000)
  eden space 512K,  54% used [0x04e00000, 0x04e457a0, 0x04e80000)
  from space 64K,   0% used [0x04e90000, 0x04e90000, 0x04ea0000)
  to   space 64K,   0% used [0x04e80000, 0x04e80000, 0x04e90000)
 tenured generation   total 1408K, used 803K [0x04ea0000, 0x05000000, 0x05000000)
   the space 1408K,  57% used [0x04ea0000, 0x04f68ef8, 0x04f69000, 0x05000000)
 Metaspace       used 78K, capacity 2242K, committed 2368K, reserved 4480K
[GC (Allocation Failure) [DefNew: 277K->0K(576K), 0.0002965 secs] 1081K->1081K(1984K), 0.0003113 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=4 (full 0):
 def new generation   total 576K, used 0K [0x04e00000, 0x04ea0000, 0x04ea0000)
  eden space 512K,   0% used [0x04e00000, 0x04e00000, 0x04e80000)
  from space 64K,   0% used [0x04e80000, 0x04e80000, 0x04e90000)
  to   space 64K,   0% used [0x04e90000, 0x04e90000, 0x04ea0000)
 tenured generation   total 1408K, used 1081K [0x04ea0000, 0x05000000, 0x05000000)
   the space 1408K,  76% used [0x04ea0000, 0x04fae698, 0x04fae800, 0x05000000)
 Metaspace       used 78K, capacity 2242K, committed 2368K, reserved 4480K
}
{Heap before GC invocations=4 (full 0):
 def new generation   total 576K, used 416K [0x04e00000, 0x04ea0000, 0x04ea0000)
  eden space 512K,  81% used [0x04e00000, 0x04e68368, 0x04e80000)
  from space 64K,   0% used [0x04e80000, 0x04e80000, 0x04e90000)
  to   space 64K,   0% used [0x04e90000, 0x04e90000, 0x04ea0000)
 tenured generation   total 1408K, used 1081K [0x04ea0000, 0x05000000, 0x05000000)
   the space 1408K,  76% used [0x04ea0000, 0x04fae698, 0x04fae800, 0x05000000)
 Metaspace       used 78K, capacity 2242K, committed 2368K, reserved 4480K
[GC (Allocation Failure) [DefNew: 416K->416K(576K), 0.0000137 secs][Tenured: 1081K->952K(1408K), 0.0021123 secs] 1498K->952K(1984K), [Metaspace: 78K->78K(4480K)], 0.0021674 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=5 (full 1):
 def new generation   total 576K, used 0K [0x04e00000, 0x04ea0000, 0x04ea0000)
  eden space 512K,   0% used [0x04e00000, 0x04e00000, 0x04e80000)
  from space 64K,   0% used [0x04e80000, 0x04e80000, 0x04e90000)
  to   space 64K,   0% used [0x04e90000, 0x04e90000, 0x04ea0000)
 tenured generation   total 1408K, used 952K [0x04ea0000, 0x05000000, 0x05000000)
   the space 1408K,  67% used [0x04ea0000, 0x04f8e1a8, 0x04f8e200, 0x05000000)
 Metaspace       used 78K, capacity 2242K, committed 2368K, reserved 4480K
}
{Heap before GC invocations=5 (full 1):
 def new generation   total 576K, used 0K [0x04e00000, 0x04ea0000, 0x04ea0000)
  eden space 512K,   0% used [0x04e00000, 0x04e00000, 0x04e80000)
  from space 64K,   0% used [0x04e80000, 0x04e80000, 0x04e90000)
  to   space 64K,   0% used [0x04e90000, 0x04e90000, 0x04ea0000)
 tenured generation   total 1408K, used 952K [0x04ea0000, 0x05000000, 0x05000000)
   the space 1408K,  67% used [0x04ea0000, 0x04f8e1a8, 0x04f8e200, 0x05000000)
 Metaspace       used 78K, capacity 2242K, committed 2368K, reserved 4480K
[Full GC (Allocation Failure) [Tenured: 952K->916K(1408K), 0.0020443 secs] 952K->916K(1984K), [Metaspace: 78K->78K(4480K)], 0.0020713 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap after GC invocations=6 (full 2):
 def new generation   total 576K, used 0K [0x04e00000, 0x04ea0000, 0x04ea0000)
  eden space 512K,   0% used [0x04e00000, 0x04e00000, 0x04e80000)
  from space 64K,   0% used [0x04e80000, 0x04e80000, 0x04e90000)
  to   space 64K,   0% used [0x04e90000, 0x04e90000, 0x04ea0000)
 tenured generation   total 1408K, used 916K [0x04ea0000, 0x05000000, 0x05000000)
   the space 1408K,  65% used [0x04ea0000, 0x04f850f0, 0x04f85200, 0x05000000)
 Metaspace       used 78K, capacity 2242K, committed 2368K, reserved 4480K
}
java.lang.OutOfMemoryError: Java heap space
Dumping heap to java_pid5772.hprof ...
Heap dump file created [2924907 bytes in 0.025 secs]
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
    at java.util.Arrays.copyOf(Unknown Source)
    at java.util.Arrays.copyOf(Unknown Source)
    at java.util.ArrayList.grow(Unknown Source)
    at java.util.ArrayList.ensureExplicitCapacity(Unknown Source)
    at java.util.ArrayList.ensureCapacityInternal(Unknown Source)
    at java.util.ArrayList.add(Unknown Source)
    at testObject.HeapTest.main(HeapTest.java:19)
Heap
 def new generation   total 576K, used 26K [0x04e00000, 0x04ea0000, 0x04ea0000)
  eden space 512K,   5% used [0x04e00000, 0x04e06ba0, 0x04e80000)
  from space 64K,   0% used [0x04e80000, 0x04e80000, 0x04e90000)
  to   space 64K,   0% used [0x04e90000, 0x04e90000, 0x04ea0000)
 tenured generation   total 1408K, used 916K [0x04ea0000, 0x05000000, 0x05000000)
   the space 1408K,  65% used [0x04ea0000, 0x04f850f0, 0x04f85200, 0x05000000)
 Metaspace       used 79K, capacity 2242K, committed 2368K, reserved 4480K

总结:通过上面日志可发现
1.执行轻GC之前对象是保存在伊甸区中，养老区数据为空
eden space 512K, 100% used [0x04e00000, 0x04e80000, 0x04e80000)
the space 1408K, 0% used [0x04ea0000, 0x04ea0000, 0x04ea0200, 0x05000000)

2.伊甸区保存满执行后执行 MinorGC的过程
[GC (Allocation Failure) [DefNew: 512K->64K(576K), 0.0014505 secs] 512K->438K(1984K), 0.0015239 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Heap after GC invocations=1 (full 0):

3.将伊甸区对象保存至幸存0区，如果幸存区无法存储所有对象，直接将对象保存至养老区。
from space 64K, 100% used [0x04e90000, 0x04ea0000, 0x04ea0000)
the space 1408K, 26% used [0x04ea0000, 0x04efdb40, 0x04efdc00, 0x05000000)

4.以上日志并未体现出第二次 MinorGC 将Eden，From对象存储到TO区的过程。

5.当养老区存储过大时触发FULL GC

[Full GC (Allocation Failure) [Tenured: 952K->916K(1408K), 0.0020443 secs] 952K->916K(1984K), [Metaspace: 78K->78K(4480K)], 0.0020713 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

FULL GC 后依然无法满足存储空间抛异常
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space

JVM 堆日志查看，参数，快照
1. 初始运行时VM 说明: 此处尝试给1M 但是最小totalMemory(-Xms) = 1.9375MBma...
JVM性能监控工具介绍
当系统遇到一些问题或者异常的时候，我们往往会查看系统日志、JVM堆栈、GC日志，或者查看线程快照、堆转储快照等信息...
JVM常用参数配置
本文主要内容： Trace跟踪参数堆的分配参数栈的分配参数 JVM其他参数既然学习JVM，阅读GC日志是处理...
垃圾回收机制算法分析
什么是垃圾回收机制？ JVM参数-查看GC日志： -XX:+PrintGCDetails finalize方法作...
代码验证手动触发 Full GC
很多时候我们在学习JVM时，往往需要查看JVM的回收日志，查看JVM的相关运行参数，这时候我们可以通过手动触发的形...
JVM-3 虚拟机性能监控和故障处理工具
运行日志异常堆栈GC日志线程快照（threaddump/javacore 文件）堆转储快照（headdump、hp...
JVM配置说明&查看和修改JVM某线程的各种配置值
JVM配置说明&查看和修改JVM的各种配置值 JVM参数类型标配参数 x参数(了解) xx参数 JVM标准参数(...
JVM性能调优实战(一) - 基于JDK命令行的监控
1 JVM的参数类型标准参数 X 参数 XX 参数 2 查看JVM运行时参数查看XX选项的值 -XX:+Pri...
《深入理解JVM虚拟机》 - VM性能分析工具与案例分析
JVM性能问题的处理依据：运行日志与异常堆栈、GC日志（printGCDetails）、线程快照(threaddu...
常用JVM调优命令
jps：显示所有JVM虚拟机进程 jstack：用于查看JVM虚拟机当前时刻线程快照 jinfo：用于实时查看和调...