23

JVM&GC-System.gc()方法

 3 years ago
source link: http://likeyou.cool/2020/07/19/jvm-gc-system.gc-fang-fa/
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.

在默认情况下,System.gc()会显示直接触发Full GC,同时对老年代和新生代进行回收。而一般情况下,垃圾回收应该是自动进行的,无需手工触发,否则就太麻烦了。

示例

public class TestGC {
    public static void main(String[] args) {
        new TestGC();
        System.gc();
        System.runFinalization();
    }
}

如果在idea查看日志输出,需要在Run–>Edit Configuration–>VM Options中设置

-XX:+PrintGCDetails

iIziaa3.png!web

打印结果

[GC (System.gc()) [PSYoungGen: 8489K->1707K(38400K)] 8489K->1715K(125952K), 0.0070544 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
[Full GC (System.gc()) [PSYoungGen: 1707K->0K(38400K)] [ParOldGen: 8K->1568K(87552K)] 1715K->1568K(125952K), [Metaspace: 3357K->3357K(1056768K)], 0.0228661 secs] [Times: user=0.03 sys=0.00, real=0.02 secs] 
Heap
 PSYoungGen      total 38400K, used 998K [0x00000000d5f00000, 0x00000000d8980000, 0x0000000100000000)
  eden space 33280K, 3% used [0x00000000d5f00000,0x00000000d5ff9b20,0x00000000d7f80000)
  from space 5120K, 0% used [0x00000000d7f80000,0x00000000d7f80000,0x00000000d8480000)
  to   space 5120K, 0% used [0x00000000d8480000,0x00000000d8480000,0x00000000d8980000)
 ParOldGen       total 87552K, used 1568K [0x0000000081c00000, 0x0000000087180000, 0x00000000d5f00000)
  object space 87552K, 1% used [0x0000000081c00000,0x0000000081d883f0,0x0000000087180000)
 Metaspace       used 3369K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 366K, capacity 388K, committed 512K, reserved 1048576K

在这个例子中,一个新的对象被创建,由于它没有被使用,所以该对象迅速地变为不可达(Unreachable)。

GC开头的说明此次垃圾回收为Minor GC,而Full GC开头的说明此次垃圾回收为stop-the-world的类型。

PSYoungGen表示年轻代,ParOldGen表示老年代。

方括号内的 8489K->1707K(38400K) 表示GC前该内存区域已使用容量->GC后该内存区域已使用容量(该内存区域总容量)。

方括号外的 8489K->1715K(125952K) 表示GC前Java堆已使用容量->GC后Java堆已使用容量(Java堆总容量)。

0.0070544 secs 表示该内存区域本次GC所占用的时间,单位是秒。有的收集器会给出更具体的时间数据,如 [Times: user=0.00 sys=0.00, real=0.01 secs] ,这里的user、sys、real与Linux的time命令所输出的时间含义一致,分别代表用户态消耗的CPU时间、内核态消耗的CPU时间、操作从开始到结束所经过的墙钟时间。CPU时间和墙钟时间的区别是,墙钟时间包括各种非运算的等待耗时,如等待磁盘I/O、等待线程阻塞,而CPU时间不包括这些耗时,但当系统有多CPU或者多核的话,多线程操作会叠加这些CPU时间,所以若看到user或sys时间超过real时间也是完全正常的。

eden、from、to 表示年轻代中各区域的划分。

Metaspace 表示元空间的大小,这里用的是JDK1.8,如果是JDK1.7则没有该区域。

默认情况下,即使System.gc()生效,他会使用传统的Full GC方式回收整个堆内存垃圾,而会忽略选项中的USeG1GC,比如我们设置 -XX:+PrintGCDetails -XX:+UseG1GC ,运行代码,输出结果如下:

[GC pause (G1 Evacuation Pause) (young), 0.0065937 secs]
   [Parallel Time: 1.2 ms, GC Workers: 4]
      [GC Worker Start (ms): Min: 262.2, Avg: 262.5, Max: 263.4, Diff: 1.2]
      [Ext Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.3, Diff: 0.3, 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.7, Max: 0.9, Diff: 0.9, Sum: 2.7]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.2]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [GC Worker Total (ms): Min: 0.0, Avg: 0.9, Max: 1.2, Diff: 1.2, Sum: 3.6]
      [GC Worker End (ms): Min: 263.4, Avg: 263.4, Max: 263.4, Diff: 0.0]
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.0 ms]
   [Other: 5.4 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 5.3 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.0 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.0 ms]
   [Eden: 6144.0K(6144.0K)->0.0B(12.0M) Survivors: 0.0B->1024.0K Heap: 7086.4K(128.0M)->1579.0K(128.0M)]
 [Times: user=0.00 sys=0.00, real=0.01 secs] 
[Full GC (System.gc())  2078K->1176K(8192K), 0.0057042 secs]
   [Eden: 1024.0K(12.0M)->0.0B(3072.0K) Survivors: 1024.0K->0.0B Heap: 2078.9K(128.0M)->1176.6K(8192.0K)], [Metaspace: 3358K->3358K(1056768K)]
 [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 garbage-first heap   total 8192K, used 1176K [0x0000000081c00000, 0x0000000081d00040, 0x0000000100000000)
  region size 1024K, 1 young (1024K), 0 survivors (0K)
 Metaspace       used 3368K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 366K, capacity 388K, committed 512K, reserved 1048576K

可以看出G1 GC并没有并发执行。打开虚拟机选项 -XX:+ExplicitGCInvokesConcurrent 后可改变这种默认行为

[GC pause (System.gc()) (young) (initial-mark), 0.0017516 secs]
   [Parallel Time: 1.4 ms, GC Workers: 4]
      [GC Worker Start (ms): Min: 254.2, Avg: 254.3, Max: 254.5, Diff: 0.3]
      [Ext Root Scanning (ms): Min: 0.0, Avg: 0.4, Max: 1.4, Diff: 1.3, Sum: 1.8]
      [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.8, Max: 1.1, Diff: 1.0, Sum: 3.0]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
         [Termination Attempts: Min: 1, Avg: 28.3, Max: 47, Diff: 46, Sum: 113]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 1.1, Avg: 1.3, Max: 1.4, Diff: 0.3, Sum: 5.0]
      [GC Worker End (ms): Min: 255.6, Avg: 255.6, Max: 255.6, Diff: 0.0]
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.0 ms]
   [Other: 0.3 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.0 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.0 ms]
   [Eden: 7168.0K(14.0M)->0.0B(12.0M) Survivors: 0.0B->2048.0K Heap: 7676.5K(128.0M)->1665.6K(128.0M)]
 [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC concurrent-root-region-scan-start]
[GC concurrent-root-region-scan-end, 0.0007669 secs]
[GC concurrent-mark-start]
[GC concurrent-mark-end, 0.0001007 secs]
[GC remark [Finalize Marking, 0.0000437 secs] [GC ref-proc, 0.0000645 secs] [Unloading, 0.0004621 secs], 0.0006229 secs]
 [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC cleanup 1665K->1665K(128M), 0.0001751 secs]
 [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 garbage-first heap   total 131072K, used 1665K [0x0000000081c00000, 0x0000000081d00400, 0x0000000100000000)
  region size 1024K, 3 young (3072K), 2 survivors (2048K)
 Metaspace       used 3373K, capacity 4496K, committed 4864K, reserved 1056768K
  class space    used 366K, capacity 388K, committed 512K, reserved 1048576K

调用System.gc()也仅仅是一个请求垃圾回收的建议,JVM接收这个消息后并不是立即做垃圾回收,而是对几个垃圾回收算法做加权,使垃圾回收操作容易发生或者提早发生,或回收较多而已。


About Joyk


Aggregate valuable and interesting links.
Joyk means Joy of geeK