为啥 JFR 会跳过事件字段

Posted 2023-03-06

【中文标题】为啥 JFR 会跳过事件字段

【英文标题】：Why JFR skips event fields为什么 JFR 会跳过事件字段

【发布时间】：2021-09-07 14:18:11

【问题描述】：

我有一个简单的事件：

@Name("trace.dbquery")
public class QueryJfrEvent extends Event
    @Label("Event Name")
    public String eventName;
    
    @Label("Event Name2")
    public String eventName2;
    
    @Label("Event Name3")
    public String eventName3;
    
    @Label("timestamp")
    public long timestamp;  

并使用它：

QueryJfrEvent qevent= new QueryJfrEvent();
if(qevent.isEnabled())
    String name = span.name();
    System.out.println(" Check ---- " + name);
    
    qevent.eventName = name;
    qevent.eventName2 = name + "-bla-bla-bla";
    qevent.eventName3 = "test-test-test";
    qevent.timestamp = span.startTimestamp();
    qevent.commit;  

当我第一次启动 JFR（jcmd PID JFR.start name=test disk=true settings=./jfr/test.jfc filename=./jfr/result.jfr duration=30s）时，一切都很好。

所有字段 eventName/eventName2/eventName3 都是存在的。

例如：

jfr print --events trace.dbquery result.jfr
trace.dbquery 
    eventName = "SomeClassName"
    eventName2 = "SomeClassName-bla-bla-bla"
    eventName3 = "test-test-test"
    timestamp  =  1631023232432

但是当我第二次启动 JFR（相同的 JVM，无需重新启动）时，“jcmd PID JFR.start name=test disk=true settings=./jfr/test.jfc filename=./jfr/result2.jfr duration =30s" 字段 eventName 和 eventName2 为空，但 event3 正常 ""test-test-test""

jfr print --events trace.dbquery result2.jfr

trace.dbquery 
    eventName = N/A
    eventName2 = N/A    
    eventName3 = "test-test-test"
    timestamp  =  1631023234343

这段代码 "System.out.println(" Check ---- " + name);"始终显示正确的名称值。

我试用了 Linux OpenJDK 11、16 个最新版本。

【问题讨论】：

无法复制。就我而言，一切都按预期工作。发布 complete 示例，包括主类 test.jfc 和要运行的确切命令。另外，您使用哪个操作系统版本和 JDK 版本？

很遗憾，我无法在简单的应用程序中重现此问题。我整天都在尝试使用纯 Java 核心和 Spring Boot + Sleuth + Zipkin 的应用程序，但这个问题在同一个 Linux 主机、OpenJDK 等上无法重现。我会进一步尝试，但我不明白我的 Spring Boot 应用程序如何影响 JFR 内部逻辑。我还凭经验发现，在第二次执行 JFR.start 期间，超过 16 个字符的字段消失了。如果 String

openjdk version "11.0.9.1" 2020-11-04 LTS OpenJDK Runtime Environment 18.9 (build 11.0.9.1+1-LTS) OpenJDK 64-Bit Server VM 18.9 (build 11.0.9.1+1- LTS、混合模式、共享）

Red Hat Enterprise Linux 服务器版本 7.9 (Maipo) Linux xxxxxx 3.10.0-1160.31.1.el7.x86_64 #1 SMP Wed May 26 20:18:08 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

嗯。我不了解 JFR 源代码的所有逻辑，但有 LIMIT = 16 [link] (github.com/openjdk/jdk11u-dev/blob/…)

【参考方案1】：

如果开始连续录制，则会导致字符串值丢失，在 JDK 17 中已修复并向后移植到 JDK 11.0.12。

仅当字符串超过 16 个字符时才会出现该错误，因为它可能会被缓存。有关详细信息，请参阅：

https://bugs.openjdk.java.net/browse/JDK-8257621

【讨论】：

非常感谢您的帮助，但我已尝试升级 Java 版本，但问题仍然存在：openjdk 版本“11.0.12”2021-07-20 LTS OpenJDK 运行时环境 18.9（构建 11.0.12 +7-LTS) OpenJDK 64 位服务器 VM 18.9（内部版本 11.0.12+7-LTS，混合模式）

我测试了一整天，尝试剪切到 16 个字符，但自定义事件录制仍然非常不稳定。将行数减少到 16 行，一切似乎都很好，但是通过在我的自定义事件中再添加一个字段，一些事件开始从转储 JFR 文件中完全消失。不幸的是，JFR 中的自定义事件是一种非常原始的技术。

我想知道您是否出于某种原因在您正在运行的构建/发行版中没有修复程序。你试过 JDK 17 吗？