Java JFR 民间指南 - 事件详解 - jdk.ObjectAllocationInNewTLAB

╰半夏微凉° 2023-01-16 02:56 69阅读 0赞

# 重新申请 TLAB 分配对象事件：jdk.ObjectAllocationInNewTLAB #

**引入版本**：Java 11

**相关 ISSUES**：

1.  [JFR: RecordingStream leaks memory][JFR_ RecordingStream leaks memory]：启用 jdk.ObjectAllocationInNewTLAB 发现在 RecordingStream 中有内存泄漏，影响 Java 14、15、16，在 jdk-16+36 (Java 16.0.1) 修复。
2.  [Introduce JFR Event Throttling and new jdk.ObjectAllocationSample event (enabled by default)][Introduce JFR Event Throttling and new jdk.ObjectAllocationSample event _enabled by default]：引入 jdk.ObjectAllocationSample 优化并替代 jdk.ObjectAllocationInNewTLAB 和 jdk.ObjectAllocationOutsideTLAB 事件。

## 各版本配置： ##

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

**默认配置**（[default.jfc of Java 11][]，[default.jfc of Java 12][]，[default.jfc of Java 13][]，[default.jfc of Java 14][]，[default.jfc of Java 15][]，[default.jfc of Java 16][]，[default.jfc of Java 17][]）:

<table> 
 <thead> 
  <tr> 
   <th>配置</th> 
   <th>值</th> 
   <th>描述</th> 
  </tr> 
 </thead> 
 <tbody> 
  <tr> 
   <td>enabled</td> 
   <td>false</td> 
   <td>默认不启用</td> 
  </tr> 
  <tr> 
   <td>stackTrace</td> 
   <td>true</td> 
   <td>采集事件的时候，也采集堆栈</td> 
  </tr> 
 </tbody> 
</table>

**采样配置**（[profile.jfc of Java 11][]，[profile.jfc of Java 12][]，[profile.jfc of Java 13][]，[profile.jfc of Java 14][]，[profile.jfc of Java 15][]，[profile.jfc of Java 16][]，[profile.jfc of Java 17][]）:

<table> 
 <thead> 
  <tr> 
   <th>配置</th> 
   <th>值</th> 
   <th>描述</th> 
  </tr> 
 </thead> 
 <tbody> 
  <tr> 
   <td>enabled</td> 
   <td>true</td> 
   <td>默认启用</td> 
  </tr> 
  <tr> 
   <td>stackTrace</td> 
   <td>true</td> 
   <td>采集事件的时候，也采集堆栈</td> 
  </tr> 
 </tbody> 
</table>

## 为何需要这个事件？ ##

首先我们来看下 Java 对象分配的流程：

![image][]

对于 HotSpot JVM 实现，所有的 GC 算法的实现都是一种对于堆内存的管理，也就是都实现了一种堆的抽象，它们都实现了接口 CollectedHeap。当分配一个对象堆内存空间时，在 CollectedHeap 上首先都会检查是否启用了 TLAB，如果启用了，则会尝试 TLAB 分配；如果当前线程的 TLAB 大小足够，那么从线程当前的 TLAB 中分配；如果不够，但是当前 TLAB 剩余空间小于**最大浪费空间限制**，则从堆上（一般是 Eden 区） 重新申请一个新的 TLAB 进行分配（对应当前提到的事件 jdk.ObjectAllocationInNewTLAB）。否则，直接在 TLAB 外进行分配（对应事件 jdk.ObjectAllocationOutsideTLAB）。TLAB 外的分配策略，不同的 GC 算法不同。例如G1：

*  如果是 Humongous 对象（对象在超过 Region 一半大小的时候），直接在 Humongous 区域分配（老年代的连续区域）。
 *  根据 Mutator 状况在当前分配下标的 Region 内分配

对于大部分的 JVM 应用，大部分的对象是在 TLAB 中分配的。如果 TLAB 外分配过多，或者 TLAB 重分配过多，那么我们需要检查代码，检查是否有大对象，或者不规则伸缩的对象分配，以便于优化代码。

## 事件包含属性 ##

<table> 
 <thead> 
  <tr> 
   <th>属性</th> 
   <th>说明</th> 
   <th>举例</th> 
  </tr> 
 </thead> 
 <tbody> 
  <tr> 
   <td>startTime</td> 
   <td>事件开始时间</td> 
   <td>10:16:27.718</td> 
  </tr> 
  <tr> 
   <td>objectClass</td> 
   <td>触发本次事件的对象的类</td> 
   <td>byte[] (classLoader = bootstrap)</td> 
  </tr> 
  <tr> 
   <td>allocationSize</td> 
   <td>分配对象大小</td> 
   <td>10.0 MB</td> 
  </tr> 
  <tr> 
   <td>tlabSize</td> 
   <td>当前线程的 TLAB 大小</td> 
   <td>512.0 KB</td> 
  </tr> 
  <tr> 
   <td>eventThread</td> 
   <td>事件发生所在线程</td> 
   <td>“Thread-0” (javaThreadId = 27)</td> 
  </tr> 
  <tr> 
   <td>stackTrace</td> 
   <td>事件发生所在堆栈</td> 
   <td>略</td> 
  </tr> 
 </tbody> 
</table>

## 使用代码测试这个事件 ##

package com.github.hashjang.jfr.test;
    
    import jdk.jfr.Recording;
    import jdk.jfr.consumer.RecordedEvent;
    import jdk.jfr.consumer.RecordedFrame;
    import jdk.jfr.consumer.RecordingFile;
    import sun.hotspot.WhiteBox;
    
    import java.io.File;
    import java.nio.file.Path;
    
    public class TestAllocOutsideTLAB {
        //对于字节数组对象头占用16字节
        private static final int BYTE_ARRAY_OVERHEAD = 16;
        //我们要测试的对象大小是100kb
        private static final int OBJECT_SIZE = 1024;
        //字节数组对象名称
        private static final String BYTE_ARRAY_CLASS_NAME = new byte[0].getClass().getName();
    
        //需要使用静态field，而不是方法内本地变量，否则编译后循环内的new byte[]全部会被省略，只剩最后一次的
        public static byte[] tmp;
    
        public static void main(String[] args) throws Exception {
            WhiteBox whiteBox = WhiteBox.getWhiteBox();
            //初始化 JFR 记录
            Recording recording = new Recording();
            recording.enable("jdk.ObjectAllocationInNewTLAB");
            // JFR 记录启动
            recording.start();
            //强制 fullGC 防止接下来程序发生 GC
            //同时可以区分出初始化带来的其他线程的TLAB相关的日志
            whiteBox.fullGC();
            //分配对象，大小1KB
            for (int i = 0; i < 512; ++i) {
                tmp = new byte[OBJECT_SIZE - BYTE_ARRAY_OVERHEAD];
            }
            //强制 fullGC，回收所有 TLAB
            whiteBox.fullGC();
            //分配对象，大小100KB
            for (int i = 0; i < 200; ++i) {
                tmp = new byte[OBJECT_SIZE * 100 - BYTE_ARRAY_OVERHEAD];
            }
            whiteBox.fullGC();
            //将 JFR 记录 dump 到一个文件
            Path path = new File(new File(".").getAbsolutePath(), "recording-" + recording.getId() + "-pid" + ProcessHandle.current().pid() + ".jfr").toPath();
            recording.dump(path);
            int countOf1KBObjectAllocationInNewTLAB = 0;
            int countOf100KBObjectAllocationInNewTLAB = 0;
            //读取文件中的所有 JFR 事件
            for (RecordedEvent event : RecordingFile.readAllEvents(path)) {
                //获取分配的对象的类型
                String className = event.getString("objectClass.name");
    
                if (
                    //确保分配类型是 byte[]
                        BYTE_ARRAY_CLASS_NAME.equalsIgnoreCase(className)
                ) {
                    RecordedFrame recordedFrame = event.getStackTrace().getFrames().get(0);
                    //同时必须是咱们这里的main方法分配的对象，并且是Java堆栈中的main方法
                    if (recordedFrame.isJavaFrame()
                            && "main".equalsIgnoreCase(recordedFrame.getMethod().getName())
                    ) {
                        //获取分配对象大小
                        long allocationSize = event.getLong("allocationSize");
                            if ("jdk.ObjectAllocationInNewTLAB".equalsIgnoreCase(event.getEventType().getName())) {
                            if (allocationSize == 102400) {
                                countOf100KBObjectAllocationInNewTLAB++;
                            } else if (allocationSize == 1024) {
                                countOf1KBObjectAllocationInNewTLAB++;
                            }
                        } else {
                            throw new Exception("unexpected size of TLAB event");
                        }
                        System.out.println(event);
                    }
                }
            }
            System.out.println("countOf1KBObjectAllocationInNewTLAB: " + countOf1KBObjectAllocationInNewTLAB);
            System.out.println("countOf100KBObjectAllocationInNewTLAB: " + countOf100KBObjectAllocationInNewTLAB);
            //阻塞程序，保证所有日志输出完
            Thread.currentThread().join();
        }
    }

以下面参数运行这个程序，注意将 whitebox jar 包位置参数替换成你的 whitebox jar 包所在位置。

-Xbootclasspath/a:D:\github\jfr-spring-all\jdk-white-box\target\jdk-white-box-17.0-SNAPSHOT.jar -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI -Xms512m -Xmx512m

运行结果：

jdk.ObjectAllocationInNewTLAB {
      //事件开始时间
      startTime = 07:37:53.309
      //分配对象类
      objectClass = byte[] (classLoader = bootstrap)
      //分配对象大小
      allocationSize = 1.0 kB
      //当前线程的 TLAB 大小
      tlabSize = 457.7 kB
      //事件发生所在线程
      eventThread = "main" (javaThreadId = 1)
      //事件发生所在堆栈
      stackTrace = [
        com.github.hashjang.jfr.test.TestAllocOutsideTLAB.main(String[]) line: 92
      ]
    }
    
    
    jdk.ObjectAllocationInNewTLAB {
      startTime = 07:37:53.310
      objectClass = byte[] (classLoader = bootstrap)
      allocationSize = 1.0 kB
      tlabSize = 310.3 kB
      eventThread = "main" (javaThreadId = 1)
      stackTrace = [
        com.github.hashjang.jfr.test.TestAllocOutsideTLAB.main(String[]) line: 92
      ]
    }
    
    
    jdk.ObjectAllocationInNewTLAB {
      startTime = 07:37:53.405
      objectClass = byte[] (classLoader = bootstrap)
      allocationSize = 100.0 kB
      tlabSize = 512.0 kB
      eventThread = "main" (javaThreadId = 1)
      stackTrace = [
        com.github.hashjang.jfr.test.TestAllocOutsideTLAB.main(String[]) line: 98
      ]
    }
    
    
    jdk.ObjectAllocationInNewTLAB {
      startTime = 07:37:53.409
      objectClass = byte[] (classLoader = bootstrap)
      allocationSize = 100.0 kB
      tlabSize = 512.0 kB
      eventThread = "main" (javaThreadId = 1)
      stackTrace = [
        com.github.hashjang.jfr.test.TestAllocOutsideTLAB.main(String[]) line: 98
      ]
    }
    
    countOf1KBObjectAllocationInNewTLAB: 2
    countOf100KBObjectAllocationInNewTLAB: 2

## 底层原理以及相关 JVM 源码 ##

在每次发生内存分配的时候，都会创建一个 Allocation 对象记录描述本次分配的一些状态，他的构造函数以及析构函数为（其中 JFR 事件要采集的我已经注释出来了）：

[`memAllocator.cpp`][memAllocator.cpp]

public:
      Allocation(const MemAllocator& allocator, oop* obj_ptr)
          //内存分配器
        : _allocator(allocator),
          //分配线程
          _thread(Thread::current()),
          //要分配的对象指针
          _obj_ptr(obj_ptr),
          _overhead_limit_exceeded(false),
          //是否是 tlab 外分配
          _allocated_outside_tlab(false),
          //本次分配新分配的 tlab 大小，只有发生 tlab 重分配这个值才会大于 0
          _allocated_tlab_size(0),
          _tlab_end_reset_for_sample(false)
      {
        verify_before();
      }
    
      ~Allocation() {
        if (!check_out_of_memory()) {
          verify_after();
          //在销毁时，调用 notify_allocation 来上报相关采集
          notify_allocation();
        }
      }

`notify_allocation()`包括：

void MemAllocator::Allocation::notify_allocation() {
      notify_allocation_low_memory_detector();
      //上报 jfr 相关
      notify_allocation_jfr_sampler();
      notify_allocation_dtrace_sampler();
      notify_allocation_jvmti_sampler();
    }
    
    void MemAllocator::Allocation::notify_allocation_jfr_sampler() {
      HeapWord* mem = cast_from_oop<HeapWord*>(obj());
      size_t size_in_bytes = _allocator._word_size * HeapWordSize;
      //如果标记的是 tlab 外分配，调用 send_allocation_outside_tlab
      if (_allocated_outside_tlab) {
        AllocTracer::send_allocation_outside_tlab(obj()->klass(), mem, size_in_bytes, _thread);
      } else if (_allocated_tlab_size != 0) {
        //如果不是 tlab 外分配，并且 _allocated_tlab_size 大于 0，代表发生了 tlab 重分配，调用 send_allocation_outside_tlab
        AllocTracer::send_allocation_in_new_tlab(obj()->klass(), mem, _allocated_tlab_size * HeapWordSize,
                                                 size_in_bytes, _thread);
      }
    }

在发生 TLAB 重分配的时候，会立刻生成这个事件并上报，对应源码：  
[`allocTracer.cpp`][allocTracer.cpp]

//在每次发生 TLAB 重分配的时候，调用这个方法上报
    void AllocTracer::send_allocation_in_new_tlab(Klass* klass, HeapWord* obj, size_t tlab_size, size_t alloc_size, Thread* thread) {
      JFR_ONLY(JfrAllocationTracer tracer(obj, alloc_size, thread);)
      //立刻生成 jdk.ObjectAllocationInNewTLAB 这个事件
      EventObjectAllocationInNewTLAB event;
      if (event.should_commit()) {
        event.set_objectClass(klass);
        event.set_allocationSize(alloc_size);
        event.set_tlabSize(tlab_size);
        event.commit();
      }
      const int64_t allocated_bytes = load_allocated_bytes(thread);
      if (allocated_bytes == 0) {
        return;
      }
      //采样 jdk.ObjectAllocationSample 事件
      send_allocation_sample(klass, allocated_bytes);
    }

通过源码分析我们可以知道，如果开启这个事件，**那么只要发生 TLAB 重分配，就会生成并采集一个 jdk.ObjectAllocationInNewTLAB 事件**。

## 为何一般不在先生持续开启这个事件 ##

这个事件配置项比较少，只要开启，就会发生一个 TLAB 重分配，就生成并采集一个 jdk.ObjectAllocationInNewTLAB 事件。对于大型项目来说，分析这个事件，**如果没有堆栈，会很难定位**。并且，**并不是所有的 TLAB 重分配都是性能瓶颈**，但是也无法简单的动态采集定位。**如果需要动态开启采集，需要我们写额外的代码实现**。如果开启堆栈采集，那么只要发生比较大量的 jdk.ObjectAllocationInNewTLAB 事件，就会成为性能瓶颈，**因为堆栈采集是很耗费性能的**。目前大部分的 Java 线上应用，尤其是微服务应用，都使用了各种框架，堆栈非常深，可能达到几百，如果涉及响应式编程，这个堆栈就更深了。JFR 考虑到这一点，**默认采集堆栈深度最多是 64**，即使是这样，也还是比较耗性能的。并且，在 Java 11 之后，JDK 一直在优化获取堆栈的速度，例如堆栈方法字符串放入缓冲池，优化缓冲池过期策略与 GC 策略等等，但是目前性能损耗还是不能忽视。

如果你不想开发额外代码，还想线上持续监控的话，建议使用 Java 16 引入的 [jdk.ObjectAllocationSample][]

## 总结 ##

1.  jdk.ObjectAllocationInNewTLAB 监控 TLAB 重分配事件，如果开启，只要发生 TLAB 重分配，就会生成并采集一个 jdk.ObjectAllocationInNewTLAB 事件。
2.  开启采集，并打开堆栈采集的话，会非常消耗性能。
3.  如果你不想开发额外代码，还想线上持续监控的话，建议使用 Java 16 引入的 [jdk.ObjectAllocationSample][]

> **微信搜索“我的编程喵”关注公众号，加作者微信，每日一刷，轻松提升技术，斩获各种offer**：

> ![image][image 1]

[JFR_ RecordingStream leaks memory]: https://bugs.openjdk.java.net/browse/JDK-8257906
[Introduce JFR Event Throttling and new jdk.ObjectAllocationSample event _enabled by default]: https://bugs.openjdk.java.net/browse/JDK-8257602
[default.jfc of Java 11]: https://github.com/openjdk/jdk/blob/jdk-11+28/src/jdk.jfr/share/conf/jfr/default.jfc
[default.jfc of Java 12]: https://github.com/openjdk/jdk/blob/jdk-12+33/src/jdk.jfr/share/conf/jfr/default.jfc
[default.jfc of Java 13]: https://github.com/openjdk/jdk/blob/jdk-13+33/src/jdk.jfr/share/conf/jfr/default.jfc
[default.jfc of Java 14]: https://github.com/openjdk/jdk/blob/jdk-14+36/src/jdk.jfr/share/conf/jfr/default.jfc
[default.jfc of Java 15]: https://github.com/openjdk/jdk/blob/jdk-15+36/src/jdk.jfr/share/conf/jfr/default.jfc
[default.jfc of Java 16]: https://github.com/openjdk/jdk/blob/jdk-16+36/src/jdk.jfr/share/conf/jfr/default.jfc
[default.jfc of Java 17]: https://github.com/openjdk/jdk/blob/jdk-17+19/src/jdk.jfr/share/conf/jfr/default.jfc
[profile.jfc of Java 11]: https://github.com/openjdk/jdk/blob/jdk-11+28/src/jdk.jfr/share/conf/jfr/profile.jfc
[profile.jfc of Java 12]: https://github.com/openjdk/jdk/blob/jdk-12+33/src/jdk.jfr/share/conf/jfr/profile.jfc
[profile.jfc of Java 13]: https://github.com/openjdk/jdk/blob/jdk-13+33/src/jdk.jfr/share/conf/jfr/profile.jfc
[profile.jfc of Java 14]: https://github.com/openjdk/jdk/blob/jdk-14+36/src/jdk.jfr/share/conf/jfr/profile.jfc
[profile.jfc of Java 15]: https://github.com/openjdk/jdk/blob/jdk-15+36/src/jdk.jfr/share/conf/jfr/profile.jfc
[profile.jfc of Java 16]: https://github.com/openjdk/jdk/blob/jdk-16+36/src/jdk.jfr/share/conf/jfr/profile.jfc
[profile.jfc of Java 17]: https://github.com/openjdk/jdk/blob/jdk-17+19/src/jdk.jfr/share/conf/jfr/profile.jfc
[image]: /images/20221022/f1318c39df62424d9b3c14ff0568e68f.png
[memAllocator.cpp]: https://github.com/openjdk/jdk/blob/jdk-17+19/src/hotspot/share/gc/shared/memAllocator.cpp
[allocTracer.cpp]: https://github.com/openjdk/jdk/blob/jdk-17+19/src/hotspot/share/gc/shared/allocTracer.cpp
[jdk.ObjectAllocationSample]: https://juejin.cn/post/6953934014029758500
[image 1]: /images/20221022/2d3c59fedc3240089061116be822cab6.png