Adds JDK Flight Recorder context correlation

.travis.yml

@@ -10,7 +10,7 @@ cache:
 language: java
 
 jdk:
-  - oraclejdk9
+  - oraclejdk11
 
 before_install:
   # Parameters used during release

brave-bom/pom.xml

@@ -91,6 +91,11 @@
         <artifactId>brave-tests</artifactId>
         <version>${project.version}</version>
       </dependency>
+      <dependency>
+        <groupId>${project.groupId}</groupId>
+        <artifactId>brave-context-jfr</artifactId>
+        <version>${project.version}</version>
+      </dependency>
       <dependency>
         <groupId>${project.groupId}</groupId>
         <artifactId>brave-context-log4j2</artifactId>

context/jfr/pom.xml

@@ -0,0 +1,52 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<project xmlns="http://maven.apache.org/POM/4.0.0"
+    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
+    xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
+  <parent>
+    <groupId>io.zipkin.brave</groupId>
+    <artifactId>brave-context-parent</artifactId>
+    <version>5.5.3-SNAPSHOT</version>
+  </parent>
+  <modelVersion>4.0.0</modelVersion>
+
+  <artifactId>brave-context-jfr</artifactId>
+  <name>Brave Context: JDK Flight Recorder</name>
+
+  <properties>
+    <main.basedir>${project.basedir}/../..</main.basedir>
+    <main.java.version>11</main.java.version>
+  </properties>
+
+  <build>
+    <plugins>
+      <plugin>
+        <artifactId>maven-jar-plugin</artifactId>
+        <configuration>
+          <archive>
+            <manifestEntries>
+              <Automatic-Module-Name>brave.context.jfr</Automatic-Module-Name>
+            </manifestEntries>
+          </archive>
+        </configuration>
+      </plugin>
+      <plugin>
+        <groupId>net.orfjackal.retrolambda</groupId>
+        <artifactId>retrolambda-maven-plugin</artifactId>
+        <executions>
+          <execution>
+            <phase>none</phase>
+          </execution>
+        </executions>
+      </plugin>
+      <plugin>
+        <groupId>org.codehaus.mojo</groupId>
+        <artifactId>animal-sniffer-maven-plugin</artifactId>
+        <executions>
+          <execution>
+            <phase>none</phase>
+          </execution>
+        </executions>
+      </plugin>
+    </plugins>
+  </build>
+</project>

context/jfr/src/main/java/brave/context/jfr/JfrScopeDecorator.java

@@ -0,0 +1,68 @@
+package brave.context.jfr;
+
+import brave.internal.Nullable;
+import brave.propagation.CurrentTraceContext.Scope;
+import brave.propagation.CurrentTraceContext.ScopeDecorator;
+import brave.propagation.TraceContext;
+import jdk.jfr.Category;
+import jdk.jfr.Description;
+import jdk.jfr.Event;
+import jdk.jfr.Label;
+
+/**
+ * Adds {@linkplain Event} properties "traceId", "parentId" and "spanId" when a {@link
+ * brave.Tracer#currentSpan() span is current}. These can be used to correlate JDK Flight recorder
+ * events with logs or Zipkin.
+ *
+ * <p>Ex.
+ * <pre>{@code
+ * tracing = Tracing.newBuilder()
+ *                  .currentTraceContext(ThreadLocalCurrentTraceContext.newBuilder()
+ *                    .addScopeDecorator(JfrScopeDecorator.create())
+ *                    .build()
+ *                  )
+ *                  ...
+ *                  .build();
+ * }</pre>
+ */
+public final class JfrScopeDecorator implements ScopeDecorator {
+
+  @Category("Zipkin")
+  @Label("Scope")
+  @Description("Zipkin event representing a span being placed in scope")
+  static final class ScopeEvent extends Event {
+    @Label("Trace Id") String traceId;
+    @Label("Parent Id") String parentId;
+    @Label("Span Id") String spanId;
+  }
+
+  public static ScopeDecorator create() {
+    return new JfrScopeDecorator();
+  }
+
+  @Override public Scope decorateScope(@Nullable TraceContext currentSpan, Scope scope) {
+    ScopeEvent event = new ScopeEvent();
+    if (!event.isEnabled()) return scope;
+
+    if (currentSpan != null) {
+      event.traceId = currentSpan.traceIdString();
+      event.parentId = currentSpan.parentIdString();
+      event.spanId = currentSpan.spanIdString();
+    }
+
+    event.begin();
+
+    class JfrCurrentTraceContextScope implements Scope {
+      @Override public void close() {
+        scope.close();
+        if (!event.shouldCommit()) return;
+        event.end();
+        event.commit();
+      }
+    }
+    return new JfrCurrentTraceContextScope();
+  }
+
+  JfrScopeDecorator() {
+  }
+}

context/jfr/src/test/java/brave/context/jfr/JfrScopeDecoratorTest.java

@@ -0,0 +1,97 @@
+package brave.context.jfr;
+
+import brave.propagation.CurrentTraceContext;
+import brave.propagation.CurrentTraceContext.Scope;
+import brave.propagation.StrictScopeDecorator;
+import brave.propagation.ThreadLocalCurrentTraceContext;
+import brave.propagation.TraceContext;
+import java.nio.file.Path;
+import java.util.List;
+import java.util.concurrent.CountDownLatch;
+import java.util.concurrent.Executor;
+import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
+import java.util.concurrent.TimeUnit;
+import jdk.jfr.Recording;
+import jdk.jfr.consumer.RecordedEvent;
+import jdk.jfr.consumer.RecordingFile;
+import org.junit.After;
+import org.junit.Rule;
+import org.junit.Test;
+import org.junit.rules.TemporaryFolder;
+
+import static org.assertj.core.api.Assertions.assertThat;
+import static org.assertj.core.api.Assertions.tuple;
+
+public class JfrScopeDecoratorTest {
+  @Rule public TemporaryFolder folder = new TemporaryFolder();
+
+  ExecutorService wrappedExecutor = Executors.newSingleThreadExecutor();
+  CurrentTraceContext currentTraceContext = ThreadLocalCurrentTraceContext.newBuilder()
+      .addScopeDecorator(StrictScopeDecorator.create())
+      .addScopeDecorator(JfrScopeDecorator.create())
+      .build();
+
+  Executor executor = currentTraceContext.executor(wrappedExecutor);
+  TraceContext context = TraceContext.newBuilder().traceId(1).spanId(1).build();
+  TraceContext context2 = TraceContext.newBuilder().traceId(1).parentId(1).spanId(2).build();
+  TraceContext context3 = TraceContext.newBuilder().traceId(2).spanId(3).build();
+
+  @After public void shutdownExecutor() throws InterruptedException {
+    wrappedExecutor.shutdown();
+    wrappedExecutor.awaitTermination(1, TimeUnit.SECONDS);
+  }
+
+  @Test public void endToEndTest() throws Exception {
+    Path destination = folder.newFile("execute.jfr").toPath();
+
+    try (Recording recording = new Recording()) {
+      recording.start();
+
+      makeFiveScopes();
+
+      recording.dump(destination);
+    }
+
+    List<RecordedEvent> events = RecordingFile.readAllEvents(destination);
+    assertThat(events).extracting(e ->
+        tuple(e.getString("traceId"), e.getString("parentId"), e.getString("spanId")))
+        .containsExactlyInAnyOrder(
+            tuple("0000000000000001", null, "0000000000000001"),
+            tuple("0000000000000001", null, "0000000000000001"),
+            tuple(null, null, null),
+            tuple("0000000000000001", "0000000000000001", "0000000000000002"),
+            tuple("0000000000000002", null, "0000000000000003")
+        );
+  }
+
+  /**
+   * This makes five scopes:
+   *
+   * <pre><ol>
+   *   <li>Explicit scope 1</li>
+   *   <li>Implicit scope 1 with a scoping executor</li>
+   *   <li>Explicit scope 2 inside an executor thread</li>
+   *   <li>Explicit clearing scope inside an executor thread</li>
+   *   <li>Explicit scope 3 outside the executor thread</li>
+   * </ol></pre>
+   */
+  void makeFiveScopes() throws InterruptedException {
+    CountDownLatch latch = new CountDownLatch(1);
+
+    try (Scope ws = currentTraceContext.newScope(context)) {
+      executor.execute(() -> {
+        try (Scope clear = currentTraceContext.newScope(null)) {
+        }
+        try (Scope child = currentTraceContext.newScope(context2)) {
+          latch.countDown();
+        }
+      });
+    }
+
+    try (Scope ws = currentTraceContext.newScope(context3)) {
+      latch.countDown();
+      shutdownExecutor();
+    }
+  }
+}

context/jfr/src/test/resources/log4j2.properties

@@ -0,0 +1,8 @@
+appenders = console
+appender.console.type = Console
+appender.console.name = STDOUT
+appender.console.layout.type = PatternLayout
+appender.console.layout.pattern = %d{ABSOLUTE} %-5p [%t] %C{2} (%F:%L) [%X{traceId}/%X{spanId}] - %m%n
+rootLogger.level = info
+rootLogger.appenderRefs = stdout
+rootLogger.appenderRef.stdout.ref = STDOUT

context/pom.xml

@@ -17,6 +17,7 @@
   </properties>
 
   <modules>
+    <module>jfr</module>
     <module>slf4j</module>
     <module>log4j12</module>
     <module>log4j2</module>

pom.xml

@@ -451,6 +451,11 @@
             </execution>
           </executions>
         </plugin>
+        <plugin>
+          <groupId>org.codehaus.mojo</groupId>
+          <artifactId>animal-sniffer-maven-plugin</artifactId>
+          <version>1.17</version>
+        </plugin>
       </plugins>
     </pluginManagement>
     <resources>
@@ -507,7 +512,6 @@
       <plugin>
         <groupId>org.codehaus.mojo</groupId>
         <artifactId>animal-sniffer-maven-plugin</artifactId>
-        <version>1.17</version>
         <configuration>
           <signature>
             <groupId>org.codehaus.mojo.signature</groupId>