From 00a3928181581e3c98d394f3c7c34c40ed2a5fc0 Mon Sep 17 00:00:00 2001 From: Cyrille Le Clerc Date: Wed, 29 Mar 2023 15:20:34 +0200 Subject: [PATCH] [maven-extension] Propagate OTel context to plugin mojos (#786) **Description:** Propagate OTel context to plugin mojos so they can add their own attributes and spans to traces. **Existing Issue(s):** None **Testing:** No unit test framework compatible with JUnit 5 for Maven builds yet. **Documentation:** See updated README.md **Outstanding items:** None --- maven-extension/README.md | 66 ++++++++++++- .../maven/OtelExecutionListener.java | 99 ++++++++++++++++++- .../resources/META-INF/maven/extension.xml | 14 +++ 3 files changed, 175 insertions(+), 4 deletions(-) create mode 100644 maven-extension/src/main/resources/META-INF/maven/extension.xml diff --git a/maven-extension/README.md b/maven-extension/README.md index 06ed60d71..bcbf3d057 100644 --- a/maven-extension/README.md +++ b/maven-extension/README.md @@ -36,7 +36,7 @@ Add the Maven OpenTelemetry Extension in the `pom.xml` file: io.opentelemetry.contrib opentelemetry-maven-extension - 1.10.0-alpha + 1.23.0-alpha @@ -175,6 +175,70 @@ The [Jenkins OpenTelemetry Plugin](https://plugins.jenkins.io/opentelemetry/) ex The [`otel-cli`](https://github.com/equinix-labs/otel-cli) is a command line wrapper to observe the execution of a shell command as an OpenTelemetry trace. +## Instrumenting Maven Mojos for better visibility in Maven builds + +Maven plugin authors can instrument Mojos for better visibility in Maven builds. + +Common instrumentation patterns include: + +* Adding contextual data as attributes on the spans created by the OpenTelemetry Maven Extension, +* Creating additional sub spans to breakdown long mojo goal executions in finer grained steps + +Note that the instrumentation of a plugin is enabled when the OpenTelemetry Maven extension is added to the build and activated. +Otherwise, the instrumentation of the Maven plugin is noop. + +It is recommended to enrich spans using the [OpenTelemetry Semantic Conventions](https://opentelemetry.io/docs/concepts/semantic-conventions/) +to improve the visualization and analysis in Observability products. +The [HTTP](https://opentelemetry.io/docs/reference/specification/trace/semantic_conventions/http/) +and [database client calls](https://opentelemetry.io/docs/reference/specification/trace/semantic_conventions/database/) +conventions are particularly useful when invoking external systems. + +Steps to instrument a Maven Mojo: + +* Add the OpenTelemetry API dependency in the `pom.xml` of the Maven plugin. + +```xml + + ... + + + io.opentelemetry + opentelemetry-api + LATEST + + ... + + +```` + +* Instrument the Mojo: + +```java +@Mojo(name = "test", defaultPhase = LifecyclePhase.PROCESS_SOURCES) +public class TestMojo extends AbstractMojo { + + @Override + public void execute() { + Span mojoExecuteSpan = Span.current(); + + // ENRICH THE DEFAULT SPAN OF THE MOJO EXECUTION + // (this span is created by the opentelemetry-maven-extension) + mojoExecuteSpan.setAttribute("an-attribute", "a-value"); + + // ... some logic + + // CREATE SUB SPANS TO CAPTURE FINE GRAINED DETAILS OF THE MOJO EXECUTION + Tracer tracer = GlobalOpenTelemetry.get().getTracer("com.example.maven.otel_aware_plugin"); + Span childSpan = tracer.spanBuilder("otel-aware-goal-sub-span").setAttribute("another-attribute", "another-value").startSpan(); + try (Scope ignored2 = childSpan.makeCurrent()) { + // ... mojo sub operation + } finally { + childSpan.end(); + } + } +} +``` + ## Component owners - [Cyrille Le Clerc](https://github.com/cyrille-leclerc), Elastic diff --git a/maven-extension/src/main/java/io/opentelemetry/maven/OtelExecutionListener.java b/maven-extension/src/main/java/io/opentelemetry/maven/OtelExecutionListener.java index 6fac0a665..4eb9eab0b 100644 --- a/maven-extension/src/main/java/io/opentelemetry/maven/OtelExecutionListener.java +++ b/maven-extension/src/main/java/io/opentelemetry/maven/OtelExecutionListener.java @@ -11,13 +11,15 @@ import io.opentelemetry.api.trace.StatusCode; import io.opentelemetry.api.trace.Tracer; import io.opentelemetry.context.Context; +import io.opentelemetry.context.ContextStorage; +import io.opentelemetry.context.Scope; import io.opentelemetry.context.propagation.TextMapGetter; import io.opentelemetry.maven.handler.MojoGoalExecutionHandler; import io.opentelemetry.maven.handler.MojoGoalExecutionHandlerConfiguration; import io.opentelemetry.maven.semconv.MavenOtelSemanticAttributes; -import java.util.HashMap; import java.util.Locale; import java.util.Map; +import java.util.Optional; import java.util.stream.Collectors; import javax.annotation.Nullable; import org.apache.maven.execution.AbstractExecutionListener; @@ -45,6 +47,15 @@ public final class OtelExecutionListener extends AbstractExecutionListener { private static final Logger logger = LoggerFactory.getLogger(OtelExecutionListener.class); + /** + * Note that using a thread local around the mojo goal execution to carry the {@link Scope } works + * even when using Maven build parallelization. {@link Span#current()} invoked in {@link + * org.apache.maven.plugin.Mojo#execute()} returns as expected the span set in {@link + * ExecutionListener#mojoStarted(ExecutionEvent)} using {@link Span#makeCurrent()}. For this + * reason, we can carry over the {@link Scope} in a thread local variable. + */ + private static final ThreadLocal MOJO_EXECUTION_SCOPE = new ThreadLocal<>(); + @SuppressWarnings("NullAway") // Automatically initialized by DI @Requirement private SpanRegistry spanRegistry; @@ -53,7 +64,7 @@ public final class OtelExecutionListener extends AbstractExecutionListener { @Requirement private OpenTelemetrySdkService openTelemetrySdkService; - private Map mojoGoalExecutionHandlers = new HashMap<>(); + private final Map mojoGoalExecutionHandlers; public OtelExecutionListener() { this.mojoGoalExecutionHandlers = @@ -66,6 +77,28 @@ public OtelExecutionListener() { + mojoGoalExecutionHandlers.entrySet().stream() .map(entry -> entry.getKey().toString() + ": " + entry.getValue().toString()) .collect(Collectors.joining(", "))); + + // help debugging class loader issues when the OTel APIs used in + // Maven plugin mojos are mistakenly not loaded by the OTel Maven extension + // causing the lack of context propagation from the OTel Maven extension to the plugin mojos + ContextStorage contextStorage = ContextStorage.get(); + logger.debug( + "ContextStorage: " + + contextStorage + + ", identity=" + + System.identityHashCode(contextStorage)); + Class contextStorageClass = contextStorage.getClass(); + logger.debug( + "ContextStorageClass=" + + contextStorageClass.getName() + + ", identity=" + + System.identityHashCode(contextStorageClass) + + " classloader=" + + contextStorageClass.getClassLoader() + + " codeLocation=" + + Optional.of(contextStorageClass.getProtectionDomain().getCodeSource()) + .map(source -> source.getLocation().toString()) + .orElse("#unknown#")); } } @@ -232,7 +265,28 @@ public void mojoStarted(ExecutionEvent executionEvent) { } Span span = spanBuilder.startSpan(); + @SuppressWarnings("MustBeClosedChecker") + Scope scope = span.makeCurrent(); spanRegistry.putSpan(span, mojoExecution, executionEvent.getProject()); + Optional.ofNullable(MOJO_EXECUTION_SCOPE.get()) + .ifPresent( + previousScope -> + logger.warn( + "OpenTelemetry: Scope " + + System.identityHashCode(previousScope) + + "already attached to thread '" + + Thread.currentThread().getName() + + "'")); + MOJO_EXECUTION_SCOPE.set(scope); + if (logger.isDebugEnabled()) { + logger.debug( + "OpenTelemetry: Attach scope " + + System.identityHashCode(scope) + + " to thread '" + + Thread.currentThread().getName() + + "' for " + + mojoExecution); + } } @Override @@ -247,8 +301,27 @@ public void mojoSucceeded(ExecutionEvent executionEvent) { executionEvent.getProject()); Span mojoExecutionSpan = spanRegistry.removeSpan(mojoExecution, executionEvent.getProject()); mojoExecutionSpan.setStatus(StatusCode.OK); - mojoExecutionSpan.end(); + Scope scope = MOJO_EXECUTION_SCOPE.get(); + if (scope == null) { + logger.warn( + "OpenTelemetry: No scope found on thread '" + + Thread.currentThread().getName() + + "' for succeeded " + + mojoExecution); + } else { + scope.close(); + MOJO_EXECUTION_SCOPE.remove(); + if (logger.isDebugEnabled()) { + logger.debug( + "OpenTelemetry: Remove scope " + + System.identityHashCode(scope) + + " on thread '" + + Thread.currentThread().getName() + + "' for succeeded " + + mojoExecution); + } + } } @Override @@ -273,6 +346,26 @@ public void mojoFailed(ExecutionEvent executionEvent) { mojoExecutionSpan.recordException(exception); } mojoExecutionSpan.end(); + Scope scope = MOJO_EXECUTION_SCOPE.get(); + if (scope == null) { + logger.warn( + "OpenTelemetry: No scope found on thread '" + + Thread.currentThread().getName() + + "' for failed " + + mojoExecution); + } else { + scope.close(); + MOJO_EXECUTION_SCOPE.remove(); + if (logger.isDebugEnabled()) { + logger.debug( + "OpenTelemetry: Remove scope " + + System.identityHashCode(scope) + + " on thread '" + + Thread.currentThread().getName() + + "' for failed " + + mojoExecution); + } + } } @Override diff --git a/maven-extension/src/main/resources/META-INF/maven/extension.xml b/maven-extension/src/main/resources/META-INF/maven/extension.xml new file mode 100644 index 000000000..082c5a748 --- /dev/null +++ b/maven-extension/src/main/resources/META-INF/maven/extension.xml @@ -0,0 +1,14 @@ + + + + io.opentelemetry.api + io.opentelemetry.api.* + io.opentelemetry.api.baggage + io.opentelemetry.api.baggage.propagation + io.opentelemetry.api.common + io.opentelemetry.api.internal + io.opentelemetry.api.metrics + io.opentelemetry.api.trace + io.opentelemetry.context + +