Java JFR 民間指南 - 事件詳解 - jdk.ObjectAllocationSample

時間  2021-04-23
標籤 java git github 算法 編程 bootstrap 數組 微信 多線程 框架 欄目 Java 简体版
原文   原文鏈接

對象分配採樣：jdk.ObjectAllocationSample

引入版本：Java 16java

相關 ISSUE：Introduce JFR Event Throttling and new jdk.ObjectAllocationSample event (enabled by default)git

各版本配置：

Java 16：

默認配置（default.jfc）:github

配置 值 描述
enabled true 默認啓用
throttle 150/s 每秒最多采集 150 個
stackTrace true 採集事件的時候，也採集堆棧

採樣配置（profile.jfc）:算法

配置 值 描述
enabled true 默認啓用
throttle 300/s 每秒最多采集 300 個
stackTrace true 採集事件的時候，也採集堆棧

爲什麼須要這個事件？

對於大部分的 JVM 應用，大部分的對象是在 TLAB 中分配的。若是 TLAB 外分配過多，或者 TLAB 重分配過多，那麼咱們須要檢查代碼，檢查是否有大對象，或者不規則伸縮的對象分配，以便於優化代碼。對於 TLAB 外分配和重分配分別有對應的事件：jdk.ObjectAllocationOutsideTLAB和jdk.ObjectAllocationInNewTLAB。可是這兩個事件，若是不採集堆棧，則沒有什麼實際參考意義，若是採集堆棧的話，這兩個事件數量很是大，尤爲是出現問題的時候。那麼採集堆棧的次數也會變得很是多，這樣會很是影響性能。採集堆棧，是一個比較耗性能的操做，目前大部分的 Java 線上應用，尤爲是微服務應用，都使用了各類框架，堆棧很是深，可能達到幾百，若是涉及響應式編程，這個堆棧就更深了。JFR 考慮到這一點，默認採集堆棧深度最可能是 64，即便是這樣，也仍是比較耗性能的。而且，在 Java 11 以後，JDK 一直在優化獲取堆棧的速度，例如堆棧方法字符串放入緩衝池，優化緩衝池過時策略與 GC 策略等等，可是目前性能損耗仍是不能忽視。因此，引入這個事件，減小對於堆棧的採集致使的消耗。編程

事件包含屬性

屬性 說明 舉例
startTime 事件開始時間 10:16:27.718
objectClass 觸發本次事件的對象的類 byte[] (classLoader = bootstrap)
weight 注意，這個不是對象大小，而是該線程距離上次被採集 jdk.ObjectAllocationSample 事件到這個事件的這段時間，線程分配的對象總大小 10.0 MB
eventThread 線程 "Thread-0" (javaThreadId = 27)
stackTrace 線程堆棧 略

測試這個事件

package com.github.hashjang.jfr.test;

import jdk.jfr.Recording;
import jdk.jfr.consumer.RecordedEvent;
import jdk.jfr.consumer.RecordingFile;
import sun.hotspot.WhiteBox;

import java.io.File;
import java.io.IOException;
import java.nio.file.Path;
import java.util.concurrent.TimeUnit;

public class TestObjectAllocationSample {
    //對於字節數組對象頭佔用16字節
    private static final int BYTE_ARRAY_OVERHEAD = 16;
    //分配對象的大小，1MB
    private static final int OBJECT_SIZE = 1024 * 1024;
    //要分配的對象個數
    private static final int OBJECTS_TO_ALLOCATE = 20;
    //分配對象的 class 名稱
    private static final String BYTE_ARRAY_CLASS_NAME = new byte[0].getClass().getName();
    private static final String INT_ARRAY_CLASS_NAME = new int[0].getClass().getName();
    //測試的 JFR 事件名稱
    private static String EVENT_NAME = "jdk.ObjectAllocationSample";
    //分配的對象放入這個靜態變量，防止編譯器優化去掉沒有使用的分配代碼
    public static byte[] tmp;
    public static int[] tmp2;

    public static void main(String[] args) throws IOException, InterruptedException {
        //使用 WhiteBox 執行 FullGC，清楚干擾
        WhiteBox whiteBox = WhiteBox.getWhiteBox();
        whiteBox.fullGC();

        Recording recording = new Recording();
        //設置 throttle 爲 1/s，也就是每秒最多采集一個
        //目前 throttle 只對 jdk.ObjectAllocationSample 有效，還不算是標準配置，因此只能這樣配置
        recording.enable(EVENT_NAME).with("throttle", "1/s");
        recording.start();
        //main 線程分配對象
        for (int i = 0; i < OBJECTS_TO_ALLOCATE; ++i) {
            //因爲 main 線程在 JVM 初始化的時候分配了一些其餘對象，因此第一次採集的大小可能不許確，或者採集的類不對，後面結果中咱們會看到
            tmp = new byte[OBJECT_SIZE - BYTE_ARRAY_OVERHEAD];
            TimeUnit.MILLISECONDS.sleep(100);
        }
        //測試多線程分配對象
        Runnable runnable = () -> {
            for (int i = 0; i < OBJECTS_TO_ALLOCATE; ++i) {
                tmp = new byte[OBJECT_SIZE - BYTE_ARRAY_OVERHEAD];
                try {
                    TimeUnit.MILLISECONDS.sleep(100);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        };
        Thread thread = new Thread(runnable);
        Runnable runnable2 = () -> {
            for (int i = 0; i < OBJECTS_TO_ALLOCATE; ++i) {
                tmp2 = new int[OBJECT_SIZE - BYTE_ARRAY_OVERHEAD];
                try {
                    TimeUnit.MILLISECONDS.sleep(100);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        };
        Thread thread2 = new Thread(runnable2);
        thread.start();
        thread2.start();
        long threadId = thread.getId();
        long threadId2 = thread2.getId();
        thread.join();
        thread2.join();
        recording.stop();
        Path path = new File(new File(".").getAbsolutePath(), "recording-" + recording.getId() + "-pid" + ProcessHandle.current().pid() + ".jfr").toPath();
        recording.dump(path);
        long size = 0;
        for (RecordedEvent event : RecordingFile.readAllEvents(path)) {
            if (!EVENT_NAME.equals(event.getEventType().getName())) {
                continue;
            }
            String objectClassName = event.getString("objectClass.name");
            boolean isMyEvent = (
                    Thread.currentThread().getId() == event.getThread().getJavaThreadId()
                    || threadId == event.getThread().getJavaThreadId()
                    || threadId2 == event.getThread().getJavaThreadId()
                    ) && (
                            objectClassName.equals(BYTE_ARRAY_CLASS_NAME) ||
                            objectClassName.equals(INT_ARRAY_CLASS_NAME)
                    );
            if (!isMyEvent) {
                continue;
            }
            System.out.println(event);
        }
    }
}

輸出示例：bootstrap

//main線程在初始化 JVM 的時候，分配了一些其餘對象，因此這裏 weight 很大
jdk.ObjectAllocationSample {
  startTime = 10:16:24.677
  //觸發本次事件的對象的類
  objectClass = byte[] (classLoader = bootstrap)
  //注意，這個不是對象大小，而是該線程距離上次被採集 jdk.ObjectAllocationSample 事件到這個事件的這段時間，線程分配的對象總大小
  weight = 15.9 MB
  eventThread = "main" (javaThreadId = 1)
  stackTrace = [
    com.github.hashjang.jfr.test.TestObjectAllocationSample.main(String[]) line: 42
  ]
}

jdk.ObjectAllocationSample {
  startTime = 10:16:25.690
  objectClass = byte[] (classLoader = bootstrap)
  weight = 10.0 MB
  eventThread = "main" (javaThreadId = 1)
  stackTrace = [
    com.github.hashjang.jfr.test.TestObjectAllocationSample.main(String[]) line: 42
  ]
}

jdk.ObjectAllocationSample {
  startTime = 10:16:26.702
  objectClass = byte[] (classLoader = bootstrap)
  weight = 1.0 MB
  eventThread = "Thread-0" (javaThreadId = 27)
  stackTrace = [
    com.github.hashjang.jfr.test.TestObjectAllocationSample.lambda$main$0() line: 48
    java.lang.Thread.run() line: 831
  ]
}

jdk.ObjectAllocationSample {
  startTime = 10:16:27.718
  objectClass = byte[] (classLoader = bootstrap)
  weight = 10.0 MB
  eventThread = "Thread-0" (javaThreadId = 27)
  stackTrace = [
    com.github.hashjang.jfr.test.TestObjectAllocationSample.lambda$main$0() line: 48
    java.lang.Thread.run() line: 831
  ]
}

各位讀者能夠將採集頻率改爲 "100/s"，就能看到基本全部代碼裏面的對象分配都被採集成爲一個事件了。數組

底層原理與相關 JVM 源碼

首先咱們來看下 Java 對象分配的流程：微信

image

對於 HotSpot JVM 實現，全部的 GC 算法的實現都是一種對於堆內存的管理，也就是都實現了一種堆的抽象，它們都實現了接口 CollectedHeap。當分配一個對象堆內存空間時，在 CollectedHeap 上首先都會檢查是否啓用了 TLAB，若是啓用了，則會嘗試 TLAB 分配；若是當前線程的 TLAB 大小足夠，那麼從線程當前的 TLAB 中分配；若是不夠，可是當前 TLAB 剩餘空間小於最大浪費空間限制，則從堆上（通常是 Eden 區） 從新申請一個新的 TLAB 進行分配。不然，直接在 TLAB 外進行分配。TLAB 外的分配策略，不一樣的 GC 算法不一樣。例如G1：多線程

  • 若是是 Humongous 對象（對象在超過 Region 一半大小的時候），直接在 Humongous 區域分配（老年代的連續區域）。
  • 根據 Mutator 情況在當前分配下標的 Region 內分配

jdk.ObjectAllocationSample 事件只關心 TLAB 外分配，由於這也是程序主要須要的優化點。throttle 配置，是限制在一段時間內只能採集這麼多的事件。可是咱們究竟怎麼篩選採集哪些事件呢？假設咱們配置的是 100/s，首先想到的是時間窗口，採集這一窗口內開頭的 100 個事件。這樣顯然是不符合咱們的要求的，咱們並不能保證性能瓶頸的事件就在每秒的前 100 個，而且咱們的程序可能每秒發生不少不少次 TLAB 外分配，僅憑前 100 個事件並不能很好的採集咱們想看到的事件。因此，JDK 內部經過 EWMA（Exponential Weighted Moving Average）的算法估計什麼時候的採集時間以及越大分配上報次數越多的這樣的優化來實現更準確地採樣。
若是是直接在 TLAB 外進行分配，纔可能生成 jdk.ObjectAllocationSample 事件。框架

參考源碼：

allocTracer.cpp

//在每次發生 TLAB 外分配的時候，調用這個方法上報
void AllocTracer::send_allocation_outside_tlab(Klass* klass, HeapWord* obj, size_t alloc_size, Thread* thread) {
  JFR_ONLY(JfrAllocationTracer tracer(obj, alloc_size, thread);)
  //馬上生成 jdk.ObjectAllocationOutsideTLAB 這個事件
  EventObjectAllocationOutsideTLAB event;
  if (event.should_commit()) {
    event.set_objectClass(klass);
    event.set_allocationSize(alloc_size);
    event.commit();
  }
  //歸一化分配數據並採樣 jdk.ObjectAllocationSample 事件
  normalize_as_tlab_and_send_allocation_samples(klass, static_cast<intptr_t>(alloc_size), thread);
}

再來看歸一化分配數據並生成 jdk.ObjectAllocationSample 事件的具體內容：

static void normalize_as_tlab_and_send_allocation_samples(Klass* klass, intptr_t obj_alloc_size_bytes, Thread* thread) {
  //讀取當前線程分配過的字節大小
  const int64_t allocated_bytes = load_allocated_bytes(thread);
  assert(allocated_bytes > 0, "invariant"); // obj_alloc_size_bytes is already attributed to allocated_bytes at this point.
  //若是沒有使用 TLAB，那麼不須要處理，allocated_bytes 確定只包含 TLAB 外分配的字節大小
  if (!UseTLAB) {
    //採樣 jdk.ObjectAllocationSample 事件
    send_allocation_sample(klass, allocated_bytes);
    return;
  }
  //獲取當前線程的 TLAB 指望大小
  const intptr_t tlab_size_bytes = estimate_tlab_size_bytes(thread);
  //若是當前線程分配過的字節大小與上次讀取的當前線程分配過的字節大小相差不超過 TLAB 指望大小，證實多是因爲 TLAB 快滿了致使的 TLAB 外分配，而且大小不大，不必上報。
  if (allocated_bytes - _last_allocated_bytes < tlab_size_bytes) {
    return;
  }
  assert(obj_alloc_size_bytes > 0, "invariant");
  //利用這個循環，若是當前線程分配過的字節大小越大，則採樣次數越多，越容易被採集到。
  do {
    if (send_allocation_sample_with_result(klass, allocated_bytes)) {
      return;
    }
    obj_alloc_size_bytes -= tlab_size_bytes;
  } while (obj_alloc_size_bytes > 0);
}

這裏咱們就觀察到了 JDK 作的第一個上報優化算法：若是本次分配對象大小越大，那麼這個循環次數就會越多，採樣次數就越多，被採集到的機率也越大
接下來來看具體的採樣方法：

inline bool send_allocation_sample_with_result(const Klass* klass, int64_t allocated_bytes) {
  assert(allocated_bytes > 0, "invariant");
  EventObjectAllocationSample event;
  //判斷事件是否應該 commit，只有 commit 的事件纔會被採集
  if (event.should_commit()) {
    //weight 等於上次記錄當前線程的 threadLocal 的 allocated_bytes 減去當前線程的 allocated_bytes
    //因爲不是每次線程發生 TLAB 外分配的時候上報都會被採集，因此須要記錄上次被採集時候的線程分配的 allocated_bytes 大小，計算與當前的差值就是本次上報的事件中的線程距離上次上報分配的對象大小。
    const size_t weight = allocated_bytes - _last_allocated_bytes;
    assert(weight > 0, "invariant");
    //objectClass 即觸發上報的分配對象的 class
    event.set_objectClass(klass);
    //weight 並不表明 objectClass 的對象的大小，而是這個線程距離上次上報被採集分配的對象大小
    event.set_weight(weight);
    event.commit();
    //只有事件 commit，也就是被採集，纔會更新 _last_allocated_bytes 這個 threadLocal 變量
    _last_allocated_bytes = allocated_bytes;
    return true;
  }
  return false;
}

經過這裏的代碼咱們明白了：

  • ObjectClass 是 TLAB 外分配對象的 class，也是本次觸發記錄jdk.ObjectAllocationSample 事件的對象的 class
  • weight 是線程距離上次記錄 jdk.ObjectAllocationSample 事件到當前這個事件時間內，線程分配的對象大小。

這裏一般會誤覺得 weight 就是本次事件 ObjectClass 的對象大小。這個須要着重注意下。

那麼如何判斷的事件是否應該 commit？ 這裏走的是 JFR 通用邏輯：
jfrEvent.hpp

bool should_commit() {
    if (!_started) {
      return false;
    }
    if (_untimed) {
      return true;
    }
    if (_evaluated) {
      return _should_commit;
    }
    _should_commit = evaluate();
    _evaluated = true;
    return _should_commit;
}
bool evaluate() {
    assert(_started, "invariant");
    if (_start_time == 0) {
      set_starttime(JfrTicks::now());
    } else if (_end_time == 0) {
      set_endtime(JfrTicks::now());
    }
    if (T::isInstant || T::isRequestable) {
      return T::hasThrottle ? JfrEventThrottler::accept(T::eventId, _untimed ? 0 : _start_time) : true;
    }
    if (_end_time - _start_time < JfrEventSetting::threshold(T::eventId)) {
      return false;
    }
    //這裏咱們先只關心 Throttle
    return T::hasThrottle ? JfrEventThrottler::accept(T::eventId, _untimed ? 0 : _end_time) : true;
}

這裏涉及 JfrEventThrottler 控制實現 throttle 配置。主要經過 EWMA 算法實現對於下次合適的採集時間間隔的不斷估算優化更新，來採集到最合適的 jdk.ObjectAllocationSample，同時這種算法並不像滑動窗口那樣記錄歷史數據致使佔用很大內存，指數移動平均（exponential moving average），或者叫作指數加權移動平均（exponentially weighted moving average），是以指數式遞減加權的移動平均，各數值的加權影響力隨時間呈指數式遞減，能夠用來估計變量的局部均值，使得變量的更新與一段時間內的歷史取值有關。

假設每次採集數據爲 P(n)，權重衰減程度爲 t，t 在 0~1 之間：

image

上面的公式，也能夠寫做：

image

從這個公式能夠看出，權重係數 t 以指數等比形式縮小，時間越靠近當前時刻的數據加權影響力越大。
這個 t 越小，過去過去累計值的權重越低，當前抽樣值的權重越高，平均值的實時性就越強。反之 t 越大，吸取瞬時突發值的能力變強，平均值的平穩性更好。

對於 jdk.ObjectAllocationSample 這個事件，算法實現即 jfrEventThrottler.hpp。若是你們感興趣，能夠在運行實例程序的時候，增長以下的啓動參數 -Xlog:jfr+system+throttle=debug 來查看這個 EWMA 採集窗口的相關信息，從而理解學習源碼。日誌示例：

[0.743s][debug][jfr,system,throttle] jdk.ObjectAllocationSample: avg.sample size: 0.0000, window set point: 0, sample size: 0, population size: 0, ratio: 0.0000, window duration: 0 ms

[1.761s][debug][jfr,system,throttle] jdk.ObjectAllocationSample: avg.sample size: 0.0400, window set point: 1, sample size: 1, population size: 19, ratio: 0.0526, window duration: 1000 ms

[2.775s][debug][jfr,system,throttle] jdk.ObjectAllocationSample: avg.sample size: 0.0784, window set point: 1, sample size: 1, population size: 19, ratio: 0.0526, window duration: 1000 ms

[3.794s][debug][jfr,system,throttle] jdk.ObjectAllocationSample: avg.sample size: 0.1153, window set point: 1, sample size: 1, population size: 118, ratio: 0.0085, window duration: 1000 ms

[4.815s][debug][jfr,system,throttle] jdk.ObjectAllocationSample: avg.sample size: 0.1507, window set point: 1, sample size: 1, population size: 107, ratio: 0.0093, window duration: 1000 ms

總結

  1. jdk.ObjectAllocationSample 是 Java 16 引入，用來優化對象分配不容易高效監控的事件。
  2. jdk.ObjectAllocationSample 事件裏面的 ObjectClass 是觸發事件的 class，weight 是線程分配的對象總大小。因此實際觀察的時候，採集會與實際狀況有些誤差。這是高效採集沒法避免的。
  3. JVM 經過 EMWA 作了算法優化，採集到的事件隨着程序運行會愈來愈是你的性能瓶頸或者熱點代碼相關的事件。

微信搜索「個人編程喵」關注公衆號，加做者微信，每日一刷，輕鬆提高技術，斬獲各類offer：

image

相關文章
相關標籤/搜索
每日一句
    每一个你不满意的现在，都有一个你没有努力的曾经。
本站公眾號
   歡迎關注本站公眾號,獲取更多信息
聯繫我們 最近搜索 最新文章 沪ICP备13005482号-10 MyBatis教程 SQL 教程 MySQL教程 Java 教程 Thymeleaf 教程 Hibernate教程 Spring教程 Redis教程