8356698: JFR: @contextual

egahlin · egahlin · commit 1373ceb7f304 · 2025-06-02T18:22:35.000Z
Reviewed-by: mgronlun
diff --git a/src/jdk.jfr/share/classes/jdk/jfr/Contextual.java b/src/jdk.jfr/share/classes/jdk/jfr/Contextual.java
@@ -0,0 +1,67 @@
+package jdk.jfr;
+
+import java.lang.annotation.ElementType;
+import java.lang.annotation.Retention;
+import java.lang.annotation.RetentionPolicy;
+import java.lang.annotation.Target;
+
+/**
+ * Event field annotation, specifies that the value carries contextual
+ * information.
+ * <p>
+ * Contextual information is data that applies to all events happening in the
+ * same thread from the beginning to the end of the event with a field annotated
+ * with {@code Contextual}.
+ * <p>
+ * For example, to trace requests or transactions in a system, a trace event can
+ * be created to provide context.
+ * {@snippet class = "Snippets" region = "ContextualTrace"}
+ * <p>
+ * To track details within an order service, an order event can be created where
+ * only the order ID provides context.
+ * {@snippet class = "Snippets" region = "ContextualOrder"}
+ * <p>
+ * If an order in the order service stalls due to lock contention, a user
+ * interface can display contextual information together with the
+ * JavaMonitorEnter event to simplify troubleshooting, for example:
+ * {@snippet lang=text :
+ *   $ jfr print --events JavaMonitorEnter recording.jfr
+ *   jdk.JavaMonitorEnter {
+ *     Context: Trace.id = "00-0af7651916cd43dd8448eb211c80319c-00f067aa0ba902b7-01"
+ *     Context: Trace.name = "POST /checkout/place-order"
+ *     Context: Order.id = 314159
+ *     startTime = 17:51:29.038 (2025-02-07)
+ *     duration = 50.56 ms
+ *     monitorClass = java.util.ArrayDeque (classLoader = bootstrap)
+ *    previousOwner = "Order Thread" (javaThreadId = 56209, virtual = true)
+ *    address = 0x60000232ECB0
+ *    eventThread = "Order Thread" (javaThreadId = 52613, virtual = true)
+ *    stackTrace = [
+ *      java.util.zip.ZipFile$CleanableResource.getInflater() line: 685
+ *      java.util.zip.ZipFile$ZipFileInflaterInputStream.<init>(ZipFile) line: 388
+ *      java.util.zip.ZipFile.getInputStream(ZipEntry) line: 355
+ *      java.util.jar.JarFile.getInputStream(ZipEntry) line: 833
+ *      ...
+ *    ]
+ *   }
+ * }
+ * <p>
+ * The difference between {@link Relational} and {@link Contextual} annotations
+ * is that {@link Relational} ties event data together to form a global data
+ * structure, similar to a foreign key in a relational database, but
+ * {@link Contextual} represents a state that applies to all events that happen
+ * at the same time, in the same thread. A field can be both contextual and
+ * relational at the same time.
+ * <p>
+ * A contextual field may incur overhead on a parser reading a recording file,
+ * since it must track active context, so it should be used sparingly and only
+ * where appropriate.
+ *
+ * @since 25
+ */
+@MetadataDefinition
+@Label("Context")
+@Retention(RetentionPolicy.RUNTIME)
+@Target({ElementType.FIELD})
+public @interface Contextual {
+}
diff --git a/src/jdk.jfr/share/classes/jdk/jfr/events/MethodTraceEvent.java b/src/jdk.jfr/share/classes/jdk/jfr/events/MethodTraceEvent.java
@@ -25,6 +25,7 @@
 package jdk.jfr.events;
 
 import jdk.jfr.Category;
+import jdk.jfr.Contextual;
 import jdk.jfr.Label;
 import jdk.jfr.Name;
 import jdk.jfr.StackTrace;
@@ -35,6 +36,7 @@
 @StackTrace(true)
 public final class MethodTraceEvent extends AbstractJDKEvent {
 
+    @Contextual
     @Label("Method")
     private long method;
 
diff --git a/src/jdk.jfr/share/classes/jdk/jfr/internal/MetadataRepository.java b/src/jdk.jfr/share/classes/jdk/jfr/internal/MetadataRepository.java
@@ -205,7 +205,11 @@ private EventConfiguration makeConfiguration(Class<? extends jdk.internal.event.
                     nativeEventTypes.remove(n);
                     nativeControls.remove(n);
                     TypeLibrary.removeType(nativeType.getId());
-                    pEventType.setFields(nativeType.getFields());
+                    PrivateAccess access = PrivateAccess.getInstance();
+                    for (int i = 0; i < nativeFields.size(); i++) {
+                        access.setAnnotations(nativeFields.get(i), eventFields.get(i).getAnnotationElements());
+                    }
+                    pEventType.setFields(nativeFields);
                 }
             }
         }
diff --git a/src/jdk.jfr/share/classes/jdk/jfr/internal/tool/PrettyWriter.java b/src/jdk.jfr/share/classes/jdk/jfr/internal/tool/PrettyWriter.java
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2016, 2024, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2016, 2025, 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
@@ -25,15 +25,26 @@
 
 package jdk.jfr.internal.tool;
 
+import java.io.IOException;
 import java.io.PrintWriter;
+import java.nio.file.Path;
 import java.time.Duration;
+import java.time.Instant;
 import java.time.OffsetDateTime;
 import java.time.format.DateTimeFormatter;
 import java.time.temporal.ChronoUnit;
+import java.util.ArrayList;
+import java.util.HashMap;
+import java.util.LinkedHashSet;
 import java.util.List;
+import java.util.Map;
+import java.util.PriorityQueue;
+import java.util.SequencedSet;
 import java.util.StringJoiner;
 
+import jdk.jfr.Contextual;
 import jdk.jfr.DataAmount;
+import jdk.jfr.EventType;
 import jdk.jfr.Frequency;
 import jdk.jfr.MemoryAddress;
 import jdk.jfr.Percentage;
@@ -46,7 +57,7 @@
 import jdk.jfr.consumer.RecordedObject;
 import jdk.jfr.consumer.RecordedStackTrace;
 import jdk.jfr.consumer.RecordedThread;
-import jdk.jfr.internal.Type;
+import jdk.jfr.consumer.RecordingFile;
 import jdk.jfr.internal.util.ValueFormatter;
 
 /**
@@ -55,10 +66,60 @@
  * This class is also used by {@link RecordedObject#toString()}
  */
 public final class PrettyWriter extends EventPrintWriter {
-    private static final String TYPE_OLD_OBJECT = Type.TYPES_PREFIX + "OldObject";
+    private static record Timestamp(RecordedEvent event, long seconds, int nanosCompare, boolean contextual) implements Comparable<Timestamp> {
+        // If the start timestamp from a contextual event has the same start timestamp
+        // as an ordinary instant event, the contextual event should be processed first
+        // One way to ensure this is to multiply the nanos value and add 1 ns to the end
+        // timestamp so the context event always comes first in a comparison.
+        // This also prevents a contextual start time to be processed after a contextual
+        // end time, if the event is instantaneous.
+        public static Timestamp createStart(RecordedEvent event, boolean contextual) {
+            Instant time = event.getStartTime(); // Method allocates, so store seconds and nanos
+            return new Timestamp(event, time.getEpochSecond(), 2 * time.getNano(), contextual);
+        }
+
+        public static Timestamp createEnd(RecordedEvent event, boolean contextual) {
+            Instant time = event.getEndTime(); // Method allocates, so store seconds and nanos
+            return new Timestamp(event, time.getEpochSecond(), 2 * time.getNano() + 1, contextual);
+        }
+
+        public boolean start() {
+            return (nanosCompare & 1L) == 0;
+        }
+
+        @Override
+        public int compareTo(Timestamp that) {
+            // This is taken from Instant::compareTo
+            int cmp = Long.compare(seconds, that.seconds);
+            if (cmp != 0) {
+                return cmp;
+            }
+            return nanosCompare - that.nanosCompare;
+        }
+    }
+
+    private static record TypeInformation(Long id, List<ValueDescriptor> contextualFields, boolean contextual, String simpleName) {
+    }
+
+    private static final SequencedSet<RecordedEvent> EMPTY_SET = new LinkedHashSet<>();
+    private static final String TYPE_OLD_OBJECT = "jdk.types.OldObject";
     private static final DateTimeFormatter TIME_FORMAT_EXACT = DateTimeFormatter.ofPattern("HH:mm:ss.SSSSSSSSS (yyyy-MM-dd)");
     private static final DateTimeFormatter TIME_FORMAT = DateTimeFormatter.ofPattern("HH:mm:ss.SSS (yyyy-MM-dd)");
     private static final Long ZERO = 0L;
+    // Rationale for using one million events in the window.
+    // Events in JFR arrive in batches. The commit time (end time) of an
+    // event in batch N typically doesn't come before any events in batch N - 1,
+    // but it can't be ruled out completely. Data is also partitioned into chunks,
+    // typically 16 MB each. Within a chunk, there must be at least one batch.
+    // The size of an event is typically more than 16 bytes, so an
+    // EVENT_WINDOW_SIZE of 1 000 000 events will likely cover more than one batch.
+    // Having at least two batches in a window avoids boundary issues.
+    // At the same time, a too large window, means it will take more time
+    // before the first event is printed and the tool will feel unresponsive.
+    private static final int EVENT_WINDOW_SIZE = 1_000_000;
+    private final PriorityQueue<Timestamp> timeline = new PriorityQueue<>(EVENT_WINDOW_SIZE + 4);
+    private final Map<Long, TypeInformation> typeInformation = new HashMap<>();
+    private final Map<Long, SequencedSet<RecordedEvent>> contexts = new HashMap<>();
     private final boolean showExact;
     private RecordedEvent currentEvent;
 
@@ -71,19 +132,110 @@ public PrettyWriter(PrintWriter destination) {
         this(destination, false);
     }
 
+    void print(Path source) throws IOException {
+        printBegin();
+        int counter = 0;
+        try (RecordingFile file = new RecordingFile(source)) {
+            while (file.hasMoreEvents()) {
+                RecordedEvent event = file.readEvent();
+                if (typeInformation(event).contextual()) {
+                    timeline.add(Timestamp.createStart(event, true));
+                    timeline.add(Timestamp.createEnd(event, true));
+                }
+                if (acceptEvent(event)) {
+                    timeline.add(Timestamp.createEnd(event, false));
+                }
+                // There should not be a limit on the size of the recording files that
+                // the 'jfr' tool can process. To avoid OutOfMemoryError and time complexity
+                // issues on large recordings, a window size must be set when sorting
+                // and processing contextual events.
+                while (timeline.size() > EVENT_WINDOW_SIZE) {
+                    print(timeline.remove());
+                    flush(false);
+                }
+                if ((++counter % EVENT_WINDOW_SIZE) == 0) {
+                    contexts.entrySet().removeIf(c -> c.getValue().isEmpty());
+                }
+            }
+            while (!timeline.isEmpty()) {
+                print(timeline.remove());
+            }
+        }
+        printEnd();
+        flush(true);
+    }
+
+    private TypeInformation typeInformation(RecordedEvent event) {
+        long id = event.getEventType().getId();
+        TypeInformation ti = typeInformation.get(id);
+        if (ti == null) {
+            ti = createTypeInformation(event.getEventType());
+            typeInformation.put(ti.id(), ti);
+        }
+        return ti;
+    }
+
+    private TypeInformation createTypeInformation(EventType eventType) {
+        ArrayList<ValueDescriptor> contextualFields = new ArrayList<>();
+        for (ValueDescriptor v : eventType.getFields()) {
+            if (v.getAnnotation(Contextual.class) != null) {
+                contextualFields.add(v);
+            }
+        }
+        contextualFields.trimToSize();
+        String name = eventType.getName();
+        String simpleName = name.substring(name.lastIndexOf(".") + 1);
+        boolean contextual = contextualFields.size() > 0;
+        return new TypeInformation(eventType.getId(), contextualFields, contextual, simpleName);
+    }
+
+    private void print(Timestamp t) {
+        RecordedEvent event = t.event();
+        RecordedThread rt = event.getThread();
+        if (rt != null) {
+            processThreadedTimestamp(rt, t);
+        } else {
+            if (!t.contextual()) {
+                print(event);
+            }
+        }
+    }
+
+    public void processThreadedTimestamp(RecordedThread thread, Timestamp t) {
+        RecordedEvent event = t.event();
+        var contextEvents = contexts.computeIfAbsent(thread.getId(), k -> new LinkedHashSet<>(1));
+        if (t.contextual) {
+            if (t.start()) {
+                contextEvents.add(event);
+            } else {
+                contextEvents.remove(event);
+            }
+            return;
+        }
+        if (typeInformation(event).contextual()) {
+            print(event);
+        } else {
+            print(event, contextEvents);
+        }
+    }
+
     @Override
     protected void print(List<RecordedEvent> events) {
-        for (RecordedEvent e : events) {
-            print(e);
-            flush(false);
-        }
+        throw new InternalError("Should not reach here!");
     }
 
     public void print(RecordedEvent event) {
+        print(event, EMPTY_SET);
+    }
+
+    public void print(RecordedEvent event, SequencedSet<RecordedEvent> context) {
         currentEvent = event;
         print(event.getEventType().getName(), " ");
         println("{");
         indent();
+        if (!context.isEmpty()) {
+            printContexts(context);
+        }
         for (ValueDescriptor v : event.getFields()) {
             String name = v.getName();
             if (!isZeroDuration(event, name) && !isLateField(name)) {
@@ -106,6 +258,22 @@ public void print(RecordedEvent event) {
         println();
     }
 
+    private void printContexts(SequencedSet<RecordedEvent> contextEvents) {
+        for (RecordedEvent e : contextEvents) {
+            printContextFields(e);
+        }
+    }
+
+    private void printContextFields(RecordedEvent contextEvent) {
+        TypeInformation ti = typeInformation(contextEvent);
+        for (ValueDescriptor v : ti.contextualFields()) {
+            printIndent();
+            String name = "Context: " + ti.simpleName() + "." + v.getName();
+            print(name, " = ");
+            printValue(getValue(contextEvent, v), v, "");
+        }
+    }
+
     private boolean isZeroDuration(RecordedEvent event, String name) {
         return name.equals("duration") && ZERO.equals(event.getValue("duration"));
     }
diff --git a/src/jdk.jfr/share/classes/jdk/jfr/snippet-files/Snippets.java b/src/jdk.jfr/share/classes/jdk/jfr/snippet-files/Snippets.java
@@ -26,6 +26,7 @@
 
 import jdk.jfr.AnnotationElement;
 import jdk.jfr.BooleanFlag;
+import jdk.jfr.Contextual;
 import jdk.jfr.ValueDescriptor;
 import jdk.jfr.EventFactory;
 import jdk.jfr.EventType;
@@ -251,6 +252,39 @@ void printTemperaturesInCelsius(Path file) throws IOException {
     }
     // @end
 
+    // @start region="ContextualTrace"
+    @Label("Trace")
+    @Name("com.example.Trace")
+    class TraceEvent extends Event {
+        @Label("ID")
+        @Contextual
+        String id;
+
+        @Label("Name")
+        @Contextual
+        String name;
+    }
+    // @end
+
+    void hello() {
+        // @start region="ContextualOrder"
+        @Label("Order")
+        @Name("com.example.Order")
+        class OrderEvent extends Event {
+            @Label("Order ID")
+            @Contextual
+            long id;
+
+            @Label("Order Date")
+            @Timestamp(Timestamp.MILLISECONDS_SINCE_EPOCH)
+            long date;
+
+            @Label("Payment Method")
+            String paymentMethod;
+        }
+        // @end
+    }
+
     // @start region="DataAmountOverview"
     @Name("com.example.ImageRender")
     @Label("Image Render")
diff --git a/test/jdk/jdk/jfr/tool/TestPrintContextual.java b/test/jdk/jdk/jfr/tool/TestPrintContextual.java

Original file line number	Diff line number	Diff line change
`@@ -205,7 +205,11 @@ private EventConfiguration makeConfiguration(Class<? extends jdk.internal.event.`
`205`	`205`	`nativeEventTypes.remove(n);`
`206`	`206`	`nativeControls.remove(n);`
`207`	`207`	`TypeLibrary.removeType(nativeType.getId());`
`208`		`- pEventType.setFields(nativeType.getFields());`
	`208`	`+ PrivateAccess access = PrivateAccess.getInstance();`
	`209`	`+ for (int i = 0; i < nativeFields.size(); i++) {`
	`210`	`+ access.setAnnotations(nativeFields.get(i), eventFields.get(i).getAnnotationElements());`
	`211`	`+ }`
	`212`	`+ pEventType.setFields(nativeFields);`
`209`	`213`	`}`
`210`	`214`	`}`
`211`	`215`	`}`