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

fix span stacktrace capture #3474

Merged
merged 5 commits into from Jan 8, 2024
Merged
Show file tree
Hide file tree
Changes from 4 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
4 changes: 4 additions & 0 deletions CHANGELOG.asciidoc
Expand Up @@ -31,6 +31,10 @@ Use subheadings with the "=====" level for adding notes for unreleased changes:

=== Unreleased

[float]
===== Bug fixes
* Fix span stack trace when combined with span compression - {pull}3474[#3474]

[[release-notes-1.x]]
=== Java Agent version 1.x

Expand Down
Expand Up @@ -107,7 +107,6 @@ public class ElasticApmTracer implements Tracer {
private static volatile boolean classloaderCheckOk = false;

private final ConfigurationRegistry configurationRegistry;
private final StacktraceConfiguration stacktraceConfiguration;
private final ApmServerClient apmServerClient;
private final List<LifecycleListener> lifecycleListeners = new CopyOnWriteArrayList<>();
private final ObjectPool<Transaction> transactionPool;
Expand Down Expand Up @@ -203,7 +202,6 @@ private static void checkClassloader() {
this.metricRegistry = metricRegistry;
this.configurationRegistry = configurationRegistry;
this.reporter = reporter;
this.stacktraceConfiguration = configurationRegistry.getConfig(StacktraceConfiguration.class);
this.apmServerClient = apmServerClient;
this.ephemeralId = ephemeralId;
this.metaDataFuture = metaDataFuture;
Expand Down Expand Up @@ -574,12 +572,6 @@ private void reportSpan(Span span) {
// makes sure that parents are also non-discardable
span.setNonDiscardable();

long spanStackTraceMinDurationMs = stacktraceConfiguration.getSpanStackTraceMinDurationMs();
if (spanStackTraceMinDurationMs >= 0 && span.isSampled() && span.getStackFrames() == null) {
if (span.getDurationMs() >= spanStackTraceMinDurationMs) {
span.withStacktrace(new Throwable());
}
}
reporter.report(span);
}

Expand Down
Expand Up @@ -26,6 +26,7 @@
import co.elastic.apm.agent.impl.context.ServiceTarget;
import co.elastic.apm.agent.impl.context.SpanContext;
import co.elastic.apm.agent.impl.context.Url;
import co.elastic.apm.agent.impl.stacktrace.StacktraceConfiguration;
import co.elastic.apm.agent.tracer.util.ResultUtil;
import co.elastic.apm.agent.sdk.logging.Logger;
import co.elastic.apm.agent.sdk.logging.LoggerFactory;
Expand All @@ -43,6 +44,7 @@ public class Span extends AbstractSpan<Span> implements Recyclable, co.elastic.a
private static final Logger logger = LoggerFactory.getLogger(Span.class);
public static final long MAX_LOG_INTERVAL_MICRO_SECS = TimeUnit.MINUTES.toMicros(5);
private static long lastSpanMaxWarningTimestamp;
private final StacktraceConfiguration stacktraceConfiguration;

/**
* A subtype describing this span (eg 'mysql', 'elasticsearch', 'jsf' etc)
Expand Down Expand Up @@ -86,6 +88,7 @@ public void setNonDiscardable() {

public Span(ElasticApmTracer tracer) {
super(tracer);
this.stacktraceConfiguration = tracer.getConfig(StacktraceConfiguration.class);
}

public <T> Span start(TraceContext.ChildContextCreator<T> childContextCreator, T parentContext, Baggage parentBaggage, long epochMicros) {
Expand Down Expand Up @@ -263,6 +266,14 @@ public void beforeEnd(long epochMicros) {

@Override
protected void afterEnd() {
// capture stack trace when the span ends, relies on this method being called synchronously from the instrumentation
long spanStackTraceMinDurationMs = stacktraceConfiguration.getSpanStackTraceMinDurationMs();
if (spanStackTraceMinDurationMs >= 0 && isSampled() && stackFrames == null) {
if (getDurationMs() >= spanStackTraceMinDurationMs) {
this.stacktrace = new Throwable();
}
}

// Why do we increment references of this span here?
// The only thing preventing the "this"-span from being recycled is the initial reference increment in onAfterStart()
// There are multiple ways in afterEnd() on how this reference may be decremented and therefore potentially causing recycling:
Expand Down
Expand Up @@ -48,6 +48,7 @@
import javax.annotation.Nullable;
import java.io.IOException;
import java.util.HashMap;
import java.util.Arrays;
import java.util.List;
import java.util.Map;
import java.util.Objects;
Expand Down Expand Up @@ -159,11 +160,20 @@ void testEnableStacktraces() throws InterruptedException {
Span span = tracerImpl.getActive().createSpan();
try (Scope spanScope = span.activateInScope()) {
Thread.sleep(10);
span.end();
stackTraceEndSpan(span);
}
transaction.end();
}
assertThat(reporter.getFirstSpan().getStacktrace()).isNotNull();
Throwable stackTrace = reporter.getFirstSpan().getStacktrace();
assertThat(stackTrace).isNotNull();
assertThat(Arrays.stream(stackTrace.getStackTrace()).filter(stackTraceElement ->
stackTraceElement.getMethodName().equals("stackTraceEndSpan")
&& stackTraceElement.getClassName().equals(ElasticApmTracerTest.class.getName()))).hasSize(1);
}
Comment on lines +169 to +172
Copy link
Member Author

Choose a reason for hiding this comment

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

[for reviewer] this test does not actually check that the bugfix is effective, but just improves a bit the heuristic because until now there was none.


private static void stackTraceEndSpan(Span span) {
// dummy method used just to verify that the captured stack trace contains it
span.end();
}

@Test
Expand Down