mirror of
https://github.com/openjdk/jdk.git
synced 2026-01-28 12:09:14 +00:00
8356698: JFR: @Contextual
Reviewed-by: mgronlun
This commit is contained in:
Erik Gahlin
parent
ec02a87aee
commit
1373ceb7f3
67
src/jdk.jfr/share/classes/jdk/jfr/Contextual.java
Normal file
67
src/jdk.jfr/share/classes/jdk/jfr/Contextual.java
Normal file
@ -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 {
|
||||
}
|
||||
@ -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;
|
||||
|
||||
|
||||
@ -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);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
@ -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<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 final class PrettyWriter extends EventPrintWriter {
|
||||
this(destination, false);
|
||||
}
|
||||
|
||||
@Override
|
||||
protected void print(List<RecordedEvent> 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<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) {
|
||||
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 final class PrettyWriter extends EventPrintWriter {
|
||||
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"));
|
||||
}
|
||||
|
||||
@ -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")
|
||||
|
||||
420
test/jdk/jdk/jfr/tool/TestPrintContextual.java
Normal file
420
test/jdk/jdk/jfr/tool/TestPrintContextual.java
Normal file
@ -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<Map.Entry<String, String>> contextValues = new ArrayList<>();
|
||||
private final List<Map.Entry<String, String>> 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<Map.Entry<String, String>> 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<PrintedEvent> 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<PrintedEvent> 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<PrintedEvent> 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<PrintedEvent> 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<PrintedEvent> 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<PrintedEvent> dumpPrintedEvents(Recording r, Path file) throws Exception {
|
||||
r.dump(file);
|
||||
return parseEvents(readPrintedLines(file));
|
||||
}
|
||||
|
||||
private static List<PrintedEvent> parseEvents(List<String> lines) {
|
||||
List<PrintedEvent> 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<String> 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();
|
||||
}
|
||||
}
|
||||
Loading…
x
Reference in New Issue
Block a user