Fwd: RFC: JFR Recording Context

[Ludovic Henry]

Hello,

As it's been a couple of months since my last update, I wanted to share
some of the progress I've made there. The TL;DR is that it now supports
adding context to any event, as well as adding a global or per-event-type
filters to control the generation of events based on the context.

The changes are available at
https://github.com/openjdk/jdk/compare/master...luhenry:jfr-context

# Description of a context

A context is a map of string key and string value which are attached to
relevant JFR events. This context is installed on the current thread, and
can be snapshotted and activated on other threads.

# Building a context

To build a context, you first declare the keys of the context :

```

var contextKey1 = RecordingContextKey.forName("Key1");

```

Then, to use that key to build a specific context, use the following:

```

var context = RecordingContext.where(contextKey1, "Value1").build();

```

# Installing a context

Building a context will also install the context on the current thread. To
uninstall the context, simply do `context.close()`.

To capture the context and restore it on another thread, do:

```

// On the thread where the context is already installed:

var snapshot = RecordingContext.snapshot();

// On the thread you want to restore/install the context:

try (var activation = snapshot.activate()) { ... }

```

You can also use helper functions for structured concurrency:

```

RecordingContext.callWithSnapshot(o -> { ... }, snapshot);

RecordingContext.runWithSnapshot(() -> { ... }, snapshot);

```

# Lifecycle of a context

Let’s take a look at an example:

```

public class Program {

  private static final RecordingContextKey contextKey1 =

    RecordingContextKey.forName("Key1");

  public static void main(String[] args) {

    try (Recording recording = new Recording()) {

      recording.start();

      recording.enable("jdk.ThreadSleep");

      try (RecordingContext context =

            RecordingContext.where(contextKey1, "Value1").build()) {

        ForkJoinPool pool = ForkJoinPool.commonPool();

        final RecordingContext.Snapshot snapshot =
RecordingContext.snapshot();

        pool.execute(() -> {

          try (var activation = snapshot.activate()) {

            Thread.sleep(1);

          }

        });

        pool.execute(() -> {

          try (var activation = snapshot.activate()) {

            Thread.sleep(1);

          }

        });

        pool.shutdown();

        pool.awaitTermination(Long.MAX_VALUE, TimeUnit.DAYS);

      }

      recording.stop();

      recording.dump(Files.createTempFile("my-recording", ".jfr"));

    }

  }

}

```

The two `jdk.ThreadSleep` events generated are as follows:
```

jdk.ThreadSleep {

  startTime = 11:06:20.336 (2021-11-12)

  duration = 1.05 ms

  time = 1.00 ms

  eventThread = "main" (javaThreadId = 1)

  stackTrace = [

    java.lang.Thread.sleep(long)

    Program.lambda$main$0(RecordingContext$Snapshot) line: 23

    java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec() line:
1395

    java.util.concurrent.ForkJoinTask.doExec() line: 373

    java.util.concurrent.ForkJoinPool.externalHelpQuiescePool(long,
boolean) line: 2104

  ]

  context = [

    Key1 -> Value1,

  ]

}

jdk.ThreadSleep {

  startTime = 11:06:20.336 (2021-11-12)

  duration = 1.10 ms

  time = 1.00 ms

  eventThread = "ForkJoinPool.commonPool-worker-1" (javaThreadId = 18)

  stackTrace = [

    java.lang.Thread.sleep(long)

    Program.lambda$main$0(RecordingContext$Snapshot) line: 23

    java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec() line:
1395

    java.util.concurrent.ForkJoinTask.doExec() line: 373

    java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinTask,
ForkJoinPool$WorkQueue) line: 1182

  ]

  context = [

    Key1 -> Value1,

  ]

}

```

# Filtering on the context

In order to control the generation of events, this change introduces
context filters. A filter is per-type or for all types, and is installed
globally.

To build and install a filter, you do the following:

```

var filter = RecordingContextFilter.Config.createFilter()

  .forType(EventType.getEventType(TestEvent.class), b -> {

    b.hasEntry(contextKey1, "Value1");

  })

  .forAllTypes(b -> {

    b.hasKey(contextKey1);

  })

  .build()

RecordingContextFilter.Config.setContextFilter(filter);

```

To uninstall a filter, set it to null:
`RecordingContextFilter.Config.setContextFilter(null);`

The currently supported operations are:

- hasKey(key)

- hasEntry(key, value)

- hasContext()

- hasNoContext()

To guarantee a certain level of performance, I've made two tradeoffs:

 - A filter can't have custom code and can only use the supported
operations, and

 - The filters are eagerly computed on the installation of a context to
avoid matching the filter on the generation of every event. The per-type
and for all types results are stored in a map (or array in native) to
guarantee O(1) lookup time.

>From microbenchmarks, the current overhead is the following (all the JMH
numbers at [1]):

- Generating an event with the @Context annotation and an empty context
adds ~25ns to the generation of the event

- Each entry in the context adds ~100ns to the generation of an event

- Setting a filter does not impact the performance of the generation of an
event

I'll submit a draft PR in the following hours to give an easier time for
reviews and feedback.

Thank you again very much, and looking forward to your feedback and
questions.

Ludovic

[1]

Benchmark                                                Mode  Cnt  Score
Error  Units

RecordingContextBenchmark.Baseline.withContext           avgt   30  0.046 ±
0.001  us/op

RecordingContextBenchmark.Baseline.withoutContext        avgt   30  0.021 ±
0.001  us/op

RecordingContextBenchmark.One.withContext                avgt   30  0.160 ±
0.005  us/op

RecordingContextBenchmark.One.withoutContext             avgt   30  0.021 ±
0.001  us/op

RecordingContextBenchmark.Three.withContext              avgt   30  0.331 ±
0.009  us/op

RecordingContextBenchmark.Three.withoutContext           avgt   30  0.022 ±
0.001  us/op

RecordingContextBenchmark.Two.withContext                avgt   30  0.237 ±
0.003  us/op

RecordingContextBenchmark.Two.withoutContext             avgt   30  0.021 ±
0.001  us/op

RecordingContextFilterBenchmark.Baseline.withContext     avgt   30  0.048 ±
0.001  us/op

RecordingContextFilterBenchmark.Baseline.withoutContext  avgt   30  0.021 ±
0.001  us/op

RecordingContextFilterBenchmark.One.withContext          avgt   30  0.154 ±
0.003  us/op

RecordingContextFilterBenchmark.One.withoutContext       avgt   30  0.023 ±
0.001  us/op

RecordingContextFilterBenchmark.Three.withContext        avgt   30  0.346 ±
0.007  us/op

RecordingContextFilterBenchmark.Three.withoutContext     avgt   30  0.021 ±
0.001  us/op

RecordingContextFilterBenchmark.Two.withContext          avgt   30  0.239 ±
0.004  us/op

RecordingContextFilterBenchmark.Two.withoutContext       avgt   30  0.021 ±
0.001  us/op