GC日志分析

最新推荐文章于 2020-09-01 10:22:10 发布

hqw11

最新推荐文章于 2020-09-01 10:22:10 发布

阅读量728

点赞数

分类专栏： java基础

本文链接：https://blog.csdn.net/hqw11/article/details/86650192

版权

java基础专栏收录该内容

10 篇文章 0 订阅

订阅专栏

基础gclog日志分析

待补充
java version - jdk1.8
默认参数： InitialSurvivorRatio/8 Newratio/2
默认堆分配： toSpace ： fromSpace ： edenSpace ： tenuredSpace = 1/10 ： 1/10： 8/10 : 2
jdk1.8 方法区的实现：MetaSpace — 使用本地内存。已经没有XX:PermSize，XX:MaxPermSize的参数配置。
jdk1.7 就开始“去永久代”的工作。 1.7把字符串常量池从永久代中剥离出来，存放在堆空间中。但还有PermGen区。
查看jvm默认参数： java -XX:+PrintFlagsFinal -version

垃圾收集器参数

-XX:+UseSerialGC，虚拟机运行在Client模式下的默认值，Serial+Serial Old。
-XX:+UseParNewGC，ParNew+Serial Old，在JDK1.8被废弃，在JDK1.7还可以使用。
-XX:+UseConcMarkSweepGC，ParNew+CMS+Serial Old。
-XX:+UseParallelGC，虚拟机运行在Server模式下的默认值，Parallel Scavenge+Serial Old(PS Mark Sweep)。
-XX:+UseParallelOldGC，Parallel Scavenge+Parallel Old。
-XX:+UseG1GC，G1+G1

简单jvm进程代码

public class GcTest {
    private static final int _1MB = 1024 * 1024;
    public static void main(String[] args){
        GcTest.testHandlePromotion();
    }
    @SuppressWarnings("unused")
    public static void testHandlePromotion() {
        byte[] allocation1, allocation2, allocation3, allocation4, allocation5, allocation6, allocation7;
        allocation1 = new byte[2 * _1MB];
        allocation2 = new byte[2 * _1MB];
        allocation3 = new byte[2 * _1MB];
        allocation4 = new byte[4 * _1MB];
        
        allocation1 = null;
        allocation2 = null;
        allocation3 = null;
        allocation5 = new byte[2 * _1MB];
        allocation6 = new byte[5 * _1MB];
    }
}

分配担保

当JVM准备为一个对象分配内存空间时，发现此时Eden+Survior中空闲的区域无法装下该对象，那么就会触发MinorGC，对该区域的废弃对象进行回收。但如果MinorGC过后只有少量对象被回收，仍然无法装下新对象，那么此时需要将Eden+Survior中的所有对象都转移到老年代中，然后再将新对象存入Eden区。这个过程就是“分配担保”。
具体过程为：当垃圾收集器准备要在新生代发起一次MinorGC时，首先会检查“老年代中最大的连续空闲区域的大小是否大于新生代中所有对象的大小？”。
若老年代能够装下新生代中所有的对象，那么此时进行MinorGC没有任何风险，然后就进行MinorGC。
若老年代无法装下新生代中所有的对象，那么此时进行MinorGC是有风险的，垃圾收集器会进行一次预测：根据以往MinorGC过后存活对象的平均数来预测这次MinorGC后存活对象的平均数。
如果以往存活对象的平均数小于当前老年代最大的连续空闲空间，那么就进行MinorGC，虽然此次MinorGC是有风险的。 MinorGC
如果以往存活对象的平均数大于当前老年代最大的连续空闲空间，那么就对老年代进行一次Full GC，通过清除老年代中废弃数据来扩大老年代空闲空间，以便给新生代作担保。 FullGC

对象分配策略

对象优先在Eden区中分配
每次创建对象时，首先会在Eden区中分配。
若Eden区已满，则在Survior1区中分配。
若Eden区＋Survior1区剩余内存太少，导致对象无法放入该区域时，就会启用“分配担保”，将当前Eden区＋Survior1区中的对象转移到老年代中，然后再将新对象存入Eden区
大对象直接进入老年代
通过-XX:PretrnureSizeThreshold参数设置大对象
生命周期较长的对象进入老年代
使用-XXMaxTenuringThreshold设置新生代的最大年龄
相同年龄的对象内存超过Survior内存一半的对象进入老年代
年龄相同的对象的内存空间总和超过了Survior内存空间的一半，那么所有年龄相同的对象和超过该年龄的对象都被转移到老年代中去

Serial+Serial Old
（MinorGC：分配4时，2+2+2 直接进入老年代，4进入新生代）
（FullGC：分配5时，2+4新生代没有被GC，2*3老年代被GC，但新生代中2+4 直接进入老年代(6144K->6456K)，最后5进入新生代）
– java -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:+UseSerialGC -Xloggc:./serialGclogs -XX:SurvivorRatio=8 GcTest

Java HotSpot(TM) 64-Bit Server VM (25.162-b12) for linux-amd64 JRE (1.8.0_162-b12), built on Dec 19 2017 21:15:48 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
Memory: 4k page, physical 65978848k(38797604k free), swap 0k(0k free)
CommandLine flags: -XX:InitialHeapSize=20971520 -XX:MaxHeapSize=20971520 -XX:MaxNewSize=10485760 -XX:NewSize=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseSerialGC
0.086: [GC (Allocation Failure) 0.087: [DefNew: 6815K->317K(9216K), 0.0050115 secs] 6815K->6461K(19456K), 0.0051259 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
0.093: [GC (Allocation Failure) 0.093: [DefNew: 6621K->6621K(9216K), 0.0000254 secs]0.093: [Tenured: 6144K->6456K(10240K), 0.0030300 secs] 12765K->6456K(19456K), [Metaspace: 2652K->2652K(1056768K)], 0.0031154 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
Heap
 def new generation   total 9216K, used 5284K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
  eden space 8192K,  64% used [0x00000000fec00000, 0x00000000ff1290e0, 0x00000000ff400000)
  from space 1024K,   0% used [0x00000000ff500000, 0x00000000ff500000, 0x00000000ff600000)
  to   space 1024K,   0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000)
 tenured generation   total 10240K, used 6456K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
   the space 10240K,  63% used [0x00000000ff600000, 0x00000000ffc4e0e0, 0x00000000ffc4e200, 0x0000000100000000)
 Metaspace       used 2659K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 287K, capacity 386K, committed 512K, reserved 1048576K

Parallel Scavenge+Serial Old
(分配的内存>=Eden区大小的一半，那么会直接把要分配的内存放入老年代中。否则才会进入担保机制)
(分配4时，4直接进入老年代)
(分配2时，MinorGC 2*3，2放入新生代，分配5时，5放入新生代)

Java HotSpot(TM) 64-Bit Server VM (25.162-b12) for linux-amd64 JRE (1.8.0_162-b12), built on Dec 19 2017 21:15:48 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
Memory: 4k page, physical 65978848k(38794836k free), swap 0k(0k free)
CommandLine flags: -XX:InitialHeapSize=20971520 -XX:MaxHeapSize=20971520 -XX:MaxNewSize=10485760 -XX:NewSize=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC
0.270: [GC (Allocation Failure) [PSYoungGen: 6815K->464K(9216K)] 10911K->4568K(19456K), 0.0017262 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
Heap
 PSYoungGen      total 9216K, used 7878K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 8192K, 90% used [0x00000000ff600000,0x00000000ffd3d898,0x00000000ffe00000)
  from space 1024K, 45% used [0x00000000ffe00000,0x00000000ffe74010,0x00000000fff00000)
  to   space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)
 ParOldGen       total 10240K, used 4104K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
  object space 10240K, 40% used [0x00000000fec00000,0x00000000ff002010,0x00000000ff600000)
 Metaspace       used 2659K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 287K, capacity 386K, committed 512K, reserved 1048576K

Parallel Scavenge+Parallel Old

Java HotSpot(TM) 64-Bit Server VM (25.162-b12) for linux-amd64 JRE (1.8.0_162-b12), built on Dec 19 2017 21:15:48 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
Memory: 4k page, physical 65978848k(38797020k free), swap 0k(0k free)
CommandLine flags: -XX:InitialHeapSize=20971520 -XX:MaxHeapSize=20971520 -XX:MaxNewSize=10485760 -XX:NewSize=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelOldGC
0.094: [GC (Allocation Failure) [PSYoungGen: 6815K->384K(9216K)] 10911K->4488K(19456K), 0.0029001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Heap
 PSYoungGen      total 9216K, used 7798K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
  eden space 8192K, 90% used [0x00000000ff600000,0x00000000ffd3d898,0x00000000ffe00000)
  from space 1024K, 37% used [0x00000000ffe00000,0x00000000ffe60020,0x00000000fff00000)
  to   space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)
 ParOldGen       total 10240K, used 4104K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
  object space 10240K, 40% used [0x00000000fec00000,0x00000000ff002010,0x00000000ff600000)
 Metaspace       used 2654K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 287K, capacity 386K, committed 512K, reserved 1048576K

G1
没有新生代和老年代的概念，而是将堆划分为一块块独立的Region

Java HotSpot(TM) 64-Bit Server VM (25.162-b12) for linux-amd64 JRE (1.8.0_162-b12), built on Dec 19 2017 21:15:48 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
Memory: 4k page, physical 65978848k(38786896k free), swap 0k(0k free)
CommandLine flags: -XX:InitialHeapSize=20971520 -XX:MaxHeapSize=20971520 -XX:MaxNewSize=10485760 -XX:NewSize=10485760 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseG1GC
0.146: [GC pause (G1 Humongous Allocation) (young) (initial-mark), 0.0252877 secs]
   [Parallel Time: 20.0 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 146.6, Avg: 148.6, Max: 164.3, Diff: 17.7]
      [Ext Root Scanning (ms): Min: 0.0, Avg: 15.1, Max: 19.3, Diff: 19.2, Sum: 151.1]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.3, Max: 0.9, Diff: 0.9, Sum: 2.7]
      [Termination (ms): Min: 0.0, Avg: 0.4, Max: 0.6, Diff: 0.6, Sum: 3.6]
         [Termination Attempts: Min: 1, Avg: 2.5, Max: 6, Diff: 5, Sum: 25]
      [GC Worker Other (ms): Min: 0.0, Avg: 1.8, Max: 17.2, Diff: 17.2, Sum: 17.7]
      [GC Worker Total (ms): Min: 1.8, Avg: 17.5, Max: 19.5, Diff: 17.7, Sum: 175.2]
      [GC Worker End (ms): Min: 166.1, Avg: 166.1, Max: 166.2, Diff: 0.0]
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 2.2 ms]
   [Other: 3.1 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 1.8 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 1.1 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.0 ms]
   [Eden: 1024.0K(10.0M)->0.0B(9216.0K) Survivors: 0.0B->1024.0K Heap: 6987.5K(20.0M)->6680.1K(20.0M)]
 [Times: user=0.02 sys=0.01, real=0.02 secs]
0.172: [GC concurrent-root-region-scan-start]
0.173: [GC concurrent-root-region-scan-end, 0.0007402 secs]
0.173: [GC concurrent-mark-start]
0.173: [GC concurrent-mark-end, 0.0003235 secs]
0.176: [GC remark 0.176: [Finalize Marking, 0.0015102 secs] 0.177: [GC ref-proc, 0.0001493 secs] 0.177: [Unloading, 0.0058818 secs], 0.0092204 secs]
 [Times: user=0.01 sys=0.00, real=0.01 secs]
0.187: [GC cleanup 12M->12M(20M), 0.0046040 secs]
 [Times: user=0.00 sys=0.00, real=0.00 secs]
0.192: [GC pause (G1 Humongous Allocation) (young), 0.0143999 secs]
   [Parallel Time: 3.2 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 192.1, Avg: 193.7, Max: 194.3, Diff: 2.2]
      [Ext Root Scanning (ms): Min: 0.0, Avg: 0.1, Max: 0.5, Diff: 0.5, Sum: 0.7]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.1, Max: 0.8, Diff: 0.8, Sum: 1.2]
      [Termination (ms): Min: 0.0, Avg: 0.5, Max: 0.9, Diff: 0.9, Sum: 5.1]
         [Termination Attempts: Min: 1, Avg: 1.2, Max: 3, Diff: 2, Sum: 12]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
      [GC Worker Total (ms): Min: 0.0, Avg: 0.7, Max: 2.3, Diff: 2.2, Sum: 7.2]
      [GC Worker End (ms): Min: 194.4, Avg: 194.4, Max: 194.4, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 4.5 ms]
   [Other: 6.7 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 4.3 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 2.2 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.0 ms]
   [Eden: 0.0B(9216.0K)->0.0B(9216.0K) Survivors: 1024.0K->1024.0K Heap: 12.5M(20.0M)->6471.3K(20.0M)]
 [Times: user=0.01 sys=0.01, real=0.02 secs]
Heap
 garbage-first heap   total 20480K, used 11591K [0x00000000fec00000, 0x00000000fed000a0, 0x0000000100000000)
  region size 1024K, 2 young (2048K), 1 survivors (1024K)
 Metaspace       used 2653K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 287K, capacity 386K, committed 512K, reserved 1048576K

GC日志的离线分析开源工具

gchisto(https://java.net/projects/gchisto)
gcviewer（https://github.com/chewiebug/GCViewer ）

hqw11

关注

0
点赞
踩
0

收藏

觉得还不错? 一键收藏
0
评论
GC日志分析

最简单进程jmap -histo PID分析待补充java version - jdk1.8其中需要关注的几个类对象[C is a char[] 跟String相关，final char[]-jdk8 / byte[]-jdk9[S is a short[][I is a int[][B is a byte[][I is a int[]java.lang.Class - ...
复制链接

扫一扫