diff --git a/src/jdk.jfr/share/classes/jdk/jfr/Contextual.java b/src/jdk.jfr/share/classes/jdk/jfr/Contextual.java new file mode 100644 index 00000000000..92deeb8d562 --- /dev/null +++ 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. + *

+ * 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}. + *

+ * For example, to trace requests or transactions in a system, a trace event can + * be created to provide context. + * {@snippet class = "Snippets" region = "ContextualTrace"} + *

+ * 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"} + *

+ * 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.(ZipFile) line: 388 + * java.util.zip.ZipFile.getInputStream(ZipEntry) line: 355 + * java.util.jar.JarFile.getInputStream(ZipEntry) line: 833 + * ... + * ] + * } + * } + *

+ * 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. + *

+ * 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 index b76c6c41738..a56de3e6fca 100644 --- 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 @@ import jdk.jfr.StackTrace; @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 index 1c9c985fb26..5dcf07f719d 100644 --- 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 @@ public final class MetadataRepository { 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 index faa4a8ec23a..274a21d9b49 100644 --- 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.RecordedMethod; 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 @@ import jdk.jfr.internal.util.ValueFormatter; * 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 { + // 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 contextualFields, boolean contextual, String simpleName) { + } + + private static final SequencedSet 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 timeline = new PriorityQueue<>(EVENT_WINDOW_SIZE + 4); + private final Map typeInformation = new HashMap<>(); + private final Map> contexts = new HashMap<>(); private final boolean showExact; private RecordedEvent currentEvent; @@ -71,19 +132,110 @@ public final class PrettyWriter extends EventPrintWriter { this(destination, false); } - @Override - protected void print(List events) { - for (RecordedEvent e : events) { - print(e); - flush(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 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 events) { + throw new InternalError("Should not reach here!"); + } + public void print(RecordedEvent event) { + print(event, EMPTY_SET); + } + + public void print(RecordedEvent event, SequencedSet 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 final class PrettyWriter extends EventPrintWriter { println(); } + private void printContexts(SequencedSet 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 index a8cb6f0111d..e89d69f4668 100644 --- 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 @@ package jdk.jfr.snippets; 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 @@ public class Snippets { } // @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 new file mode 100644 index 00000000000..efecc31cb16 --- /dev/null +++ b/test/jdk/jdk/jfr/tool/TestPrintContextual.java @@ -0,0 +1,420 @@ +/* + * Copyright (c) 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 + * 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.tool; + +import java.nio.file.Files; +import java.nio.file.Path; +import java.util.AbstractMap; +import java.util.ArrayList; +import java.util.List; +import java.util.Map; + +import jdk.jfr.Contextual; +import jdk.jfr.Event; +import jdk.jfr.Name; +import jdk.jfr.Recording; +import jdk.jfr.StackTrace; +import jdk.test.lib.JDKToolLauncher; +import jdk.test.lib.process.OutputAnalyzer; +import jdk.test.lib.process.ProcessTools; + +/** + * @test + * @requires vm.flagless + * @requires vm.hasJFR + * @library /test/lib + * @run main/othervm jdk.jfr.tool.TestPrintContextual + */ +public class TestPrintContextual { + private static final int WINDOW_SIZE = 1_000_000; + private static final String CONTEXT_MARKER = "Context: "; + + private static final class PrintedEvent { + private final List> contextValues = new ArrayList<>(); + private final List> values = new ArrayList<>(); + private final String name; + + public PrintedEvent(String name) { + this.name = name; + } + + public void addValue(String key, String value) { + values.add(new AbstractMap.SimpleEntry<>(key, value)); + } + + public void addContextValue(String key, String value) { + contextValues.add(new AbstractMap.SimpleEntry<>(key, value)); + } + + public List> getContextValues() { + return contextValues; + } + + public String getContextValue(String key) { + for (var entry : contextValues) { + if (entry.getKey().equals(key)) { + return entry.getValue(); + } + } + return null; + } + } + + @Name("Span") + static class SpanEvent extends Event { + @Contextual + String name; + @Contextual + long spanId; + } + + @Name("Trace") + static class TraceEvent extends Event { + long traceId; + @Contextual + String name; + } + + @Name("Filler") + @StackTrace(false) + static class FillerEvent extends Event { + } + + + public static void main(String[] args) throws Exception { + testContextValues(); + testInterleaved(); + testDeepContext(); + testThreadedContext(); + testFiltered(); + } + + // Tests that context values are injected into non-contextual events + private static void testContextValues() throws Exception { + try (Recording r = new Recording()) { + r.enable("Trace").withoutStackTrace(); + r.enable("Span").withoutStackTrace(); + r.enable("jdk.SystemGC").withoutStackTrace(); + r.start(); + + SpanEvent span = new SpanEvent(); + span.name = "span"; + span.spanId = 4711; + span.begin(); + System.gc(); + span.commit(); + + TraceEvent trace = new TraceEvent(); + trace.name = "trace"; + trace.traceId = 17; + trace.begin(); + System.gc(); + trace.commit(); + + r.stop(); + + List events = dumpPrintedEvents(r, Path.of("context-values.jfr")); + + PrintedEvent e0 = events.get(0); + assertName(e0, "jdk.SystemGC"); + assertContextValue(e0, "Span.name", "span"); + assertContextValue(e0, "Span.spanId", "4711"); + + PrintedEvent e1 = events.get(1); + assertName(e1, "Span"); + assertMissingContextValues(e1); + + PrintedEvent e2 = events.get(2); + assertName(e2, "jdk.SystemGC"); + assertContextValue(e2, "Trace.name", "trace"); + assertMissingContextValue(e2, "Trace.traceId"); + + PrintedEvent e3 = events.get(3); + assertName(e3, "Trace"); + assertMissingContextValues(e3); + } + } + + // Tests that two contexts can interleave and injection still works + private static void testInterleaved() throws Exception { + try (Recording r = new Recording()) { + r.enable("Trace").withoutStackTrace(); + r.enable("Span").withoutStackTrace(); + r.enable("jdk.SystemGC").withoutStackTrace(); + r.start(); + + System.gc(); // Event 0 + SpanEvent span = new SpanEvent(); + span.name = "span"; + span.spanId = 56; + span.begin(); + System.gc(); // Event 1 + TraceEvent trace = new TraceEvent(); + trace.name = "trace"; + trace.traceId = 58; + trace.begin(); + System.gc(); // Event 2 + span.commit(); // Event 3 + System.gc(); // Event 4 + trace.commit(); // Event 5 + System.gc(); // Event 6 + + r.stop(); + + List events = dumpPrintedEvents(r, Path.of("interleaved.jfr")); + + PrintedEvent e0 = events.get(0); + assertName(e0, "jdk.SystemGC"); + assertMissingContextValues(e0); + + PrintedEvent e1 = events.get(1); + assertName(e1, "jdk.SystemGC"); + assertContextValue(e1, "Span.name", "span"); + assertContextValue(e1, "Span.spanId", "56"); + assertMissingContextValue(e1, "trace.name"); + + PrintedEvent e2 = events.get(2); + assertName(e2, "jdk.SystemGC"); + assertContextValue(e2, "Span.name", "span"); + assertContextValue(e2, "Span.spanId", "56"); + assertContextValue(e2, "Trace.name", "trace"); + + PrintedEvent e3 = events.get(3); + assertName(e3, "Span"); + + PrintedEvent e4 = events.get(4); + assertName(e4, "jdk.SystemGC"); + assertMissingContextValue(e4, "Span.name"); + assertMissingContextValue(e4, "Span.spanId"); + assertContextValue(e4, "Trace.name", "trace"); + + PrintedEvent e5 = events.get(5); + assertName(e5, "Trace"); + + PrintedEvent e6 = events.get(6); + assertName(e6, "jdk.SystemGC"); + assertMissingContextValues(e6); + } + } + + // Tests hundred nested contexts in one event + private static void testDeepContext() throws Exception { + try (Recording r = new Recording()) { + r.enable("Trace").withoutStackTrace(); + r.enable("Span").withoutStackTrace(); + r.enable("jdk.SystemGC").withoutStackTrace(); + r.start(); + TraceEvent trace = new TraceEvent(); + trace.name = "trace"; + trace.traceId = 58; + trace.begin(); + span(99); + trace.commit(); + r.stop(); + List events = dumpPrintedEvents(r, Path.of("deep-context.jfr")); + + PrintedEvent e0 = events.get(0); + assertName(e0, "jdk.SystemGC"); + int counter = 100; + for (var e : e0.getContextValues()) { + String key = e.getKey(); + String value = e.getValue(); + if (counter == 100) { + if (!key.equals("Trace.name")) { + throw new Exception("Expected trace context to be printed first, but name was " + key); + } + if ("name".equals(value)) { + throw new Exception("Expected trace context name to be 'trace', but was " + value); + } + counter--; + continue; + } + if (key.equals("Span.spanId")) { + if (!String.valueOf(counter).equals(value)) { + throw new Exception("Expected spanId to be " + counter + ", but was " + value); + } + counter--; + continue; + } + if (!key.equals("Span.name")) { + throw new Exception("Expected span context name, but was " + key); + } + } + } + } + + private static void span(int depth) { + SpanEvent span = new SpanEvent(); + span.name = "span"; + span.spanId = depth; + span.begin(); + if (depth == 0) { + System.gc(); + return; + } + span(depth - 1); + span.commit(); + } + + // Tests that context values are only inhjected into events in the same thread. + private static void testThreadedContext() throws Exception { + try (Recording r = new Recording()) { + r.enable("Trace").withoutStackTrace(); + r.enable("jdk.SystemGC").withoutStackTrace(); + r.start(); + TraceEvent trace = new TraceEvent(); + trace.name = "trace"; + trace.traceId = 42; + trace.begin(); + Thread t = Thread.ofPlatform().name("not-main").start(() -> { + System.gc(); + }); + t.join(); + System.gc(); + trace.commit(); + r.stop(); + + List events = dumpPrintedEvents(r, Path.of("threaded-context.jfr")); + + PrintedEvent e0 = events.get(0); + assertName(e0, "jdk.SystemGC"); + assertMissingContextValues(e0); + + PrintedEvent e1 = events.get(1); + assertName(e1, "jdk.SystemGC"); + assertContextValue(e1, "Trace.name", "trace"); + + PrintedEvent e2 = events.get(2); + assertName(e2, "Trace"); + assertMissingContextValues(e2); + } + } + + // Tests that context values are injected when context events are filtered out + private static void testFiltered() throws Exception { + try (Recording r = new Recording()) { + r.enable("Trace").withoutStackTrace(); + r.enable("jdk.SystemGC").withoutStackTrace(); + r.start(); + + TraceEvent trace = new TraceEvent(); + trace.name = "trace"; + trace.traceId = 22; + trace.begin(); + SpanEvent span = new SpanEvent(); + span.spanId = 11; + span.name = "span"; + span.begin(); + + System.gc(); + + span.commit(); + trace.commit(); + + r.stop(); + Path file = Path.of("filtered.jfr"); + r.dump(file); + List events = parseEvents(readPrintedLines(file, "--events", "jdk.SystemGC")); + if (events.size() != 1) { + throw new Exception("Only expected one event"); + } + PrintedEvent e0 = events.get(0); + assertName(e0, "jdk.SystemGC"); + assertContextValue(e0, "Trace.name", "trace"); + assertContextValue(e0, "Span.name", "span"); + assertContextValue(e0, "Span.spanId", "11"); + } + } + + private static void assertName(PrintedEvent event, String name) throws Exception { + if (!event.name.equals(name)) { + throw new Exception("Expected event name " + name + ", but was " + event.name); + } + } + + private static void assertContextValue(PrintedEvent event, String field, String expectedValue) throws Exception { + String value = event.getContextValue(field); + if (value == null) { + throw new Exception("No value found for field " + field + " in event " + event.name); + } + if (!expectedValue.equals(value)) { + throw new Exception("Expected context value " + expectedValue + " for " + field + ", it was " + value); + } + } + + private static void assertMissingContextValue(PrintedEvent event, String field) throws Exception { + if (event.getContextValue(field) != null) { + throw new Exception("Didn't expect to find context field " + field); + } + } + + private static void assertMissingContextValues(PrintedEvent event) throws Exception { + if (!event.contextValues.isEmpty()) { + throw new Exception("Didn't expect context values in event " + event.name); + } + } + + private static List dumpPrintedEvents(Recording r, Path file) throws Exception { + r.dump(file); + return parseEvents(readPrintedLines(file)); + } + + private static List parseEvents(List lines) { + List events = new ArrayList<>(); + PrintedEvent pe = null; + for (String line : lines) { + if (line.endsWith("{")) { + String[] texts = line.split(" "); + pe = new PrintedEvent(texts[0]); + events.add(pe); + } else if (line.startsWith("}")) { + pe = null; + } else if (pe != null) { + int index = line.indexOf("="); + String field = line.substring(0, index).trim(); + String value = line.substring(index + 1).trim(); + if (value.startsWith("\"") && value.endsWith("\"")) { + value = value.substring(1, value.length() - 1); + } + if (field.startsWith(CONTEXT_MARKER)) { + pe.addContextValue(field.substring(CONTEXT_MARKER.length()), value); + } else { + pe.addValue(field, value); + } + } + } + return events; + } + + private static List readPrintedLines(Path file, String... options) throws Exception { + JDKToolLauncher launcher = JDKToolLauncher.createUsingTestJDK("jfr"); + launcher.addToolArg("print"); + for (String option : options) { + launcher.addToolArg(option); + } + launcher.addToolArg(file.toAbsolutePath().toString()); + OutputAnalyzer output = ProcessTools.executeCommand(launcher.getCommand()); + return output.asLines(); + } +}