Various tracing fixes by mosche · Pull Request #137908 · elastic/elasticsearch

mosche · 2025-11-11T14:39:50Z

This PR fixes various issues causing an excessive volume of APM events and incorrectly reported transaction & span durations as described in further detail:

Only continue tracing in TaskManager if a parent APM trace context exists. Trace headers might
be set by external transactions as well. If present, it caused APMTracer to report a transaction
for every span when in fact being sampled out.
Correctly report the duration of transactions if not recording by not discarding the root span
immediately. These transactions might still get reported, but without spans.
Discard transient trace start time in newTraceContext when a parent APM trace context
already exists. If propagated, all spans would start at the same time.

Relates to ES-13389

Only continue tracing in TaskManager if a parent APM trace context exists. Trace headers might be set by external transactions as well. If present, it caused APMTracer to report a transaction for every span when in fact being sampled out. Correctly report the duration of transactions if not recording by not discarding the root span immediately. These transactions might still get reported, but without spans. Discard transient trace start time in `newTraceContext` when a parent APM trace context already exists. If propagated, all spans would start at the same time. Relates to ES-13389

elasticsearchmachine · 2025-11-11T14:40:17Z

Pinging @elastic/es-core-infra (Team:Core/Infra)

mosche · 2025-11-13T16:58:19Z

Correctly report the duration of transactions if not recording by not discarding the root span
immediately. These transactions might still get reported, but without spans.

Turns out this might be unnecessary (for serverless at least), the APM agent behavior depends on the apm-server version. For recent apm-server versions such transactions are not reported of unsampled.

jdconrad

LGTM! Just a couple of questions.

modules/apm/src/test/java/org/elasticsearch/telemetry/apm/internal/tracing/APMTracerTests.java

jdconrad · 2025-11-13T20:11:03Z

server/src/main/java/org/elasticsearch/common/util/concurrent/ThreadContext.java

            final Object previousTraceContext = newTransientHeaders.remove(Task.APM_TRACE_CONTEXT);
            if (previousTraceContext != null) {
                newTransientHeaders.put(Task.PARENT_APM_TRACE_CONTEXT, previousTraceContext);
+                // Remove the trace start time override for a previous context if such a context already exists.


Naive question - it's guaranteed there will never be overlap in this case? (If we remove we are sure the prior trace is completed?)

TRACE_START_TIME is a rather unfortunate hack. It should only be used for the root span (and previously it wasn't possible to set this again, but it could be set to late). Overlapping shouldn't ever be an issue. But I'll add an assert to make sure this is never set after a trace context already exists catching the too late case.

modules/apm/src/test/java/org/elasticsearch/telemetry/apm/internal/tracing/APMTracerTests.java

…rnal/tracing/APMTracerTests.java

mosche · 2025-11-14T09:27:20Z

server/src/main/java/org/elasticsearch/common/util/concurrent/ThreadContext.java

+            assert key != Task.TRACE_START_TIME || (hasApmTraceContext() || hasParentApmTraceContext()) == false
+                : "trace.starttime cannot be set after a trace context is present";
+


@jdconrad this will prevent wrong usage of trace.starttime

- Only continue tracing in TaskManager if a parent APM trace context exists. Trace headers might be set by external transactions as well. If present, it caused APMTracer to report a transaction for every span when in fact being sampled out. - Correctly report the duration of transactions if not recording by not discarding the root span immediately. These transactions might still get reported, but without spans. - Discard transient trace start time in `newTraceContext` when a parent APM trace context already exists. If propagated, all spans would start at the same time. Relates to ES-13389

elasticsearchmachine · 2025-11-14T16:03:15Z

💔 Backport failed

Status	Branch	Result
✅	9.2
❌	8.19	Commit could not be cherrypicked due to conflicts
❌	9.1	Commit could not be cherrypicked due to conflicts

You can use sqren/backport to manually backport by running backport --upstream elastic/elasticsearch --pr 137908

- Only continue tracing in TaskManager if a parent APM trace context exists. Trace headers might be set by external transactions as well. If present, it caused APMTracer to report a transaction for every span when in fact being sampled out. - Correctly report the duration of transactions if not recording by not discarding the root span immediately. These transactions might still get reported, but without spans. - Discard transient trace start time in `newTraceContext` when a parent APM trace context already exists. If propagated, all spans would start at the same time. Relates to ES-13389

* main: (135 commits) Mute org.elasticsearch.upgrades.IndexSortUpgradeIT testIndexSortForNumericTypes {upgradedNodes=1} elastic#138130 Mute org.elasticsearch.upgrades.IndexSortUpgradeIT testIndexSortForNumericTypes {upgradedNodes=2} elastic#138129 Mute org.elasticsearch.search.basic.SearchWithRandomDisconnectsIT testSearchWithRandomDisconnects elastic#138128 [DiskBBQ] avoid EsAcceptDocs bug by calling cost before building iterator (elastic#138127) Log NOT_PREFERRED shard movements (elastic#138069) Improve bulk loading of binary doc values (elastic#137995) Add internal action for getting inference fields and inference results for those fields (elastic#137680) Address issue with DateFieldMapper#isFieldWithinQuery(...) (elastic#138032) WriteLoadConstraintDecider: Have separate rate limiting for canRemain and canAllocate decisions (elastic#138067) Adding NodeContext to TransportBroadcastByNodeAction (elastic#138057) Mute org.elasticsearch.simdvec.ESVectorUtilTests testSoarDistanceBulk elastic#138117 Mute org.elasticsearch.xpack.esql.qa.single_node.GenerativeIT test elastic#137909 Backport batched_response_might_include_reduction_failure version to 8.19 (elastic#138046) Add summary metrics for tdigest fields (elastic#137982) Add gp-llm-v2 model ID and inference endpoint (elastic#138045) Various tracing fixes (elastic#137908) [ML] Fixing KDE evaluate() to return correct ValueAndMagnitude object (elastic#128602) Mute org.elasticsearch.xpack.shutdown.NodeShutdownIT testStalledShardMigrationProperlyDetected elastic#115697 [ML] Fix Flaky Audit Message Assertion in testWithDatastream for RegressionIT and ClassificationIT (elastic#138065) [ML] Fix Non-Deterministic Training Set Selection in RegressionIT testTwoJobsWithSameRandomizeSeedUseSameTrainingSet (elastic#138063) ... # Conflicts: # rest-api-spec/src/yamlRestTest/resources/rest-api-spec/test/search.vectors/200_dense_vector_docvalue_fields.yml

ankit--sethi · 2025-11-20T00:29:12Z

server/src/main/java/org/elasticsearch/common/util/concurrent/ThreadContext.java

            final Object previousTraceContext = newTransientHeaders.remove(Task.APM_TRACE_CONTEXT);
            if (previousTraceContext != null) {
                newTransientHeaders.put(Task.PARENT_APM_TRACE_CONTEXT, previousTraceContext);
+                // Remove the trace start time override for a previous context if such a context already exists.


I had seen this behavior as well, but I wasn't super sure if I my understanding was correct. Glad to see this here!

mosche added 5 commits November 11, 2025 15:03

Don't expose scope if context is not recording

ed8387d

remove extra logging

beeebd3

fixes

77c5d80

fixes

998daba

mosche requested a review from a team as a code owner November 11, 2025 14:39

mosche added >refactoring auto-backport Automatically create backport pull requests when merged :Core/Infra/Metrics Metrics and metering infrastructure branch:9.2 branch:9.1 branch:8.19 labels Nov 11, 2025

elasticsearchmachine added Team:Core/Infra Meta label for core/infra team v9.3.0 v9.2.2 v8.19.8 v9.1.8 labels Nov 11, 2025

elasticsearchmachine removed branch:9.2 branch:9.1 branch:8.19 labels Nov 11, 2025

mosche requested a review from ankit--sethi November 11, 2025 14:40

mosche added 2 commits November 12, 2025 09:13

Merge branch 'main' into metrics/fix_tracing

40704d1

test fixes

af5a7fb

elasticsearchmachine added the serverless-linked Added by automation, don't add manually label Nov 12, 2025

mosche added 2 commits November 13, 2025 08:33

Merge branch 'main' into metrics/fix_tracing

3534468

Merge branch 'main' into metrics/fix_tracing

2be6639

mosche requested a review from jdconrad November 13, 2025 16:54

jdconrad approved these changes Nov 13, 2025

View reviewed changes

mosche commented Nov 14, 2025

View reviewed changes

modules/apm/src/test/java/org/elasticsearch/telemetry/apm/internal/tracing/APMTracerTests.java Outdated Show resolved Hide resolved

mosche and others added 2 commits November 14, 2025 09:55

Update modules/apm/src/test/java/org/elasticsearch/telemetry/apm/inte…

041e31f

…rnal/tracing/APMTracerTests.java

prevent invalid usage of trace.starttime

7b523bf

mosche commented Nov 14, 2025

View reviewed changes

mosche added 4 commits November 14, 2025 10:28

Merge branch 'main' into metrics/fix_tracing

344e591

fix style

a9d4323

Merge branch 'main' into metrics/fix_tracing

739855c

Merge branch 'main' into metrics/fix_tracing

f23b503

mosche merged commit 928e584 into elastic:main Nov 14, 2025
34 checks passed

mosche mentioned this pull request Nov 14, 2025

[9.2] Various tracing fixes (#137908) #138109

Merged

elasticsearchmachine added the backport pending label Nov 14, 2025

ankit--sethi reviewed Nov 20, 2025

View reviewed changes

This was referenced Nov 24, 2025

[CLEAN] Synthetic Benchmark PR #137908 - Various tracing fixes qodo-benchmark/elasticsearch#9

Open

[CORRUPTED] Synthetic Benchmark PR #137908 - Various tracing fixes qodo-benchmark/elasticsearch#10

Open

mosche removed backport pending v8.19.8 v9.1.8 labels Nov 25, 2025

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Various tracing fixes#137908

Various tracing fixes#137908
mosche merged 15 commits intoelastic:mainfrom
mosche:metrics/fix_tracing

mosche commented Nov 11, 2025

Uh oh!

elasticsearchmachine commented Nov 11, 2025

Uh oh!

mosche commented Nov 13, 2025

Uh oh!

jdconrad left a comment

Uh oh!

Uh oh!

jdconrad Nov 13, 2025

Uh oh!

mosche Nov 14, 2025

Uh oh!

Uh oh!

mosche Nov 14, 2025

Uh oh!

Uh oh!

elasticsearchmachine commented Nov 14, 2025

Uh oh!

ankit--sethi Nov 20, 2025

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

		assert key != Task.TRACE_START_TIME \|\| (hasApmTraceContext() \|\| hasParentApmTraceContext()) == false
		: "trace.starttime cannot be set after a trace context is present";

Conversation

mosche commented Nov 11, 2025

Uh oh!

elasticsearchmachine commented Nov 11, 2025

Uh oh!

mosche commented Nov 13, 2025

Uh oh!

jdconrad left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

jdconrad Nov 13, 2025

Choose a reason for hiding this comment

Uh oh!

mosche Nov 14, 2025

Choose a reason for hiding this comment

Uh oh!

Uh oh!

mosche Nov 14, 2025

Choose a reason for hiding this comment

Uh oh!

Uh oh!

elasticsearchmachine commented Nov 14, 2025

💔 Backport failed

Uh oh!

ankit--sethi Nov 20, 2025

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants