Skip to content

Gate OpenTelemetry attribute building on the sampling decision - #2

Closed
nhachicha wants to merge 1 commit into
mainfrom
nh/otel-gate-attributes-on-sampling
Closed

nhachicha wants to merge 1 commit into
mainfrom
nh/otel-gate-attributes-on-sampling

Conversation

@nhachicha

Copy link
Copy Markdown
Owner

Reduces the Java driver's OpenTelemetry tracing overhead, following the Implementation Guidelines in mongodb/specifications#1986 (DRIVERS-3620). Draft on the fork for review before an upstream PR and Jira ticket.

Why

Benchmarking on the spec's method showed Java paying almost the same cost with a 1% sampler as with every span recorded. A JFR profile under sdk-ratio put 34% of CPU samples on tracing frames, in this order:

  1. Building the tag set on span stop. Micrometer calls DefaultMongodbObservationConvention for all low- and high-cardinality key values unconditionally in Observation.stop(), and the convention chained KeyValues.and(), which merges and re-sorts per call. This ran on every command whether or not the sampler kept the span.
  2. TracingManager.createTracingSpan decoded the just-encoded BSON command into a ByteBufBsonDocument only to read its first key.
  3. Scope thread-local handling inside the OTel bridge (not touched).

What changes

  • MongodbObservationContext: new recording flag (default true).
  • MicrometerTracer: after observation.start(), asks TracingSpanRecordingProbe whether the SDK is recording the span; clears the flag if not.
  • TracingSpanRecordingProbe (new, internal): driver-core depends only on micrometer-observation, so the micrometer-tracing span type is resolved reflectively once via method handles (TracingObservationHandler.TracingContext.getSpan(), Span.isNoop()). Micrometer's tracing handler stores the span in the context under that class key during onStart, inside start(); the OTel bridge's isNoop() is !isRecording(). When micrometer-tracing is absent or no span is attached, every span is treated as recording (previous behaviour).
  • DefaultMongodbObservationConvention: high-cardinality key values are skipped for a non-recording span; all three builders fill one KeyValue[] and call KeyValues.of once. Low-cardinality values are still produced for non-recording spans because metrics handlers on the same registry consume them.
  • CommandMessage.getCommandName(); TracingManager uses it and decodes the command only for getMore (cursor id).

No public API change beyond two accessors on MongodbObservationContext. Tag names and values are unchanged.

Verification

  • New DefaultMongodbObservationConventionTest (6) and a CommandMessageTest case: pass.
  • MicrometerProseTest sync and reactive: pass.
  • Unified MicrometerTracingTest sync and reactive at the pinned spec revision: pass except the two tests needing configureFailPoint, which the local server lacked.
  • Span counts unchanged in verify mode (2/op sdk-always, 0.02/op sdk-ratio).

Measured effect (same host and harness, 5 reps, medians; loss vs off / added CPU µs per op excl. GC)

API Task Config Before After
sync Small doc insertOne api-only +4.2% / +1.6 +1.0% / +0.2
sync Small doc insertOne sdk-ratio +9.6% / +4.5 +6.2% / +2.2
sync Small doc insertOne sdk-always +10.8% / +5.3 +7.9% / +3.0
sync Find one by ID api-only +5.4% / +2.2 +0.9% / +0.2
sync Find one by ID sdk-ratio +12.2% / +5.6 +5.3% / +2.3
sync Find one by ID sdk-always +13.3% / +6.7 +7.1% / +3.2
async Small doc insertOne api-only +3.1% / +1.7 +0.6% / +0.4
async Small doc insertOne sdk-ratio +5.5% / +4.3 +1.4% / +1.1
async Small doc insertOne sdk-always +6.3% / +5.5 +2.6% / +1.4
async Find one by ID api-only +2.6% / +0.7 −0.2% / +0.0
async Find one by ID sdk-ratio +6.3% / +4.5 +2.3% / +1.7
async Find one by ID sdk-always +7.5% / +5.5 +5.0% / +3.0

Added CPU per op roughly halved in every configuration; api-only is within 1% of off on all four tasks. The sdk-ratio/sdk-always gap stays small because the remaining cost is span creation and scope handling in the SDK, which is relevant to the spec PR's gating diagnostic.

Harness: companion draft "DRIVERS-3620: OpenTelemetry overhead benchmark suite" on this fork.

Review notes

  • The reflective probe is the part I would most like eyes on. The alternative is an optionalImplementation on micrometer-tracing, which is heavier for one boolean.
  • Needs a JAVA ticket before going upstream.

Benchmarking against the OpenTelemetry spec's "Performance Implications"
section (DRIVERS-3620) showed that the Java driver paid almost the same
cost under a 1% sampler as with every span recorded. A CPU profile placed
the cost in three places: building the tag set on span stop (chained
KeyValues.and() merges, run on every command regardless of sampling),
decoding the just-encoded BSON command to read its name, and scope
handling inside the Micrometer/OpenTelemetry bridge.

This change addresses the first two:

- MongodbObservationContext gains a `recording` flag. After the
  observation starts, MicrometerTracer asks TracingSpanRecordingProbe
  whether the tracing SDK is recording the span and clears the flag if
  not. The probe resolves the micrometer-tracing span type reflectively,
  since driver-core depends only on micrometer-observation; when that
  module is absent every span is treated as recording, as before.
- DefaultMongodbObservationConvention returns no high-cardinality key
  values for a non-recording span, and builds all key-value sets from a
  single array instead of repeated KeyValues.and() merges. Low-cardinality
  values are still produced for non-recording spans because metrics
  handlers on the same registry consume them.
- CommandMessage exposes getCommandName(); TracingManager uses it and
  decodes the command only for getMore, to read the cursor id.

Measured on the spec's benchmark (5 interleaved repetitions, medians):
added CPU per operation roughly halved in every configuration, and the
api-only cost is within 1% of tracing off on all four tasks.
Span counts and tag contents are unchanged.
@nhachicha

Copy link
Copy Markdown
Owner Author

Superseded: reopened against mongodb/mongo-java-driver main.

@nhachicha nhachicha closed this Oct 15, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant