PYTHON-5947 Add OpenTelemetry Operation and Transaction Span Support - #2964
Draft
blink1073 wants to merge 81 commits into
Draft
PYTHON-5947 Add OpenTelemetry Operation and Transaction Span Support#2964blink1073 wants to merge 81 commits into
blink1073 wants to merge 81 commits into
Conversation
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.
…e unified test format runner
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.
Codecov Report❌ Patch coverage is 📢 Thoughts on this report? Let us know! |
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.
_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.
4 tasks
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
# Conflicts: # pymongo/_telemetry.py # pymongo/asynchronous/command_runner.py # pymongo/synchronous/command_runner.py
# Conflicts: # pymongo/asynchronous/client_bulk.py # pymongo/asynchronous/mongo_client.py # pymongo/synchronous/client_bulk.py # pymongo/synchronous/mongo_client.py # test/asynchronous/test_operation_id_retry.py # test/test_operation_id_retry.py
DRIVERS-3598 resolves an ambiguity in the OpenTelemetry specification: when the caller drives cursor iteration, each getMore gets its own operation span, sibling to the span of the command that created the cursor, rather than one span covering the cursor's whole lifetime. The application is free to do unrelated work between batches, and a lifetime-scoped span would attribute that work to the original operation. Driver-internal iteration keeps today's behavior: when the driver drains a cursor to produce the return value of a single public API call, those getMore command spans stay under that call's one operation span. Also: - db.mongodb.cursor_id on a getMore now records the id the driver sent rather than the id the reply returned, so it survives the final getMore whose reply carries 0. It is still omitted, never emitted as 0, for a cursor-creating command that leaves no cursor open. - A cursor opened by a command (listCollections, listIndexes, a database-level aggregate) targets no user collection, so db.collection.name is omitted and its getMore operation span is named "getMore <db>" rather than "getMore <db>.$cmd.listCollections". Adds the spec's get_more.json unified fixture and prose tests 3 and 4. The fixture comes from a specification change that is not merged yet.
Follow _CommandTelemetry's fast path for operation spans: route the seven construction sites through _operation_telemetry_or_none, which returns None when tracing is disabled instead of building an object whose every method is a no-op. Verified by counting constructions: zero with tracing off, five for the same work with it on. Also run the otel suite against sharded clusters. Sharded adds mongos, which rewrites commands and reports a different server.address, plus auth and ssl, which exercise sensitive-command redaction. The variant now covers all three topologies, subset to hold the task count at 22: replica set in full, since it is the only one where transaction spans run and the only one covering free-threaded Python; sharded on the newest CPython and PyPy; standalone only for its min-deps tasks, which resolve opentelemetry-api to its floor. The rest is trimming the comments and docstrings this branch added.
Nesting with_transaction() is legal on a different session, and each session's operations must parent to its own transaction span. That holds because an operation span takes its parent explicitly from session._transaction.span rather than reading ambient context, so the test asserts both transaction spans are trace roots and that each insert parents to a different one. Confirmed the assertion bites: dropping the explicit parent fails it.
start_transaction_span already returned None when tracing was off, but its callers ran the surrounding bookkeeping regardless. Check enablement at the call sites instead, matching command and operation telemetry. with_transaction gains the most: its finally block no longer ends a span, compares identities and clears two attributes on every call when tracing is off. start_transaction, the retried-commit path and _end_own_transaction_span now only touch _transaction.span when there is a span to touch. Counted the calls: two per pair of transactions before, zero with tracing off, and both transactions still commit either way.
_start_getmore_operation_telemetry ran is_command_namespace and the telemetry factory on every getMore before anything checked whether tracing was on. Hoist the check. The cursor path in _retryable_read_cursor likewise consulted is_internal_cursor_iteration when there was no span to attach.
_is_tracing_enabled read OTEL_PYTHON_INSTRUMENTATION_MONGODB_ENABLED on every call to answer a question that cannot change during a client's life, and os.environ access goes through os.fsencode on POSIX. ClientOptions now folds the environment variable into tracing.enabled when the client is built, leaving the check a lookup: 248 to 17 ns on PyPy and 532 to 82 ns on CPython, which is what makes the object guards worth having (they now save 72 and 74 percent rather than 21 and 39). This also fixes a bug. Monitor and handshake connections have no client, so their tracing options are None, and the old fallback consulted the environment anyway. A client enabled by the environment variable rather than the tracing option therefore traced every heartbeat: 12 hello spans in a two-second window, which the spec excludes. None now means untraced, and a regression test covers it.
Context-related environment variables are process-startup input, so a client
reads them when it is built and never again. _get_query_text_max_length was
still calling os.getenv on every traced command; ClientOptions now folds both
variables in through _otel._resolve_tracing_options, leaving the accessor a
lookup.
Confirmed by counting: a client built with both variables set resolves to
{enabled: True, query_text_max_length: 1024} and then performs zero OTEL_
environment reads across an insert, a batched find and a ping, with
db.query.text still emitted.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
PYTHON-5947
Changes in this PR
Extends the OpenTelemetry support added in PYTHON-5945 with:
getMorecommands nest under the originatingfind/aggregateinstead of producing spans of their own."transaction"span wrappingstart_transaction()throughcommit_transaction()/abort_transaction(), with the operations inside nested under it. A retriedwith_transaction()produces one span covering all attempts.observeTracingMessages/expectTracingMessages, plus the vendored spec test suite.Failure paths stay conformant: an operation that fails before any command reaches the wire still carries
db.operation.nameanddb.operation.summary, andkillCursors/endSessionsget operation spans rather than leaving their command spans unparented.Opt-in, with no behavior change unless the
tracingclient option orOTEL_PYTHON_INSTRUMENTATION_MONGODB_ENABLEDis set. When tracing is off, no telemetry object is constructed at all, following the fast path PYTHON-5977 introduced for command telemetry. Enablement is resolved once when the client is built rather than re-read from the environment on every command, which takes the check from 248 ns to 17 ns on PyPy and 532 ns to 82 ns on CPython.Reviewer's guide
Of ~9,500 added lines, most aren't hand-written:
test/open_telemetry/*.json)resync-specs.shoutputpymongo/synchronous/*, mirroredtest/*)just synchrooutput.evergreen/spec-patch/PYTHON-5979.patch)git diffoutputtest_otel.pyWhere to look.
pymongo/_otel.pyis the core (~500 lines): span primitives plus all of the spec's naming and attribute rules.pymongo/_telemetry.pyholds the lifecycle wrappers and no spec knowledge. Inmongo_client.py,_retry_internalgained three span modes: owned, caller-owned, and passthrough. The two decisions most worth scrutinising are theparent_spanparameter in_otel.py(transaction parenting is passed explicitly rather than read from ambient context) and cursor-lifetime span ownership incursor_shared.py, where_end_operation_telemetryis idempotent because close, GC, and exception paths can all reach it.Already considered:
bson/json_util.pyis touched._truncate_documentssilently dropped falsy values (0,False,"") from truncated output. It's shared withpymongo/logger.py, so this affected structured command logging too. Has a regression test.getMorenesting, because a tailing stream's operation span would never end.close()needs no special handling. A monitor'shellogoes throughConnection.commandwithout a client, so its tracing options are None, which means untraced; CMAP, heartbeat and SDAM telemetry never touch_oteleither. Enabling tracing through the environment variable used to be an exception here, tracing every heartbeat, because the old enablement check fell back to reading the environment when there was no client. Fixed, with a regression test.ignoreExtraSpans: false; duplicates of those were dropped. What's left is cursor andgetMorelifetime (no fixture mentionsgetMoreat all), exception attributes on an operation span (fixtures only assert them on command spans), span status,killCursors/endSessions, change streams, and config handling.update.jsonrejected drivers that sendmulti/upsertat their defaults, and the fixtures that create collections declared noinitialData, so they weren't repeatable. Both are fixed in DRIVERS-3597, whose fixtures this PR vendors, with the deviation recorded in.evergreen/spec-patch/PYTHON-5979.patchuntil that merges.run_commandencodes the OP_MSG before the command span exists, so span creation has to move ahead of encoding. Tracked in PYTHON-5855.Test Plan
opentelemetry-apito its floor.Checklist
Checklist for Author
No follow-up work outstanding from this ticket. PYTHON-5978 was filed separately for two pre-existing bugs noticed in passing: the sync driver's
Monitor.join()andTopology.cleanup_monitors()both wrap theirjoin()calls in anasyncio.gather(...)that is never awaited, so neither actually waits.Checklist for Reviewer