Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[maven-extension] Propagate OTel context to plugin mojos #786

Merged
66 changes: 65 additions & 1 deletion maven-extension/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -36,7 +36,7 @@ Add the Maven OpenTelemetry Extension in the `pom.xml` file:
<extension>
<groupId>io.opentelemetry.contrib</groupId>
<artifactId>opentelemetry-maven-extension</artifactId>
<version>1.10.0-alpha</version>
<version>1.23.0-alpha</version>
</extension>
</extensions>
</build>
Expand Down Expand Up @@ -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
<project>
...
<dependencies>
<dependency>
<groupId>io.opentelemetry</groupId>
<artifactId>opentelemetry-api</artifactId>
<version>LATEST</version>
</dependency>
...
</dependencies>
</project>
````

* 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
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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<Scope> MOJO_EXECUTION_SCOPE = new ThreadLocal<>();
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does this cause any issue with parallel Maven builds with -T?

Copy link
Member Author

@cyrille-leclerc cyrille-leclerc Mar 14, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, using a threadlocal from ExecutionListener#mojoStarted() to ExecutionListener#mojoSucceeded() / ExecutionListener#mojoFailed() works even when parallelising the Maven builds with -T.
The code contains state checks to ensure this assumption continues to be valid with newer versions of Maven parallelization.

I tested with 8 cores and -T 1C on a Macbok Air m2 2022 building https://github.com/apache/maven. I could confirm looking at the debug logs that the build was massively parallelised and that the threadlocal worked as desired.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I just added a comment in the code to explain the rationale.


@SuppressWarnings("NullAway") // Automatically initialized by DI
@Requirement
private SpanRegistry spanRegistry;
Expand All @@ -53,7 +64,7 @@ public final class OtelExecutionListener extends AbstractExecutionListener {
@Requirement
private OpenTelemetrySdkService openTelemetrySdkService;

private Map<MavenGoal, MojoGoalExecutionHandler> mojoGoalExecutionHandlers = new HashMap<>();
private final Map<MavenGoal, MojoGoalExecutionHandler> mojoGoalExecutionHandlers;

public OtelExecutionListener() {
this.mojoGoalExecutionHandlers =
Expand All @@ -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));
mateuszrzeszutek marked this conversation as resolved.
Show resolved Hide resolved
Class<? extends ContextStorage> 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#"));
}
}

Expand Down Expand Up @@ -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
Expand All @@ -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
Expand All @@ -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
Expand Down
14 changes: 14 additions & 0 deletions maven-extension/src/main/resources/META-INF/maven/extension.xml
Original file line number Diff line number Diff line change
@@ -0,0 +1,14 @@
<extension>
<exportedPackages>
<!-- opentelemetry.api.* -->
<exportedPackage>io.opentelemetry.api</exportedPackage>
<exportedPackage>io.opentelemetry.api.*</exportedPackage>
<exportedPackage>io.opentelemetry.api.baggage</exportedPackage>
<exportedPackage>io.opentelemetry.api.baggage.propagation</exportedPackage>
<exportedPackage>io.opentelemetry.api.common</exportedPackage>
<exportedPackage>io.opentelemetry.api.internal</exportedPackage>
<exportedPackage>io.opentelemetry.api.metrics</exportedPackage>
<exportedPackage>io.opentelemetry.api.trace</exportedPackage>
<exportedPackage>io.opentelemetry.context</exportedPackage>
</exportedPackages>
</extension>