From 1b924659c87045796f62e66d69ff388b79c4467f Mon Sep 17 00:00:00 2001 From: Erik Gahlin Date: Fri, 2 Dec 2022 17:21:48 +0000 Subject: [PATCH] 8297608: JFR: Incorrect duration after chunk rotation Reviewed-by: mgronlun --- .../jfr/internal/EventInstrumentation.java | 17 ++--- test/jdk/jdk/jfr/jvm/TestEventDuration.java | 74 +++++++++++++++++++ 2 files changed, 82 insertions(+), 9 deletions(-) create mode 100644 test/jdk/jdk/jfr/jvm/TestEventDuration.java diff --git a/src/jdk.jfr/share/classes/jdk/jfr/internal/EventInstrumentation.java b/src/jdk.jfr/share/classes/jdk/jfr/internal/EventInstrumentation.java index b562c5739a6..3d02032370a 100644 --- a/src/jdk.jfr/share/classes/jdk/jfr/internal/EventInstrumentation.java +++ b/src/jdk.jfr/share/classes/jdk/jfr/internal/EventInstrumentation.java @@ -478,18 +478,20 @@ public final class EventInstrumentation { methodVisitor.visitInsn(Opcodes.RETURN); methodVisitor.visitLabel(l0); methodVisitor.visitFrame(Opcodes.F_SAME, 0, null, 0, null); + // long startTime = this.startTime + methodVisitor.visitVarInsn(Opcodes.ALOAD, 0); + methodVisitor.visitFieldInsn(Opcodes.GETFIELD, getInternalClassName(), FIELD_START_TIME, "J"); + methodVisitor.visitVarInsn(Opcodes.LSTORE, 1); // if (startTime == 0) { // startTime = EventWriter.timestamp(); // } else { - methodVisitor.visitVarInsn(Opcodes.ALOAD, 0); - methodVisitor.visitFieldInsn(Opcodes.GETFIELD, getInternalClassName(), FIELD_START_TIME, "J"); + methodVisitor.visitVarInsn(Opcodes.LLOAD, 1); methodVisitor.visitInsn(Opcodes.LCONST_0); methodVisitor.visitInsn(Opcodes.LCMP); Label durationalEvent = new Label(); methodVisitor.visitJumpInsn(Opcodes.IFNE, durationalEvent); - methodVisitor.visitVarInsn(Opcodes.ALOAD, 0); methodVisitor.visitMethodInsn(Opcodes.INVOKESTATIC, TYPE_EVENT_CONFIGURATION.getInternalName(), METHOD_TIME_STAMP.getName(), METHOD_TIME_STAMP.getDescriptor(), false); - methodVisitor.visitFieldInsn(Opcodes.PUTFIELD, getInternalClassName(), FIELD_START_TIME, "J"); + methodVisitor.visitVarInsn(Opcodes.LSTORE, 1); Label commit = new Label(); methodVisitor.visitJumpInsn(Opcodes.GOTO, commit); // if (duration == 0) { @@ -505,8 +507,7 @@ public final class EventInstrumentation { methodVisitor.visitJumpInsn(Opcodes.IFNE, commit); methodVisitor.visitVarInsn(Opcodes.ALOAD, 0); methodVisitor.visitMethodInsn(Opcodes.INVOKESTATIC, TYPE_EVENT_CONFIGURATION.getInternalName(), METHOD_TIME_STAMP.getName(), METHOD_TIME_STAMP.getDescriptor(), false); - methodVisitor.visitVarInsn(Opcodes.ALOAD, 0); - methodVisitor.visitFieldInsn(Opcodes.GETFIELD, getInternalClassName(), FIELD_START_TIME, "J"); + methodVisitor.visitVarInsn(Opcodes.LLOAD, 1); methodVisitor.visitInsn(Opcodes.LSUB); methodVisitor.visitFieldInsn(Opcodes.PUTFIELD, getInternalClassName(), FIELD_DURATION, "J"); methodVisitor.visitLabel(commit); @@ -531,9 +532,7 @@ public final class EventInstrumentation { int fieldIndex = 0; methodVisitor.visitInsn(Opcodes.DUP); // stack: [EW] [EW] - methodVisitor.visitVarInsn(Opcodes.ALOAD, 0); - // stack: [EW] [EW] [this] - methodVisitor.visitFieldInsn(Opcodes.GETFIELD, getInternalClassName(), FIELD_START_TIME, "J"); + methodVisitor.visitVarInsn(Opcodes.LLOAD, 1); // stack: [EW] [EW] [long] invokeVirtual(methodVisitor, TYPE_EVENT_WRITER, EventWriterMethod.PUT_LONG.asmMethod); // stack: [EW] diff --git a/test/jdk/jdk/jfr/jvm/TestEventDuration.java b/test/jdk/jdk/jfr/jvm/TestEventDuration.java new file mode 100644 index 00000000000..53a7af9e323 --- /dev/null +++ b/test/jdk/jdk/jfr/jvm/TestEventDuration.java @@ -0,0 +1,74 @@ +/* + * Copyright (c) 2018, Oracle and/or its affiliates. All rights reserved. + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. + * + * This code is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License version 2 only, as + * published by the Free Software Foundation. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA + * or visit www.oracle.com if you need additional information or have any + * questions. + */ + +package jdk.jfr.jvm; + +import jdk.jfr.Event; +import jdk.jfr.Recording; +import jdk.jfr.consumer.RecordingFile; +import java.nio.file.Path; + +/** + * @test Tests that the event duration is zero after a chunk rotation + * @key jfr + * @requires vm.hasJFR + * @library /test/lib + * @modules jdk.jfr/jdk.jfr.internal + * @run main/othervm jdk.jfr.jvm.TestEventDuration + */ +public class TestEventDuration { + + static class InstantEvent extends Event { + long id; + } + + public static void main(String... args) throws Exception { + try (Recording r1 = new Recording()) { + r1.start(); + long counter = 0; + for (int i = 0; i < 10; i ++) { + try (Recording r2 = new Recording()) { + r2.start(); + InstantEvent e1 = new InstantEvent(); + e1.id = counter++; + e1.commit(); + InstantEvent e2 = new InstantEvent(); + e2.id = counter++; + e2.commit(); + } + } + Path p = Path.of("dump.jfr"); + r1.dump(p); + var events = RecordingFile.readAllEvents(p); + if (events.isEmpty()) { + throw new AssertionError("Expected at least one event"); + } + events.forEach(System.out::println); + for (var event : events) { + if (event.getDuration().toNanos() != 0) { + throw new AssertionError("Expected all events to have zero duration"); + } + } + } + } +}