Skip to content

PYTHON-5947 Add OpenTelemetry Operation and Transaction Span Support - #2964

Draft
blink1073 wants to merge 71 commits into
mongodb:otelfrom
blink1073:PYTHON-5947-otel-impl
Draft

PYTHON-5947 Add OpenTelemetry Operation and Transaction Span Support#2964
blink1073 wants to merge 71 commits into
mongodb:otelfrom
blink1073:PYTHON-5947-otel-impl

Conversation

@blink1073

@blink1073 blink1073 commented Jul 28, 2026

Copy link
Copy Markdown
Member

PYTHON-5947

Changes in this PR

Extends the OpenTelemetry support added in PYTHON-5945 with:

  • Operation-level spans: one span per public API call (e.g. find_one, insert_one, bulk_write), spanning all retry attempts, with each attempt's command span nested underneath. A cursor's whole lifetime is a single operation span, so getMore commands nest under the originating find/aggregate rather than producing spans of their own.
  • Transaction pseudo-spans: a "transaction" span wrapping start_transaction() through commit_transaction()/abort_transaction(), with operations inside the transaction nested under it. A retried with_transaction() produces one span covering all of its attempts.
  • Unified test format support: observeTracingMessages/expectTracingMessages, plus the vendored spec test suite from mongodb/specifications.

Spans stay conformant on failure paths too: an operation that fails before any command reaches the wire still carries db.operation.name and db.operation.summary, and killCursors/endSessions now get operation spans rather than leaving their command spans unparented.

This is opt-in: no behavior changes for users who don't enable the tracing client option or OTEL_PYTHON_INSTRUMENTATION_MONGODB_ENABLED env var.

Reviewer's guide

The diff is large but most of it isn't hand-written. Of ~8,300 added lines:

Lines Needs review?
Vendored spec fixtures (test/open_telemetry/*.json) ~4,200 No, copied from mongodb/specifications with resync-specs.sh
Generated sync mirrors (pymongo/synchronous/*, mirrored test/*) ~1,700 No, just synchro output
Spec patch (.evergreen/spec-patch/PYTHON-5979.patch) ~260 No, git diff output
Hand-written ~2,200 Yes, and ~1,100 of that is test_otel.py

Suggested reading order. The commits are already in dependency order, so git log -p works, but if you'd rather read by file:

  1. pymongo/_otel.py (~500 lines, the core): span creation/ending primitives, plus all of the spec's naming and attribute policy. Note the three-way split: command spans, operation spans (with an eager-attribute and a detached mode), and the "transaction" pseudo-span. The parent_span parameter and the deliberate choice not to read ambient context for transaction parenting are the two decisions worth scrutinising.
  2. pymongo/_telemetry.py: _OperationTelemetry, the lifecycle wrapper. This module holds no spec knowledge, so a spec change shouldn't reach it. One line here (parent_span = session._transaction.span) is the only coupling between operation and transaction spans.
  3. pymongo/asynchronous/mongo_client.py: _retry_internal gained three span modes: owned (creates and ends its own), caller-owned (makes a caller's span current, creates/ends nothing), and passthrough (creates nothing, leaves ambient in place, used only by the client bulk-write results cursor). Also the killCursors/endSessions wrappers.
  4. pymongo/cursor_shared.py + asynchronous/cursor.py + asynchronous/command_cursor.py: cursor-lifetime span ownership. _end_operation_telemetry is idempotent and called from the two choke points every close/GC/exception path funnels through; the exactly-once property across those paths is the main thing to check.
  5. pymongo/asynchronous/client_session.py: transaction spans, including the shared-span-across-with_transaction-retries mechanism and its reentrancy guard.
  6. test/asynchronous/unified_format.py: observeTracingMessages/expectTracingMessages wiring, modelled on the existing expectLogMessages handling.

Things you might reasonably ask about, already considered:

  • bson/json_util.py is touched: _truncate_documents silently dropped falsy values (0, False, "", {}, []) from truncated output. It's shared with pymongo/logger.py, so this was affecting structured command logging too, not just tracing. Has its own regression test.
  • Background monitors emit no spans, so nothing special happens on close(). A monitor issues its hello through Connection.command without passing a client, so _run_command derives no tracing options and start_command_span returns None. _CmapTelemetry, _HeartbeatTelemetry and _SdamTelemetry never touch _otel either. Checked by running 60 connect/close cycles that cancel monitors mid-heartbeat: no hello spans appear, and nothing is exported after close() returns in either driver against a three-node replica set. This is why test clients need no more than a plain close() cleanup.
  • Change streams deliberately opt out of getMore nesting: a tailing stream's operation span would never end. Comment at the call site records this.
  • Hand-written tests are scoped to what the vendored suite can't reach. The 24 vendored cases cover per-operation attributes and operation-to-command nesting for ~20 operations, one retry case, and transaction commit/abort/withTransaction, all with ignoreExtraSpans: false. Tests duplicating those were dropped. What's left is what the fixtures structurally cannot express: cursor and getMore lifetime (no fixture mentions getMore or batchSize at all), exception attributes on an operation span (fixtures only assert them on command spans), span status, killCursors/endSessions, change streams, unix sockets, config and env-var handling, and the primitives' unit tests.
  • Two vendored fixtures were wrong; fixed upstream and carried as a spec patch. operation/update.json required the update statement to contain exactly a query and an update document, which PyMongo fails because it also sends multi and upsert at their default values, a shape the CRUD spec's own tests are written to accept. Separately, the fixtures that create collections declared no initialData, so nothing cleaned up after them, and running each fixture twice per process (async plus its synchro mirror) made the second pass collide with the first. Both are fixed in DRIVERS-3597, whose fixtures this PR vendors, with the deviation recorded in .evergreen/spec-patch/PYTHON-5979.patch so a resync reapplies it until that merges. No driver behavior changed, and nothing is skipped for either reason any more. PYTHON-5979 drops the patch once DRIVERS-3597 lands.
  • Forward compatibility with trace context propagation to the server (DRIVERS-3454, specifications#1966) was checked against this PR. That change is purely additive to open-telemetry.md, so it invalidates nothing here, and it propagates the command span's context, which is the nesting this PR establishes. It also wants server spans parented to the exact retry attempt, which the shared-operation-span plus per-attempt-command-span split already gives. The one thing it will require is unrelated to this PR: run_command encodes the OP_MSG before _run_command starts the command span, and compression covers the whole section blob, so the command span will have to move ahead of encoding. That code is untouched here and belongs to a follow-on ticket against PYTHON-5945 (tracked in PYTHON-5855).

Test Plan

  • Unit tests for the span primitives (in-memory exporter, no server needed).
  • Integration tests against a live replica set covering operation spans, cursor and transaction span nesting, retry and failure paths, and sensitive-command redaction.
  • The full vendored OpenTelemetry spec test suite from mongodb/specifications.
  • Verified on Python 3.10 and 3.13, since one bug in this area reproduced only on 3.11+.
  • The fixture fixes were validated against MongoDB 6.0, which rejects a duplicate create and
    so reproduces the collision they address. MongoDB 8.2 and 9.0 accept it and cannot exercise
    that path, so they only provide regression coverage.

Checklist

Checklist for Author

  • Did you update the changelog (if necessary)?
  • Is there test coverage?
  • Is any followup work tracked in a JIRA ticket? If so, add link(s).

No follow-up work outstanding. The span-coverage gaps originally deferred from this ticket are all closed here.

PYTHON-5978 was filed for two pre-existing bugs noticed while investigating a test flake, not for deferred work from this ticket: the sync driver's Monitor.join() and Topology.cleanup_monitors() both wrap their join() calls in an asyncio.gather(...) that is never awaited, a leftover of generating the sync file from the async source, so neither actually waits. Nothing in this PR depends on either of them.

Checklist for Reviewer

  • Does the title of the PR reference a JIRA Ticket?
  • Do you fully understand the implementation? (Would you be comfortable explaining how this code works to someone else?)
  • Is all relevant documentation (README or docstring) updated?

blink1073 added 19 commits July 27, 2026 18:40
test_sensitive_command_produces_no_span previously asserted no span at
all was produced for a sensitive command, but narrowing it to only
check the (correctly suppressed) command span silently dropped that
coverage. Add a companion assertion documenting that the wrapping
operation span is not sensitivity-gated (start_operation_span has no
such check, unlike start_command_span) and still exposes the bare
command name, so the gap is tracked instead of silently uncovered.
Add integration tests for the STARTING/COMMITTED_EMPTY early-return in
commit_transaction, the STARTING early-return in abort_transaction, and a
retried commit, per code review: none of the prior tests exercised a
transaction ended without ever sending a server command.
Task 9's fix to bson/json_util._truncate_documents (removing a truthy
check that silently dropped falsy-but-valid field values like 0, False,
"", {}, []) was previously only covered incidentally via the vendored
OTel spec tests. Add a direct unit test so a future edit to this shared
production helper (also used by pymongo/logger.py for structured
command logging) can't silently reintroduce the bug.
…rom final review

Final whole-branch review found that most _retry_internal call sites pass an
_Op enum member (a str-mixin enum) as the operation name; Python 3.11 changed
str-mixin Enum formatting so this corrupted span names/db.operation.name on
every Python version from 3.11 through 3.14 (worked by accident on 3.10). Also
fixes: Database.command() now produces a "runCommand" operation span per the
OTel spec's driver-operation-name rule instead of leaking the underlying
(possibly sensitive, e.g. saslStart) command name; the operation span's
namespace/summary backfill now runs before the sensitive-command suppression
check so it still gets its required attributes; and operation spans now carry
exception.type/message/stacktrace attributes like command spans already did.
Also merges two adjacent versionchanged:: 4.18 docstring blocks for the
tracing option into one.
…span fixes

Adds regression coverage for the final-review fixes: an operation-name
normalization test using an _Op enum member (meaningful on every Python
version, not just 3.11+, since 3.10's accidental correctness is what hid the
bug), a runCommand operation-span-naming test (unit + live), and an
operation-span exception-attribute assertion. Updates test_otel.py assertions
that assumed the old (pre-fix) db.operation.name values, and updates or
removes the now-resolved TODO(PYTHON-5947) comments. Adds one-line comments
distinguishing the two hardcoded unified-format test skips (a removed API vs.
a genuine fixture/driver mismatch) in unified_format.py.
test/open_telemetry/transaction/*.json and test_otel.py's
@require_transactions tests both require a replicaset/sharded topology, but
the OTel variant only ran against a standalone server, so transaction spans
never actually ran in CI. Adds a second task selector
(".test-non-standard .replica_set-noauth-ssl"), mirroring the existing
pattern of pairing a standard/standalone selector with a replica-set one
(e.g. create_pyopenssl_variants()). Regenerated via the generate-config
pre-commit hook rather than hand-editing the generated YAML.
docs/superpowers/plans/2026-07-27-python-5947-otel-operation-transaction-spans.md
is an internal planning artifact from the implementation process, not
project documentation (which lives under doc/, singular). The task list it
describes is now complete.
blink1073 added 10 commits July 28, 2026 07:55
trace.use_span defaults record_exception/set_status_on_exception to
True, so an exception propagating out of a `with use_operation_span():`
block was auto-recorded there and then again by the caller's own
end_operation_span_failure, producing two identical exception events
on the finished span. Disable both, matching how the attached-mode
path already avoids this via cm.__exit__(None, None, None). Also
tighten start_operation_span's dbname/collection checks to `is not
None` instead of truthiness.
…namespace

AsyncDatabase.__getattr__ synthesizes a collection for any unknown
attribute name, so the getattr(target, "database", None) probe used to
distinguish an AsyncCollection target from an AsyncDatabase target
returned a phantom collection for database/cluster-level change
streams instead of None. This misclassified AsyncDatabaseChangeStream
and AsyncClusterChangeStream targets as collections, putting the wrong
values into db.namespace/db.collection.name. Switch to isinstance
checks with a deferred (call-time) import to avoid the module-scope
circular import between change_stream.py and collection.py/database.py.
Comment thread bson/json_util.py
if hasattr(obj, "items"):
truncated: Any = {}
for k, v in obj.items():
truncated_v, remaining = _truncate_documents(v, remaining)

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

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

These changes were needed for the new distinct.json, which has a falsey value for the field. These fields should not be dropped.

blink1073 added 26 commits July 28, 2026 19:50
Both had grown by accretion across two rounds of work, reading as a base
description followed by a list of later additions. Describe the feature as
it ships instead.
…try args

PYTHON-5963's test monkeypatches _CommandTelemetry.__init__ with a fixed
positional signature. PYTHON-5945 added tracing_options and
speculative_hello to that signature on this branch, so merging main in
broke the test: git saw no conflict because the two changes touch
different files. Forward the extra arguments instead of enumerating them.
db.namespace/db.collection.name are only "Required if available" per the
OTel spec, and no vendored fixture covers the failure-before-any-command
case they existed for, so remove the ~25-call-site eager threading of
dbname/collection through _retry_internal/_retryable_read/_retryable_write/
_retry_with_session (and delete AsyncChangeStream._target_namespace, which
only fed it). Instead, guarantee the always-Required db.operation.summary
by falling back to the bare operation name in start_operation_span when no
dbname is given. The lazy backfill in start_command_span still covers
every success path, and direct _OperationTelemetry construction (cursors,
killCursors, endSessions, unacknowledged bulk writes) is untouched.
Replace the hand-written "dbname.collname".split(".", 1) parsing
duplicated in command_cursor.py, cursor.py, mongo_client.py, and
aggregation.py with a single shared _split_namespace helper in
helpers_shared.py, keeping both the async and sync trees import-cycle
free without needing synchro generation for the helper itself.
Split with_transaction() into a thin wrapper that owns the shared
"transaction" span plus a new _with_transaction_retry_loop() helper
holding the retry loop at its original indentation, removing the ~51
lines of pure re-indentation diff noise the try/finally wrapping had
introduced. Also trims the span bookkeeping comments down to the
essential facts and drops the "Important #1" review-finding reference.

No behavior change: the retry loop's statements, control flow, and
this file's mirrored pymongo/synchronous/client_session.py (via
`just synchro`) are unchanged apart from the de-indent.
…ites

Adding dbname/collection arguments pushed several _retryable_read/write
calls over the line limit, so ruff exploded them one-per-line with a
magic trailing comma. Removing those arguments again left the trailing
comma behind, which keeps ruff from collapsing the calls back. Drop it
so these sites match their original single-line form.
Same magic-trailing-comma residue as the previous commit, at call sites
whose base form spread arguments across one continuation line rather
than fitting entirely on one line.
The wrapped annotated assignment read as if it were constructing an
AsyncCommandCursor rather than annotating the result of _retryable_read.
mypy needs the annotation (cmd.get_cursor's return type can't be
inferred), so declare it separately instead of dropping it.
_retry_internal held the span lifecycle and so constructed the retryable
object three times, once per span mode. The retryable object is already
the scope an operation span covers -- every attempt of one operation --
and already derives its own operation_id the same way, so give it the
span too. _retry_internal collapses to a single construction.
… boilerplate

Seven call sites in collection.py, database.py, and mongo_client.py repeated
the same create-span/try-except/attach-to-cursor skeleton needed because a
command cursor's first batch is fetched inside _retryable_read, before the
cursor object exists. Add AsyncMongoClient._retryable_read_cursor to own that
skeleton once, and convert all seven sites to call it. _list_databases also
had its command dispatch inlined from the now-dead Database._retryable_read_command
(which had no other callers) so it fits the same helper contract.

Removes the now-unused _OperationTelemetry import from collection.py and
database.py.
_list_databases fakes a cursor that is always exhausted on its first
batch, so it never issues a getMore and has nothing to nest -- it needs
only the ordinary operation span _retry_internal already gives it.
Converting it also meant deleting _retryable_read_command, a pre-existing
method unrelated to tracing. Restore both to their original form; the six
real command-cursor sites keep using the helper.
The helper took operation positionally and the rest through **kwargs, so
every call site had to reorder its arguments relative to the
_retryable_read call it replaced. Accepting the same parameters in the
same order lets each site keep its original shape and add only the
namespace.
The arguments are unchanged from before this branch; only the trailing
comma differed, and it kept ruff from collapsing the call back to one
line.
…rvers

Create collections before starting a transaction in five OTel transaction
tests, matching the pattern already used by the file's with_transaction
tests, so the first write inside the transaction never has to implicitly
create the namespace -- illegal in a multi-document transaction before
MongoDB 4.4.

Add an autouse module-scoped fixture to the OpenTelemetry unified-format
test module that drops the databases used by the vendored fixtures before
the suite runs, derived from each fixture's createEntities block. The
create_collection fixture is not idempotent and PyMongo runs every fixture
twice per process (async + synchro-generated mirror), so the second pass
previously collided with a leftover collection from the first on any server
that rejects a duplicate `create` (all CI server versions; masked locally
by 8.2's idempotent handling).
Also drop a trailing comma that kept a _retry_with_session call exploded
across seven lines when its arguments are unchanged, and remove three
references to code-review finding numbers, which mean nothing outside the
review they came from.
…trings

Replaces the ~57 instances of "--" used as sentence punctuation across the
OTel comments, docstrings, and test prose this branch introduced, with
parentheses, colons, semicolons, or sentence splits, per house style. No
code or behavior changes; generated sync mirrors were refreshed via `just
synchro`.
A colon was introducing a sentence fragment in two docstrings, and
_attach_operation_telemetry's docstring had become one long sentence.
Split them up.
Operation name overrides, the runCommand name and the enum normalization
helper are OpenTelemetry specification rules, so they belong beside
_build_query_summary in _otel.py rather than in the lifecycle module.
Collapse them behind a single _build_operation_name entry point and drop
the unused _OperationTelemetry.operation_name attribute.
Record two facts a reader currently has to reconstruct from the code:
that start_command_span makes one leaf span per wire message and returns
it rather than making it current, and that the operation span is shared
across retry attempts while each attempt gets its own command span.
Remove eight hand-written tests whose assertions the vendored fixtures
make more strictly, with ignoreExtraSpans set to false: the find
operation/command nesting case, transaction commit and abort, the
acknowledged bulkWrite namespace case, and four none-safety unit tests
subsumed by the remaining disabled-tracing coverage.

Narrow the eager-namespace test to count_documents, the one case it
covered that no fixture reaches. Its operation span is named for the
driver operation while the command it sends is an aggregate, so the two
names diverge; count.json only exercises estimated_document_count, where
they coincide.
The normalization was a pure function living in the mirrored
unified_format.py, so just synchro duplicated it into the sync copy for
no reason. Everything it is written against already sits in
unified_format_shared.py: BSON_TYPE_ALIAS_MAP for the long alias, and
_operation_sessionLsid for the lsid shape.

Fold it into MatchEvaluatorUtil as a private staticmethod behind a new
match_span_attributes method, following the existing match_* convention,
so the span-checking code no longer has to know that span attributes need
adapting before they can be matched.
The join was added to stop a stray heartbeat command span from landing in
another test's span-capture window, but no such span exists. A monitor
issues its hello through Connection.command without passing a client, so
_run_command derives no tracing options and start_command_span returns
None. _CmapTelemetry, _HeartbeatTelemetry and _SdamTelemetry never touch
_otel either, so monitors have no way to emit a span at all.

Verified by running 60 connect/close cycles that cancel monitors
mid-heartbeat: no hello spans appear, and nothing is exported after
close() returns in either driver on a three-node replica set.

The same commit that added this also shut each test class's exporter down
in tearDownClass, which is the change that actually fixes the shared
process-wide TracerProvider cross-talk, and that stays.

Every test client is back to a plain close() cleanup, so test/__init__.py
no longer carries a two-branch cleanup path.
Replaces both local workarounds with the upstream fix. The vendored
fixtures now come from the DRIVERS-3597 branch: update.json accepts multi
and upsert either omitted or at their default values, and the fixtures
that create collections declare initialData, with create_collection.json
dropping the collection itself so it is repeatable.

That removes the skip for the update test and the module-scoped database
cleanup, and the deviation lives in .evergreen/spec-patch/PYTHON-5979.patch
so a resync reapplies it until DRIVERS-3597 merges. PYTHON-5979 drops the
patch at that point.

The otel selection goes from 178 passed and 5 skipped to 180 passed and 3
skipped, leaving only the two mapReduce skips for the API PyMongo removed.
Python 3.14 changed threading.Thread to run its target in a copy of the
creating thread's context, where before a thread started with an empty
one. The sync periodic executor therefore now inherits whatever was
current when it was opened, which for the kill-cursors executor is the
middle of the client's first operation. Every later tick then runs under
that operation's CSOT deadline, op id and span. The async executor
already reset all three because create_task always froze the context;
the sync one now does the same.

Reproduced on free-threaded 3.14t, where the kill-cursors thread saw the
main thread's span and test_background_kill_cursors_span_is_a_trace_root
failed on every run. It passes on 3.10 only because threads there start
with an empty context.

Also stop two tests asserting the exporter is completely empty. A cursor
abandoned earlier in the class ends its span from a finalizer, and on an
interpreter that does not reference count that runs at an unpredictable
point, which is why test_tracing_disabled_by_default failed under PyPy.
They now assert on the ping's own spans, which still fails if tracing is
wrongly enabled.
# Conflicts:
#	pymongo/asynchronous/mongo_client.py
#	pymongo/synchronous/mongo_client.py
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.

2 participants