Java JFR 民间指南 - 事件详解 - jdk.ThreadAllocationStatistics(上)

简介: Java JFR 民间指南 - 事件详解 - jdk.ThreadAllocationStatistics(上)

定时线程分配统计事件:jdk.ThreadAllocationStatistics


引入版本:Java 11

相关 ISSUES

  1. Test jdk/jfr/event/runtime/TestThreadAllocationEvent.java fails with null thread:在某些情况下,jdk.ThreadAllocationStatistics 没有采集到 JFR 相关线程,导致空指针。这个 Bug 和 jdk/jfr/event/compiler/TestCompilerCompile.java failed due to "RuntimeException: No thread in event" 重复.该 BUG 对于使用没有大影响,于 Java 16 修复。
  2. Per thread IO statistics in JFR,这是一个新特性,期望和 ThreadAllocationStatistics 事件类似,提供每个线程的 IO 数据统计,这个特性还没有通过讨论。


各版本配置:


从 Java 11 引入之后没有改变过:

默认配置default.jfc of Java 11default.jfc of Java 12default.jfc of Java 13default.jfc of Java 14default.jfc of Java 15default.jfc of Java 16default.jfc of Java 17):

配置 描述

采样配置profile.jfc of Java 11profile.jfc of Java 12profile.jfc of Java 13profile.jfc of Java 14profile.jfc of Java 15profile.jfc of Java 16profile.jfc of Java 17):

配置 描述


为何需要这个事件?


Java 中业务线程都会分配对象,对于以下关键的业务,对象的分配可能更加频繁。有时候我们可能会遇到以下两个情况:

  1. 线上应用频繁 GC,可能是先开始 Young GC(New GC,Light GC,不同 GC 叫法不一样),之后伴随着 Old GC 或者 Full GC,可以观察到线上应用占用 CPU 高的线程也是 GC 线程。这个很可能是某个业务 BUG 拉取了大量的数据,例如查询数据库没加条件导致查询整个表,三方接口没限制 limit 返回了超级多的数据。想要直观快速的定位这个问题,可以通过观察那些线程突然分配了很多内存,然后查看这些线程的堆栈进一步确认。jdk.ThreadAllocationStatistics 就是用来查看这个的
  2. 线上 GC 变多,想要减少 GC,光看 jmap 对象统计太多抽象,并不直观知道是那些代码创建的这些对象。堆 dump 太重,对于大内存进程分析成本也很大。可以通过 jdk.ThreadAllocationStatistics 查看是那些线程分配对象比较多,采集这些线程的堆栈可以定位相关代码。


事件包含属性


属性 说明 举例


使用代码测试这个事件


package com.github.hashjang.jfr.test;
import com.sun.management.ThreadMXBean;
import jdk.jfr.Recording;
import jdk.jfr.consumer.RecordedEvent;
import jdk.jfr.consumer.RecordedThread;
import jdk.jfr.consumer.RecordingFile;
import sun.hotspot.WhiteBox;
import java.io.File;
import java.io.IOException;
import java.lang.management.ManagementFactory;
import java.nio.file.Path;
import java.time.Duration;
import java.util.Arrays;
import java.util.HashMap;
import java.util.Map;
import java.util.Random;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.TimeUnit;
import java.util.stream.Collectors;
public class TestThreadAllocationStatistics {
    private static String EVENT_NAME = "jdk.ThreadAllocationStatistics";
    //50ms采集一次
    private static long eventPeriodMillis = 50;
    //对于字节数组对象头占用16字节
    private static final int BYTE_ARRAY_OVERHEAD = 16;
    //我们要测试的对象大小是1kb
    private static final int OBJECT_SIZE = 1024;
    public static void main(String[] args) throws IOException {
        Recording recording = new Recording();
        recording.enable(EVENT_NAME).withPeriod(Duration.ofMillis(eventPeriodMillis));
        recording.start();
        //使用 WhiteBox 执行 FullGC,清除干扰
        WhiteBox whiteBox = WhiteBox.getWhiteBox();
        whiteBox.fullGC();
        Allocator allocators[] = new Allocator[4];
        CountDownLatch allocationsDoneLatch = new CountDownLatch(allocators.length);
        for (int i = 0; i < allocators.length; i++) {
            allocators[i] = new Allocator(allocationsDoneLatch, OBJECT_SIZE * (i + 1) - BYTE_ARRAY_OVERHEAD);
            allocators[i].setDaemon(true);
            allocators[i].start();
        }
        Map<Long, Allocator> map = Arrays.stream(allocators).collect(Collectors.toMap(Thread::getId, v -> v));
        Map<Long, Long> threadAllocatedMap = new HashMap<>();
        try {
            allocationsDoneLatch.await();
            //再等待一段时间让定时采集 jdk.ThreadAllocationStatistics 采集到最新的
            TimeUnit.SECONDS.sleep(1);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        recording.stop();
        Path path = new File(new File(".").getAbsolutePath(), "recording-" + recording.getId() + "-pid" + ProcessHandle.current().pid() + ".jfr").toPath();
        recording.dump(path);
        for (RecordedEvent event : RecordingFile.readAllEvents(path)) {
            if (!EVENT_NAME.equals(event.getEventType().getName())) {
                continue;
            }
            long javaThreadId = ((RecordedThread) event.getValue("thread")).getJavaThreadId();
            if (map.containsKey(javaThreadId)) {
                //事件是时间有序的(采集时间比较短),所以放入的最后一个就是采集到的线程最终的分配大小
                threadAllocatedMap.put(javaThreadId, event.getLong("allocated"));
                System.out.println(event);
            }
        }
        map.forEach((id, thread) -> {
            System.out.println("Thread " + id + " allocated(from JMX): " + thread.totalAllocated + "; allocated(from jdk.ThreadAllocationStatistics): " + threadAllocatedMap.get(id));
        });
    }
    public static class Allocator extends Thread {
        private volatile long totalAllocated = -1;
        private final int allocationSize;
        public byte[] buffer;
        private final CountDownLatch allocationsDoneLatch;
        public Allocator(CountDownLatch allocationsDoneLatch, int allocationSize) {
            this.allocationsDoneLatch = allocationsDoneLatch;
            this.allocationSize = allocationSize;
        }
        @Override
        public void run() {
            for (int batches = 0; batches < 100; batches++) {
                for (int i = 0; i < 1024; i++) {
                    buffer = new byte[allocationSize];
                }
                try {
                    //期望每个采集周期之间的分配次数为 5
                    Thread.sleep(eventPeriodMillis / 5);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
            //获取当前线程分配的对象大小
            totalAllocated = getThreadAllocatedBytes();
            allocationsDoneLatch.countDown();
            //设置线程为守护线程,等待主线程结束之后会自动结束
            //这里进入死循环是因为防止定时采集 jdk.ThreadAllocationStatistics 事件的时候采集不到
            while (true) {
                Thread.yield();
            }
        }
        private long getThreadAllocatedBytes() {
            ThreadMXBean bean = (ThreadMXBean) ManagementFactory.getThreadMXBean();
            return bean.getThreadAllocatedBytes(Thread.currentThread().getId());
        }
    }
}

使用以下 JVM 参数启动:

-Xbootclasspath/a:D:\github\jfr-spring-all\jdk-white-box\target\jdk-white-box-17.0-SNAPSHOT.jar  -Xms512m
相关文章
|
1月前
|
Cloud Native Java 编译器
Java生态系统的进化:从JDK 1.0到今天
Java生态系统的进化:从JDK 1.0到今天
|
1月前
|
Java 编译器 测试技术
滚雪球学Java(03):你知道JDK、JRE和JVM的不同吗?看这里就够了!
【2月更文挑战第12天】🏆本文收录于「滚雪球学Java」专栏,专业攻坚指数级提升,助你一臂之力,带你早日登顶🚀,欢迎大家关注&&收藏!持续更新中,up!up!up!!
103 4
|
2月前
|
监控 安全 Java
探索Java的未来:JDK 18新特性全览
探索Java的未来:JDK 18新特性全览
64 0
|
8天前
|
Java 应用服务中间件 Linux
Caused by: java.lang.UnsatisfiedLinkError: /root/jdk1.7.0_45/jre/lib/amd64/xawt/libmawt.so: libXrend
Caused by: java.lang.UnsatisfiedLinkError: /root/jdk1.7.0_45/jre/lib/amd64/xawt/libmawt.so: libXrend
|
19天前
|
Java Maven
运行maven项目出现Error:java: JDK isn‘t specified for module ‘XXX‘
运行maven项目出现Error:java: JDK isn‘t specified for module ‘XXX‘
11 0
|
1月前
|
Java
Java处理事件
Java处理事件
13 0
|
1月前
|
Java
916.【Java】javap 查看 class 文件的jdk编译版本
916.【Java】javap 查看 class 文件的jdk编译版本
42 2
|
1月前
|
Java 编译器 测试技术
滚雪球学Java(04):JDK、IntelliJ IDEA的安装和环境变量配置
【2月更文挑战第11天】🏆本文收录于「滚雪球学Java」专栏,专业攻坚指数级提升,助你一臂之力,带你早日登顶🚀,欢迎大家关注&&收藏!持续更新中,up!up!up!!
46 1
|
2月前
|
Java
Java中常用数据类型的值长度-jdk1.8
Java中常用数据类型的值长度-jdk1.8
16 0
|
2月前
|
设计模式 Java API
[Java]静态代理、动态代理(基于JDK1.8)
本篇文章主要是对静态代理和动态代理实现思路的简述,以示例为主,少涉及理论。 如果文中阐述不全或不对的,多多交流。
53 1
[Java]静态代理、动态代理(基于JDK1.8)