016-GC-JVM的Stop The World，安全點

一、概述

　　可達性性分析中從GC Roots節點找引用鏈這個操作，可作為GC Roots的節點主要在全局性的引用（如常量或類靜態屬性）與執行上下文（如棧幀中的本地變量表）中，現在很多應用僅僅方法區就有數百兆，如果要逐個檢查這里面的引用，那么必然會消耗很多時間。

　　另外，可達性分析對執行事件的敏感還體現在GC停頓上，因為這項分析工作必須在一個能確保一致性的快照中進行。一致性是指整個分析期間整個執行系統看起來就像被凍結在某個時間點上，不可以出現在分析過程中對象引用關系還在不斷變化的情況。該點不滿足的話分析結果准確性就無法得到保證。這點是導致GC進行時必須停頓所有java線程的其中一個重要原因（Sun稱之為Stop-The-World），即使是在號稱（幾乎）不會發生停頓的CMS收集器中，枚舉跟節點時也是必須要停頓的。

　　在主流的JVM使用的是准確式GC，所以當執行系統停頓下來后，並不需要一個不漏地檢查所有執行上下文和全局的引用位置，虛擬機應當是有辦法直接得知哪些地方存放着對象引用。

　　在HotSpot實現中，是使用一組稱為OopMapde 的數據結構來達到這個目的，在類加載完的時候，HotSpot就把對象內什么偏移量上是什么類型的數據計算出來，在JIT編譯過程中，也會在特定位置記錄下棧和寄存器中哪些位置是引用。這樣，GC掃碼時就可以直接指導這些信息。

1.1、安全點

　　安全點的選定基本上是以程序”是否具有讓程序長時間執行的特征“為標准進行選定的。長時間執行，明顯的特征就是指令序列復用，如方法調用，循環跳轉，異常跳轉等，所以具有這些功能的指令才會產生Safepoint。

　　對於安全點，如何在GC發生時讓所有線程（不包括JNI調用的線程）都跑到最近的安全點上在停頓下來。兩種方案：強先式中斷和主動式中斷。

　　強先式中斷，不需要線程的執行代碼主動去配合，在GC發生時，首先把所有線程全部中斷，如果發現有線程中斷的地方不在安全點上，就恢復線程，讓他跑到安全點。現代JVM，幾乎不使用

　　主動式中斷，需要中斷線程的時候，不直接對線程操作，僅僅簡單地設置一個標志，各個線程執行時主動去輪詢這個標志，發現中斷標志為真時就自己中斷掛起。輪詢標志的地方和安全點是重合的，另外再加上創建對象需要分配的內存的地方。

1.2、安全區域

　　Safepoint機制保證了程序執行時，在不太長的時間內就會遇到可進入GC的Safepoint。但是程序“不執行”的時候呢？沒有分配時間片，如線程Sleep或Blocked狀態，這時線程無法想用JVM的中斷請求，也無法去中斷，這時需要安全區域（Safe Region）來解決。

　　安全區域是指在一段代碼片段中，引用關系不會發生變化。在這個區域中的任意地方開始GC都是安全的，擴展了的Safepoint。

1.3、java對象內存申請過程

　　007-對象內存分配與回收,垃圾收集過程，簡單敘述如下：

　　1.JVM會試圖為相關Java對象在Eden中初始化一塊內存區域；當Eden空間足夠時，內存申請結束。否則到下一步；

　　2.JVM試圖釋放在Eden中所有不活躍的對象（minor collection），釋放后若Eden空間仍然不足以放入新對象，則試圖將部分Eden中活躍對象放入Survivor區；

　　3.Survivor區被用來作為Eden及old的中間交換區域，當old區空間足夠時，Survivor區的對象會被移到Old區，否則會被保留在Survivor區；

　　4.當old區空間不夠時，JVM會在old區進行major collection；

　　5.垃圾收集后，若Survivor及old區仍然無法存放從Eden復制過來的部分對象，導致JVM無法在Eden區為新對象創建內存區域，則出現"Out of memory錯誤"；

1.4、STP（Stop-The-World）誘因

　　在新生代進行的GC叫做minor GC，在老年代進行的GC都叫major GC，Full GC同時作用於新生代和老年代。在垃圾回收過程中經常涉及到對對象的挪動（比如上文提到的對象在Survivor 0和Survivor 1之間的復制），進而導致需要對對象引用進行更新。為了保證引用更新的正確性，Java將暫停所有其他的線程，這種情況被稱為“Stop-The-World”，導致系統全局停頓。Stop-The-World對系統性能存在影響，因此垃圾回收的一個原則是盡量減少“Stop-The-World”的時間。

　　不同垃圾收集器的Stop-The-World情況，Serial、Parallel和CMS收集器均存在不同程度的Stop-The-Word情況；而即便是最新的G1收集器也不例外。

• Java中一種全局暫停的現象,jvm掛起狀態

• 全局停頓，所有Java代碼停止，native代碼可以執行，但不能和JVM交互

• 多半由於jvm的GC引起，如：
  1.老年代空間不足。
  2.永生代（jkd7）或者元數據空間（jkd8）不足。
  3.System.gc()方法調用。
  4.CMS GC時出現promotion failed和concurrent mode failure
  5.YoungGC時晉升老年代的內存平均值大於老年代剩余空間
  6.有連續的大對象需要分配

• 除了GC還有以下原因：
  1.Dump線程--人為因素。
  2.死鎖檢查。
  3.堆Dump--人為因素。
  Full GC 是清理整個堆空間—包括年輕代和老年代。

• 其他

　　1.Biased lock revocation 取消偏向鎖

　　2. Class redefinition (e.g. javaagent，AOP的代碼植入)

　　3. Various debug operation (e.g. thread dump 一條或所有線程，heapduump等)

　　打開JDK8源碼的vm_operations.hpp，有大概完整58項列表。

1.5、STP（Stop-The-World）四個階段

　　根據-XX:+PrintSafepointStatistics –XX:PrintSafepointStatisticsCount=1 參數虛擬機打印的日志文件可以看出，safepoint的執行一共可以分為四個階段：

　　　　Spin階段。因為jvm在決定進入全局safepoint的時候，有的線程在安全點上，而有的線程不在安全點上，這個階段是等待未在安全點上的用戶線程進入安全點。

　　　　Block階段。即使進入safepoint，用戶線程這時候仍然是running狀態，保證用戶不在繼續執行，需要將用戶線程阻塞。http://blog.csdn.net/iter_zc/article/details/41892567這篇bog詳細說明了如何將用戶線程阻塞。

　　　　Cleanup。這個階段是JVM做的一些內部的清理工作。

　　　　VM Operation. JVM執行的一些全局性工作，例如GC,代碼反優化。

　　常用JVM參數：

　　　　-XX:+PrintGCApplicationStoppedTime　　：JVM的停頓時間（不只是GC），打印在GC日志里。

　　 　　-XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1　　這兩個參數用於記錄STW發生的原因、線程情況、STW各個階段的停頓時間等。當添加這兩個參數后，程序運行期間會打印如下內容

　　　　如：

Total time for which application threads were stopped: 0.0053256 seconds, Stopping threads took: 0.0000221 seconds
time:14464
[GC (Allocation Failure) [DefNew: 959K->64K(960K), 0.0045369 secs] 523263K->523259K(524224K), 0.0045726 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 
         vmop                    [threads: total initially_running wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count
14.610: GenCollectForAllocation          [      13          0              0    ]      [     0     0     0     0     4    ]  0   
Total time for which application threads were stopped: 0.0047146 seconds, Stopping threads took: 0.0000224 seconds
[GC (Allocation Failure) [DefNew: 960K->960K(960K), 0.0000229 secs][Tenured: 523195K->523263K(523264K), 0.4558175 secs] 524155K->524154K(524224K), [Metaspace: 3842K->3842K(1056768K)], 0.4559020 secs] [Times: user=0.45 sys=0.00, real=0.46 secs] 
         vmop                    [threads: total initially_running wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count
14.636: GenCollectForAllocation          [      13          0              0    ]      [     0     0     0     0   455    ]  0   
Total time for which application threads were stopped: 0.4560633 seconds, Stopping threads took: 0.0000231 seconds
time:14962
[Full GC (Allocation Failure) [Tenured: 523263K->523263K(523264K), 0.4344774 secs] 524223K->524221K(524224K), [Metaspace: 3842K->3842K(1056768K)], 0.4345167 secs] [Times: user=0.43 sys=0.01, real=0.43 secs] 
         vmop                    [threads: total initially_running wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count
15.094: GenCollectForAllocation          [      13          0              0    ]      [     0     0     0     0   434    ]  0   
Total time for which application threads were stopped: 0.4346385 seconds, Stopping threads took: 0.0000174 seconds
[Full GC (Allocation Failure) [Tenured: 523263K->523263K(523264K), 0.4154644 secs] 524223K->524223K(524224K), [Metaspace: 3842K->3842K(1056768K)], 0.4154981 secs] [Times: user=0.41 sys=0.00, real=0.42 secs] 
[Full GC (Allocation Failure) [Tenured: 523263K->515874K(523264K), 0.4559588 secs] 524223K->515874K(524224K), [Metaspace: 3842K->3842K(1056768K)], 0.4559872 secs] [Times: user=0.46 sys=0.00, real=0.46 secs] 
         vmop                    [threads: total initially_running wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count
15.529: GenCollectForAllocation          [      13          0              0    ]      [     0     0     0     0   871    ]  0   
Total time for which application threads were stopped: 0.8716535 seconds, Stopping threads took: 0.0000320 seconds
time:15398

 　　　　詳細說明：

         vmop                    [threads: total initially_running wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count
14.610: GenCollectForAllocation          [      13          0              0    ]      [     0     0     0     0     4    ]  0   

　　　　第一段是時間戳，VM Operation的類型，以及線程概況　　

• • total: 所有的java線程數
  • initially_running: 號召進入安全點時，還是Running狀態的線程數
  • wait_to_block: 所有線程都不Running時，仍不是Block狀態的線程數

　　　　第二段是到達安全點的各個階段以及執行操作所花的時間，其中最重要的是vmop

• • spin: VMOP線程使用自旋，等待所有線程都不是Running的時間
  • block: VMOP線程基於鎖，等待所有線程都是Block的時間
  • sync: spin+block +其他，這是從開始到進入安全點的總耗時
  • cleanup: 退出清理所用時間
  • vmop: 真正執行VM Operation的時間　　

二、監控點應用

 

　　如果能在監控系統上顯示JVM進入安全點的次數和時間，那我們排查服務超時時就可以第一時間先上監控系統觀察下當時JVM停頓時間的情況。

2.1、在應用里往外吐信息

hotspot 里提供里一個API，但是沒掛到JMX上，所以只適合由泡在應用里的代碼往外吐。

import sun.management.HotspotRuntimeMBean;
import sun.management.ManagementFactoryHelper;

public class StopTheWorldSout {
    private static HotspotRuntimeMBean mbean = (HotspotRuntimeMBean) ManagementFactoryHelper.getHotspotRuntimeMBean();

    public static void main(String[] args) {
        long count = mbean.getSafepointCount();
        long time = mbean.getTotalSafepointTime();
        long syncTime = mbean.getSafepointSyncTime();
    }
}

三、示例

• -Xmn1m代表年輕代幾乎沒有空間。對象都到老年代了。
• 類PrintThread是打印線程，每100毫秒打印一次，如果應用線程暫停了，那么會延遲。
• 類MyThread是消耗jvm內存的線程，每到450M，會讓對象失去引用。

代碼

/**
 * 啟動參數：-Xmx512m -Xms512m -XX:+UseSerialGC -XX:+PrintGCDetails -Xmn1m
 * <p>
 * -XX:+UseSerialGC:新生代和老年代都用單線程的串行回收器。適合單核並發能力差得處理器。
 * -XX:+UseParNewGC:新生代用並行的ParNew回收期，老年代都用單線程的串行回收器。適合多核，並發能力強的處理器。
 * -XX:+UseParallelGC:新生代使用ParallelGC回收器，老年代使用串行回收器。
 * -XX:+UseParallelOldGC:新生代使用ParallelGC回收器，老年代使用ParallelOldGC回收器。
 * 1）--
 * -XX:+UseConclMarkSweepGC:老年代使用CMS回收器。
 **/
public class StopTheWorldTest {
    public static class MyThread extends Thread {
        HashMap<Long, byte[]> map = new HashMap<Long, byte[]>();

        @Override
        public void run() {
            try {
                while (true) {
                    if (map.size() * 512 / 1024 / 1024 >= 450) {
                        System.out.println("============准備清理==========:" + map.size());//大於450M時，清理內存。
                        map.clear();
                        System.out.println("clean map");
                    }
                    for (int i = 0; i < 100; i++) {
                        map.put(System.nanoTime(), new byte[512]);//消耗內存。
                    }
                    Thread.sleep(1);
                }
            } catch (Exception e) {
                e.printStackTrace();
            }
        }
    }

    public static class PrintThread extends Thread {

        public static final long starttime = System.currentTimeMillis();

        @Override
        public void run() {
            try {
                while (true) {
                    long t = System.currentTimeMillis() - starttime;
                    System.out.println("time:" + t);
                    Thread.sleep(100);
                }
            } catch (Exception e) {

            }
        }
    }

    public static void main(String[] args) {
        MyThread t = new MyThread();
        PrintThread p = new PrintThread();
        t.start();
        p.start();
    }
}

輸出

time:14548
[GC (Allocation Failure) [DefNew: 959K->64K(960K), 0.0050998 secs] 521756K->521753K(524224K), 0.0051346 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
[GC (Allocation Failure) [DefNew: 960K->64K(960K), 0.0048306 secs] 522649K->522646K(524224K), 0.0048594 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 
[GC (Allocation Failure) [DefNew: 960K->960K(960K), 0.0000189 secs][Tenured: 522582K->523263K(523264K), 0.4516206 secs] 523542K->523538K(524224K), [Metaspace: 3838K->3838K(1056768K)], 0.4516858 secs] [Times: user=0.44 sys=0.01, real=0.46 secs] 
time:15068
[Full GC (Allocation Failure) [Tenured: 523263K->523263K(523264K), 0.4217772 secs] 524223K->524218K(524224K), [Metaspace: 3838K->3838K(1056768K)], 0.4218278 secs] [Times: user=0.42 sys=0.00, real=0.42 secs] 
time:15507[Full GC (Allocation Failure) [Tenured: 523263K->523263K(523264K), 0.4132856 secs] 524223K->524223K(524224K), [Metaspace: 3838K->3838K(1056768K)], 0.4133185 secs] [Times: user=0.41 sys=0.00, real=0.42 secs] 
[Full GC (Allocation Failure) [Tenured: 523263K->515940K(523264K), 0.4557615 secs] 524223K->515940K(524224K), [Metaspace: 3838K->3838K(1056768K)], 0.4557908 secs] [Times: user=0.45 sys=0.01, real=0.45 secs] 

[GC (Allocation Failure) [DefNew: 896K->63K(960K), 0.0027436 secs] 516836K->516802K(524224K), 0.0027752 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 
[GC (Allocation Failure) [DefNew: 959K->64K(960K), 0.0048657 secs] 517698K->517697K(524224K), 0.0049047 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC (Allocation Failure) [DefNew: 960K->64K(960K), 0.0041075 secs] 518593K->518578K(524224K), 0.0041432 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 
[GC (Allocation Failure) [DefNew: 960K->63K(960K), 0.0040883 secs] 519474K->519473K(524224K), 0.0041230 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
time:16481

說明：

• 15.068秒前都是100ms打印一次，線程沒有停頓。但是之后發生了因full gc引發零點幾秒甚至將近1s的停頓。
• 因為對象的引用還在，老年代的對象不會被回收。如：
  [Full GC (Allocation Failure) [Tenured: 523263K->523263K(523264K),