OpenJDK開発記：JDK-8249720: Generated bytecodes of EventWriter don't be output to the logを直してみた。

これは何？

今回、パッチを書いたのはJDK-8249720のGenerated bytecodes of EventWriter don't be output to the logです。

[JDK-8249720] Generated bytecodes of EventWriter don't be output to the log - Java Bug System

VM起動引数に-Xlog:jfr+system+bytecode=traceを付けてJFRを実行すると、JFRの中で動的に作成されて使用されるEventWriterが生成されたときに、そのクラスのオペコードをログに出力する機能があります。 たまたまその機能を使ってバイトコードの変化を探してたらこのバグを発見しました。 OpenJDK の 15 からそれがデグレにより出力されなくなったため、それを修正しました。

どんな実装だったのか

原因としては、JFR のログ出力周りのオーバーヘッドを減らすという修正が入ったときに、修正ミスによってログが出力されなくなってしまいました。

-        Logger.log(LogTag.JFR_SYSTEM_BYTECODE, LogLevel.TRACE, () -> {
+        if (Logger.shouldLog(LogTag.JFR_SYSTEM_BYTECODE, LogLevel.TRACE)) {
            ClassReader cr = new ClassReader(bytes);
            ByteArrayOutputStream baos = new ByteArrayOutputStream();
            PrintWriter w = new PrintWriter(baos);
            w.println("Bytecode:");
            cr.accept(new TraceClassVisitor(w), 0);
-            return baos.toString();
-        });
+        };

以前の実装では、最後の行のreturn baos.toString();がロガーに渡されてログを出力していました。これを消してしまったためログが出なくなっています。

8247320: JFR: Reduce logging overhead · openjdk/jdk@65c461e · GitHub

どう直したの？

単純にログを出力する行を足しただけです。それに加えて、もうデグレしないようにテストケースを追加しています。

パッチはこちら

パッチの抜粋はこちらです。

--- old/src/jdk.jfr/share/classes/jdk/jfr/internal/ASMToolkit.java   2020-07-19 21:31:04.125291400 +0900
+++ new/src/jdk.jfr/share/classes/jdk/jfr/internal/ASMToolkit.java    2020-07-19 21:31:03.955544600 +0900
@@ -155,6 +155,7 @@
             PrintWriter w = new PrintWriter(baos);
             w.println("Bytecode:");
             cr.accept(new TraceClassVisitor(w), 0);
+            Logger.log(LogTag.JFR_SYSTEM_BYTECODE, LogLevel.TRACE, baos.toString());
         };
     }
 
--- /dev/null 2020-07-19 21:20:25.577740400 +0900
+++ new/test/jdk/jdk/jfr/jvm/TestEventWriterLog.java  2020-07-19 21:31:05.847842600 +0900
@@ -0,0 +1,44 @@
+ * @test TestEventWriterLog
+ * @summary Test that log message of JFR when handle bytecodes
+ * @key jfr
+ * @requires vm.hasJFR
+ * @library /test/lib /test/jdk
+ * @run main/othervm TestEventWriterLog
+ */
+
+import jdk.test.lib.process.ProcessTools;
+import jdk.test.lib.process.OutputAnalyzer;
+
+public class TestEventWriterLog {
+    public static void main(String[] args) throws Exception {
+        ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-Xlog:jfr+system+bytecode=trace", "-XX:StartFlightRecording", "-version");
+        OutputAnalyzer output = new OutputAnalyzer(pb.start());
+        output.shouldContain("extends jdk/jfr/internal/handlers/EventHandler");
+    }
+}