From ea074a361f3758611f93690f6f61a4e443536a74 Mon Sep 17 00:00:00 2001 From: Iris <58442094+sleepyStick@users.noreply.github.com> Date: Tue, 23 Jun 2026 05:53:21 -0700 Subject: [PATCH 1/9] PYTHON-5894 fix failing auth spec tests (#2888) --- test/asynchronous/test_auth_spec.py | 4 +++- test/test_auth_spec.py | 2 +- 2 files changed, 4 insertions(+), 2 deletions(-) diff --git a/test/asynchronous/test_auth_spec.py b/test/asynchronous/test_auth_spec.py index 1cfd706fbb..4a011b4aab 100644 --- a/test/asynchronous/test_auth_spec.py +++ b/test/asynchronous/test_auth_spec.py @@ -58,7 +58,9 @@ def run_test(self): if not valid: with warnings.catch_warnings(): warnings.simplefilter("default") - self.assertRaises(ConfigurationError, AsyncMongoClient, uri, connect=False) + self.assertRaises( + (ConfigurationError, ValueError), AsyncMongoClient, uri, connect=False + ) else: client = self.simple_client(uri, connect=False) credentials = client.options.pool_options._credentials diff --git a/test/test_auth_spec.py b/test/test_auth_spec.py index 974a9df1de..a165beac92 100644 --- a/test/test_auth_spec.py +++ b/test/test_auth_spec.py @@ -58,7 +58,7 @@ def run_test(self): if not valid: with warnings.catch_warnings(): warnings.simplefilter("default") - self.assertRaises(ConfigurationError, MongoClient, uri, connect=False) + self.assertRaises((ConfigurationError, ValueError), MongoClient, uri, connect=False) else: client = self.simple_client(uri, connect=False) credentials = client.options.pool_options._credentials From 1dd074791bd2ff68fdbb11c42158a7e0c4acb932 Mon Sep 17 00:00:00 2001 From: Steven Silvester Date: Tue, 23 Jun 2026 12:38:42 -0500 Subject: [PATCH 2/9] PYTHON-5890 Remove automatic synchro for local testing (#2890) --- justfile | 8 ++------ 1 file changed, 2 insertions(+), 6 deletions(-) diff --git a/justfile b/justfile index cce40f5117..55ff9e74dd 100644 --- a/justfile +++ b/justfile @@ -16,10 +16,6 @@ default: resync: @uv sync --quiet -[private] -run-synchro: - uv run --group unasync ./tools/synchro.py - # Set up the development environment install: bash .evergreen/scripts/setup-dev-env.sh @@ -70,7 +66,7 @@ lint-manual *args="": && resync # Run pytest (e.g. just test test/test_uri_parser.py) [group('test')] -test *args="-v --durations=5 --maxfail=10": run-synchro && resync +test *args="-v --durations=5 --maxfail=10": && resync #!/usr/bin/env bash set -euo pipefail uv run ${USE_ACTIVE_VENV:+--active} --extra test python -m pytest {{args}} @@ -83,7 +79,7 @@ test-numpy *args="": && resync # Run tests via the Evergreen test runner script [group('test')] -run-tests *args: run-synchro && resync +run-tests *args: && resync bash ./.evergreen/run-tests.sh {{args}} # Set up the test environment (auth, TLS, etc.) From 4282767e535756840e5d4e3c42fe70f235018752 Mon Sep 17 00:00:00 2001 From: Jeffrey 'Alex' Clark Date: Tue, 23 Jun 2026 22:08:01 -0400 Subject: [PATCH 3/9] PYTHON-5676 Consolidate command execution logic (#2852) Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Co-authored-by: Steven Silvester Co-authored-by: Noah Stapp --- pymongo/asynchronous/bulk.py | 193 ++------- pymongo/asynchronous/client_bulk.py | 185 ++------- pymongo/asynchronous/command_runner.py | 544 +++++++++++++++++++++++++ pymongo/asynchronous/network.py | 286 ------------- pymongo/asynchronous/pool.py | 46 +-- pymongo/asynchronous/server.py | 174 ++------ pymongo/message.py | 96 ----- pymongo/synchronous/bulk.py | 193 ++------- pymongo/synchronous/client_bulk.py | 185 ++------- pymongo/synchronous/command_runner.py | 544 +++++++++++++++++++++++++ pymongo/synchronous/network.py | 286 ------------- pymongo/synchronous/pool.py | 46 +-- pymongo/synchronous/server.py | 174 ++------ test/test_message.py | 49 --- 14 files changed, 1284 insertions(+), 1717 deletions(-) create mode 100644 pymongo/asynchronous/command_runner.py delete mode 100644 pymongo/asynchronous/network.py create mode 100644 pymongo/synchronous/command_runner.py delete mode 100644 pymongo/synchronous/network.py diff --git a/pymongo/asynchronous/bulk.py b/pymongo/asynchronous/bulk.py index 2f04431eb4..3075afa2b3 100644 --- a/pymongo/asynchronous/bulk.py +++ b/pymongo/asynchronous/bulk.py @@ -20,8 +20,6 @@ from __future__ import annotations import copy -import datetime -import logging from collections.abc import Iterator, Mapping, MutableMapping from itertools import islice from typing import ( @@ -34,9 +32,9 @@ from bson.objectid import ObjectId from bson.raw_bson import RawBSONDocument from pymongo import _csot, common -from pymongo.asynchronous.client_session import ( - AsyncClientSession, - _validate_session_write_concern, +from pymongo.asynchronous.client_session import AsyncClientSession, _validate_session_write_concern +from pymongo.asynchronous.command_runner import ( + run_bulk_write_command, ) from pymongo.asynchronous.helpers import _handle_reauth from pymongo.bulk_shared import ( @@ -54,18 +52,14 @@ from pymongo.errors import ( ConfigurationError, InvalidOperation, - NotPrimaryError, OperationFailure, ) from pymongo.helpers_shared import _RETRYABLE_ERROR_CODES -from pymongo.logger import _COMMAND_LOGGER, _CommandStatusMessage, _debug_log from pymongo.message import ( _DELETE, _INSERT, _UPDATE, _BulkWriteContext, - _convert_exception, - _convert_write_result, _EncryptedBulkWriteContext, _randint, ) @@ -251,83 +245,16 @@ async def write_command( docs: list[Mapping[str, Any]], client: AsyncMongoClient[Any], ) -> dict[str, Any]: - """A proxy for SocketInfo.write_command that handles event publishing.""" + """Run a batch write command, returning the response as a dict.""" cmd[bwc.field] = docs - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.STARTED, - clientId=client._topology_settings._topology_id, - command=cmd, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - bwc._start(cmd, request_id, docs) - try: - if bwc.session is not None and bwc.session._starting_transaction: - bwc.session._transaction.set_in_progress() - reply = await bwc.conn.write_command(request_id, msg, bwc.codec) # type: ignore[misc] - duration = datetime.datetime.now() - bwc.start_time - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.SUCCEEDED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - reply=reply, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - bwc._succeed(request_id, reply, duration) # type: ignore[arg-type] - await client._process_response(reply, bwc.session) # type: ignore[arg-type] - except Exception as exc: - duration = datetime.datetime.now() - bwc.start_time - if isinstance(exc, (NotPrimaryError, OperationFailure)): - failure: _DocumentOut = exc.details # type: ignore[assignment] - else: - failure = _convert_exception(exc) - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.FAILED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - failure=failure, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - isServerSideError=isinstance(exc, OperationFailure), - ) - - if bwc.publish: - bwc._fail(request_id, failure, duration) - # Process the response from the server. - if isinstance(exc, (NotPrimaryError, OperationFailure)): - await client._process_response(exc.details, bwc.session) # type: ignore[arg-type] - raise - return reply # type: ignore[return-value] + result_docs, _, _ = await run_bulk_write_command( + bwc, + cmd, + request_id, + msg, + client=client, + ) + return result_docs[0] async def unack_write( self, @@ -339,83 +266,23 @@ async def unack_write( docs: list[Mapping[str, Any]], client: AsyncMongoClient[Any], ) -> Optional[Mapping[str, Any]]: - """A proxy for AsyncConnection.unack_write that handles event publishing.""" - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.STARTED, - clientId=client._topology_settings._topology_id, - command=cmd, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - cmd = bwc._start(cmd, request_id, docs) - try: - result = await bwc.conn.unack_write(msg, max_doc_size) # type: ignore[func-returns-value, misc, override] - duration = datetime.datetime.now() - bwc.start_time - if result is not None: - reply = _convert_write_result(bwc.name, cmd, result) # type: ignore[arg-type] - else: - # Comply with APM spec. - reply = {"ok": 1} - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.SUCCEEDED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - reply=reply, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - bwc._succeed(request_id, reply, duration) - except Exception as exc: - duration = datetime.datetime.now() - bwc.start_time - if isinstance(exc, OperationFailure): - failure: _DocumentOut = _convert_write_result(bwc.name, cmd, exc.details) # type: ignore[arg-type] - elif isinstance(exc, NotPrimaryError): - failure = exc.details # type: ignore[assignment] - else: - failure = _convert_exception(exc) - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.FAILED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - failure=failure, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - isServerSideError=isinstance(exc, OperationFailure), - ) - if bwc.publish: - assert bwc.start_time is not None - bwc._fail(request_id, failure, duration) - raise - return result # type: ignore[return-value] + """Send an unacknowledged batch write command.""" + # Historically the STARTED log omits the documents while the published + # CommandStartedEvent includes them, so log ``cmd`` but publish a copy + # carrying the ``docs`` field. + published = dict(cmd) + published[bwc.field] = docs + await run_bulk_write_command( + bwc, + cmd, + request_id, + msg, + client=client, + orig=published, + max_doc_size=max_doc_size, + unacknowledged=True, + ) + return None async def _execute_batch_unack( self, @@ -487,7 +354,7 @@ async def _execute_command( run = self.current_run # AsyncConnection.command validates the session, but we use - # AsyncConnection.write_command + # run_bulk_write_command. conn.validate_session(client, session) last_run = False diff --git a/pymongo/asynchronous/client_bulk.py b/pymongo/asynchronous/client_bulk.py index 45fbc403c0..cfa2ea9853 100644 --- a/pymongo/asynchronous/client_bulk.py +++ b/pymongo/asynchronous/client_bulk.py @@ -20,8 +20,6 @@ from __future__ import annotations import copy -import datetime -import logging from collections.abc import Mapping, MutableMapping from itertools import islice from typing import ( @@ -40,6 +38,9 @@ ) from pymongo.asynchronous.collection import AsyncCollection from pymongo.asynchronous.command_cursor import AsyncCommandCursor +from pymongo.asynchronous.command_runner import ( + run_bulk_write_command, +) from pymongo.asynchronous.database import AsyncDatabase from pymongo.asynchronous.helpers import _handle_reauth @@ -65,12 +66,9 @@ WaitQueueTimeoutError, ) from pymongo.helpers_shared import _RETRYABLE_ERROR_CODES -from pymongo.logger import _COMMAND_LOGGER, _CommandStatusMessage, _debug_log from pymongo.message import ( _ClientBulkWriteContext, _convert_client_bulk_exception, - _convert_exception, - _convert_write_result, _randint, ) from pymongo.read_preferences import ReadPreference @@ -238,87 +236,21 @@ async def write_command( ns_docs: list[Mapping[str, Any]], client: AsyncMongoClient[Any], ) -> dict[str, Any]: - """A proxy for AsyncConnection.write_command that handles event publishing.""" + """Run a client-level batch write command, returning the response as a dict.""" cmd["ops"] = op_docs cmd["nsInfo"] = ns_docs - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.STARTED, - clientId=client._topology_settings._topology_id, - command=cmd, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - bwc._start(cmd, request_id, op_docs, ns_docs) try: - if bwc.session is not None and bwc.session._starting_transaction: - bwc.session._transaction.set_in_progress() - reply = await bwc.conn.write_command(request_id, msg, bwc.codec) # type: ignore[misc, arg-type] - duration = datetime.datetime.now() - bwc.start_time - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.SUCCEEDED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - reply=reply, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - bwc._succeed(request_id, reply, duration) # type: ignore[arg-type] - # Process the response from the server. - await self.client._process_response(reply, bwc.session) # type: ignore[arg-type] + result_docs, _, _ = await run_bulk_write_command( + bwc, + cmd, + request_id, + msg, # type: ignore[arg-type] + client=client, + ) + reply = result_docs[0] except Exception as exc: - duration = datetime.datetime.now() - bwc.start_time - if isinstance(exc, (NotPrimaryError, OperationFailure)): - failure: _DocumentOut = exc.details # type: ignore[assignment] - else: - failure = _convert_exception(exc) - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.FAILED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - failure=failure, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - isServerSideError=isinstance(exc, OperationFailure), - ) - - if bwc.publish: - bwc._fail(request_id, failure, duration) # Top-level error will be embedded in ClientBulkWriteException. reply = {"error": exc} - # Process the response from the server. - if isinstance(exc, OperationFailure): - await self.client._process_response(exc.details, bwc.session) # type: ignore[arg-type] - else: - await self.client._process_response({}, bwc.session) # type: ignore[arg-type] return reply # type: ignore[return-value] async def unack_write( @@ -331,81 +263,26 @@ async def unack_write( ns_docs: list[Mapping[str, Any]], client: AsyncMongoClient[Any], ) -> Optional[Mapping[str, Any]]: - """A proxy for AsyncConnection.unack_write that handles event publishing.""" - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.STARTED, - clientId=client._topology_settings._topology_id, - command=cmd, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - cmd = bwc._start(cmd, request_id, op_docs, ns_docs) + """Send an unacknowledged client-level batch write command.""" + # Historically the STARTED log omits the ops/nsInfo while the published + # CommandStartedEvent includes them, so log ``cmd`` but publish a copy + # carrying those fields. + published = dict(cmd) + published["ops"] = op_docs + published["nsInfo"] = ns_docs try: - result = await bwc.conn.unack_write(msg, bwc.max_bson_size) # type: ignore[func-returns-value, misc, override] - duration = datetime.datetime.now() - bwc.start_time - if result is not None: - reply = _convert_write_result(bwc.name, cmd, result) # type: ignore[arg-type] - else: - # Comply with APM spec. - reply = {"ok": 1} - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.SUCCEEDED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - reply=reply, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - bwc._succeed(request_id, reply, duration) + result_docs, _, _ = await run_bulk_write_command( + bwc, + cmd, + request_id, + msg, + client=client, + orig=published, + max_doc_size=bwc.max_bson_size, + unacknowledged=True, + ) + reply: Mapping[str, Any] = result_docs[0] except Exception as exc: - duration = datetime.datetime.now() - bwc.start_time - if isinstance(exc, OperationFailure): - failure: _DocumentOut = _convert_write_result(bwc.name, cmd, exc.details) # type: ignore[arg-type] - elif isinstance(exc, NotPrimaryError): - failure = exc.details # type: ignore[assignment] - else: - failure = _convert_exception(exc) - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.FAILED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - failure=failure, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - isServerSideError=isinstance(exc, OperationFailure), - ) - if bwc.publish: - assert bwc.start_time is not None - bwc._fail(request_id, failure, duration) # Top-level error will be embedded in ClientBulkWriteException. reply = {"error": exc} return reply @@ -504,7 +381,7 @@ async def _execute_command( listeners = self.client._event_listeners # AsyncConnection.command validates the session, but we use - # AsyncConnection.write_command + # run_bulk_write_command. conn.validate_session(self.client, session) bwc = self.bulk_ctx_class( diff --git a/pymongo/asynchronous/command_runner.py b/pymongo/asynchronous/command_runner.py new file mode 100644 index 0000000000..b663893a7b --- /dev/null +++ b/pymongo/asynchronous/command_runner.py @@ -0,0 +1,544 @@ +# Copyright 2015-present MongoDB, Inc. +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# https://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +"""Encoding and execution of commands over a connection (previously ``network.py``). + +Three public entry points each wrap the private :func:`_run_command`: + +- :func:`run_command` — the standard entry point used by ``pool.py``. Applies + read concern, collation, ``$clusterTime``, compression, auto-encryption, and + CSOT to a raw spec dict, encodes it as OP_MSG, then delegates to + :func:`_run_command`. +- :func:`run_bulk_write_command` — collection-level and client-level bulk write + batches. Pre-encrypted, so decryption is skipped. Callers: ``bulk.py``, + ``client_bulk.py``. +- :func:`run_cursor_command` — cursor ``find``/``getMore`` operations with + exhaust-cursor handling. Caller: ``server.py``. + +:func:`_run_command` owns the entire shared skeleton: command logging, APM +event publishing, ``send``/``receive``, ``$clusterTime`` gossip, +``_process_response``, ``_check_command_response``, failure conversion, and +auto-encryption decryption. Each public wrapper hardcodes the flags for its +command type so callers only pass what varies. +""" + +from __future__ import annotations + +import datetime +import logging +from collections.abc import Mapping, MutableMapping, Sequence +from typing import ( + TYPE_CHECKING, + Any, + Callable, + Optional, + Union, + cast, +) + +from bson import _decode_all_selective +from pymongo import _csot, helpers_shared, message +from pymongo.compression_support import _NO_COMPRESSION +from pymongo.errors import NotPrimaryError, OperationFailure +from pymongo.logger import _COMMAND_LOGGER, _CommandStatusMessage, _debug_log +from pymongo.message import _BulkWriteContextBase, _convert_exception, _OpMsg +from pymongo.monitoring import _is_speculative_authenticate + +if TYPE_CHECKING: + from bson import CodecOptions + from pymongo.asynchronous.client_session import AsyncClientSession + from pymongo.asynchronous.mongo_client import AsyncMongoClient + from pymongo.asynchronous.pool import AsyncConnection + from pymongo.compression_support import SnappyContext, ZlibContext, ZstdContext + from pymongo.monitoring import _EventListeners + from pymongo.pool_options import PoolOptions + from pymongo.read_concern import ReadConcern + from pymongo.read_preferences import _ServerMode + from pymongo.typings import _Address, _CollationIn, _DocumentOut, _DocumentType + from pymongo.write_concern import WriteConcern + +_IS_SYNC = False + + +async def _run_command( + conn: AsyncConnection, + cmd: MutableMapping[str, Any], + dbname: str, + request_id: int, + msg: bytes, + *, + client: Optional[AsyncMongoClient[Any]], + session: Optional[AsyncClientSession], + listeners: Optional[_EventListeners], + address: Optional[_Address], + start: datetime.datetime, + codec_options: CodecOptions[_DocumentType], + user_fields: Optional[Mapping[str, Any]] = None, + orig: Optional[MutableMapping[str, Any]] = None, + op_id: Optional[int] = None, + command_name: Optional[str] = None, + check: bool = True, + allowable_errors: Optional[Sequence[Union[str, int]]] = None, + parse_write_concern_error: bool = False, + pool_opts: Optional[PoolOptions] = None, + unacknowledged: bool = False, + speculative_hello: bool = False, + ensure_db: bool = False, + decrypt_reply: bool = True, + max_doc_size: int = 0, + more_to_come: bool = False, + set_conn_more_to_come: bool = False, + unpack_res: Optional[Callable[..., Any]] = None, + cursor_id: Optional[int] = None, +) -> tuple[list[dict[str, Any]], Optional[_OpMsg], datetime.timedelta]: + """Send ``msg`` over ``conn`` and return ``(docs, reply, duration)``. + + Private shared implementation. Should not be called directly outside this module. Use :func:`run_command`, :func:`run_bulk_write_command`, or :func:`run_cursor_command` instead. + + Publishes the + ``STARTED``/``SUCCEEDED``/``FAILED`` command log and APM events, performs + the network round trip, gossips ``$clusterTime``, runs + ``client._process_response`` and ``_check_command_response``, and decrypts + the reply when auto-encryption is enabled. + + :param conn: The AsyncConnection to send on. + :param cmd: The command document, used for the ``STARTED`` log/APM event. + :param dbname: The database the command runs against. + :param request_id: The request id of the encoded message (``0`` when + ``more_to_come`` and no message is sent). + :param msg: The encoded bytes to send (ignored when ``more_to_come``). + :param client: The AsyncMongoClient, for ``$clusterTime`` gossip, logging, + and decryption. ``None`` disables those steps (e.g. during handshake). + :param session: The session to update from the response. + :param listeners: The event listeners, or ``None`` to disable APM. + :param address: The (host, port) of ``conn`` for APM events. + :param start: The ``datetime`` the operation began, for duration timing. + :param codec_options: The CodecOptions used to decode the reply. + :param user_fields: Response fields decoded with the codec's TypeDecoders. + :param orig: The command document published in the ``STARTED`` APM event; + defaults to ``cmd`` (differs only when the wire command was mutated, + e.g. with a read preference or after encryption). + :param op_id: The APM operation id; defaults to ``request_id``. + :param command_name: The command name for the ``SUCCEEDED``/``FAILED`` APM + events; defaults to the first key of ``cmd``. + :param check: Raise OperationFailure on a command error. + :param allowable_errors: Errors to ignore when ``check`` is True. + :param parse_write_concern_error: Parse the ``writeConcernError`` field. + :param pool_opts: PoolOptions forwarded to ``_check_command_response`` (the + cursor path uses this in place of ``allowable_errors``). + :param unacknowledged: True for an unacknowledged write: send only and fake + an ``{"ok": 1}`` reply. + :param speculative_hello: True if the command carried speculative auth, for + APM redaction. + :param ensure_db: Add ``$db`` to the published command if missing (cursor + path), after the ``STARTED`` log has been emitted. + :param decrypt_reply: Decrypt the reply when auto-encryption is enabled; + the bulk paths pass False (their commands are encrypted up front). + :param max_doc_size: The largest document size, for ``conn.send_message``. + :param more_to_come: Receive only, without sending (exhaust ``getMore``). + :param set_conn_more_to_come: Store ``reply.more_to_come`` on ``conn`` (the + network/streaming-monitor path); the cursor path manages exhaust + separately and must leave ``conn.more_to_come`` untouched. + :param unpack_res: A callable decoding the wire response (cursor path); when + ``None`` the reply's own ``unpack_response`` is used. + :param cursor_id: The cursor id passed to ``unpack_res``. + """ + name = next(iter(cmd)) + if command_name is None: + command_name = name + if orig is None: + orig = cmd + publish = listeners is not None and listeners.enabled_for_commands + + if client is not None and _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): + _debug_log( + _COMMAND_LOGGER, + message=_CommandStatusMessage.STARTED, + clientId=client._topology_settings._topology_id, + command=cmd, + commandName=name, + databaseName=dbname, + requestId=request_id, + operationId=request_id, + driverConnectionId=conn.id, + serverConnectionId=conn.server_connection_id, + serverHost=conn.address[0], + serverPort=conn.address[1], + serviceId=conn.service_id, + ) + if publish: + assert listeners is not None + assert address is not None + if ensure_db and "$db" not in orig: + orig["$db"] = dbname + listeners.publish_command_start( + orig, + dbname, + request_id, + address, + conn.server_connection_id, + op_id, + service_id=conn.service_id, + ) + + reply: Optional[_OpMsg] = None + docs: list[dict[str, Any]] = [{"ok": 1}] + try: + if more_to_come: + reply = await conn.receive_message(None) + else: + if unacknowledged: + conn._raise_if_not_writable() + elif session is not None and session._starting_transaction: + session._transaction.set_in_progress() + await conn.send_message(msg, max_doc_size) + if not unacknowledged: + reply = await conn.receive_message(request_id) + + if reply: + if set_conn_more_to_come: + conn.more_to_come = reply.more_to_come + if unpack_res is not None: + docs = unpack_res( + reply, + cursor_id, + codec_options, + user_fields=user_fields, + ) + else: + docs = reply.unpack_response(codec_options=codec_options, user_fields=user_fields) + response_doc = docs[0] + if not conn.ready: + cluster_time = response_doc.get("$clusterTime") + if cluster_time: + conn._cluster_time = cluster_time + if client: + await client._process_response(response_doc, session) + if check: + helpers_shared._check_command_response( + response_doc, + conn.max_wire_version, + allowable_errors, + parse_write_concern_error=parse_write_concern_error, + pool_opts=pool_opts, + ) + except Exception as exc: + duration = datetime.datetime.now() - start + if isinstance(exc, (NotPrimaryError, OperationFailure)): + failure: _DocumentOut = exc.details # type: ignore[assignment] + else: + failure = _convert_exception(exc) + if client is not None and _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): + _debug_log( + _COMMAND_LOGGER, + message=_CommandStatusMessage.FAILED, + clientId=client._topology_settings._topology_id, + durationMS=duration, + failure=failure, + commandName=name, + databaseName=dbname, + requestId=request_id, + operationId=request_id, + driverConnectionId=conn.id, + serverConnectionId=conn.server_connection_id, + serverHost=conn.address[0], + serverPort=conn.address[1], + serviceId=conn.service_id, + isServerSideError=isinstance(exc, OperationFailure), + ) + if publish: + assert listeners is not None + assert address is not None + listeners.publish_command_failure( + duration, + failure, + command_name, + request_id, + address, + conn.server_connection_id, + op_id, + service_id=conn.service_id, + database_name=dbname, + ) + raise + + duration = datetime.datetime.now() - start + published_reply = docs[0] + if client is not None and _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): + _debug_log( + _COMMAND_LOGGER, + message=_CommandStatusMessage.SUCCEEDED, + clientId=client._topology_settings._topology_id, + durationMS=duration, + reply=published_reply, + commandName=name, + databaseName=dbname, + requestId=request_id, + operationId=request_id, + driverConnectionId=conn.id, + serverConnectionId=conn.server_connection_id, + serverHost=conn.address[0], + serverPort=conn.address[1], + serviceId=conn.service_id, + speculative_authenticate="speculativeAuthenticate" in orig, + ) + if publish: + assert listeners is not None + assert address is not None + listeners.publish_command_success( + duration, + published_reply, + command_name, + request_id, + address, + conn.server_connection_id, + op_id, + service_id=conn.service_id, + speculative_hello=speculative_hello, + database_name=dbname, + ) + + if client and client._encrypter and reply and decrypt_reply: + decrypted = await client._encrypter.decrypt(reply.raw_command_response()) + docs = cast( + "list[dict[str, Any]]", _decode_all_selective(decrypted, codec_options, user_fields) + ) + + return docs, reply, duration + + +async def run_bulk_write_command( + bwc: _BulkWriteContextBase, + cmd: MutableMapping[str, Any], + request_id: int, + msg: bytes, + *, + client: Optional[AsyncMongoClient[Any]], + orig: Optional[MutableMapping[str, Any]] = None, + max_doc_size: int = 0, + unacknowledged: bool = False, +) -> tuple[list[dict[str, Any]], Optional[_OpMsg], datetime.timedelta]: + """Send a bulk write batch and return ``(docs, reply, duration)``. + + :param bwc: Bulk write context supplying the connection, session, listeners, etc. + :param cmd: The encoded command document. + :param request_id: The request id of the encoded message. + :param msg: The encoded bytes to send. + :param client: The AsyncMongoClient, for ``$clusterTime`` gossip and logging. + :param orig: The original command document for the APM ``STARTED`` event; + defaults to ``cmd``. + :param max_doc_size: The largest document size in the batch, passed to ``conn.send_message``. + :param unacknowledged: When ``True``, send only and fake an ``{"ok": 1}`` reply. + """ + return await _run_command( + bwc.conn, # type: ignore[arg-type] + cmd, + bwc.db_name, + request_id, + msg, + client=client, + session=bwc.session, # type: ignore[arg-type] + listeners=bwc.listeners, + address=bwc.conn.address, # type: ignore[union-attr] + start=bwc.start_time, + codec_options=bwc.codec, + op_id=bwc.op_id, + command_name=bwc.name, + orig=orig, + max_doc_size=max_doc_size, + unacknowledged=unacknowledged, + decrypt_reply=False, + ) + + +async def run_cursor_command( + conn: AsyncConnection, + cmd: MutableMapping[str, Any], + dbname: str, + request_id: int, + msg: bytes, + *, + client: Optional[AsyncMongoClient[Any]], + session: Optional[AsyncClientSession], + listeners: Optional[_EventListeners], + address: Optional[_Address], + start: datetime.datetime, + codec_options: CodecOptions[_DocumentType], + command_name: str, + user_fields: Optional[Mapping[str, Any]] = None, + pool_opts: Optional[PoolOptions] = None, + max_doc_size: int = 0, + more_to_come: bool = False, + unpack_res: Optional[Callable[..., Any]] = None, + cursor_id: Optional[int] = None, +) -> tuple[list[dict[str, Any]], Optional[_OpMsg], datetime.timedelta]: + """Run a cursor ``find``/``getMore`` operation over ``conn``. + + :param conn: The AsyncConnection to send on. + :param cmd: The command document, used for the ``STARTED`` log/APM event. + :param dbname: The database the command runs against. + :param request_id: The request id of the encoded message. + :param msg: The encoded bytes to send (ignored when ``more_to_come``). + :param client: The AsyncMongoClient, for ``$clusterTime`` gossip and logging. + :param session: The session to update from the response. + :param listeners: The event listeners, or ``None`` to disable APM. + :param address: The (host, port) of ``conn`` for APM events. + :param start: The ``datetime`` the operation began, for duration timing. + :param codec_options: The CodecOptions used to decode the reply. + :param command_name: The command name for APM events. + :param user_fields: Response fields decoded with the codec's TypeDecoders. + :param pool_opts: PoolOptions forwarded to ``_check_command_response``. + :param max_doc_size: The largest document size, for ``conn.send_message``. + :param more_to_come: Receive only, without sending. Used for ``getMore`` on exhaust cursors. + :param unpack_res: A callable decoding the wire response; when ``None`` the + reply's own ``unpack_response`` is used. + :param cursor_id: The cursor id passed to ``unpack_res``. + """ + return await _run_command( + conn, + cmd, + dbname, + request_id, + msg, + client=client, + session=session, + listeners=listeners, + address=address, + start=start, + codec_options=codec_options, + user_fields=user_fields, + command_name=command_name, + pool_opts=pool_opts, + ensure_db=True, + max_doc_size=max_doc_size, + more_to_come=more_to_come, + unpack_res=unpack_res, + cursor_id=cursor_id, + ) + + +async def run_command( + conn: AsyncConnection, + dbname: str, + spec: MutableMapping[str, Any], + read_preference: Optional[_ServerMode], + codec_options: CodecOptions[_DocumentType], + session: Optional[AsyncClientSession], + client: Optional[AsyncMongoClient[Any]], + check: bool = True, + allowable_errors: Optional[Sequence[Union[str, int]]] = None, + address: Optional[_Address] = None, + listeners: Optional[_EventListeners] = None, + max_bson_size: Optional[int] = None, + read_concern: Optional[ReadConcern] = None, + parse_write_concern_error: bool = False, + collation: Optional[_CollationIn] = None, + compression_ctx: Union[SnappyContext, ZlibContext, ZstdContext, None] = None, + unacknowledged: bool = False, + user_fields: Optional[Mapping[str, Any]] = None, + exhaust_allowed: bool = False, + write_concern: Optional[WriteConcern] = None, +) -> _DocumentType: + """Encode and execute a command over ``conn``, or raise socket.error. + + Applies read preference, read concern, collation, ``$clusterTime``, + auto-encryption, and CSOT to ``spec``, encodes it as an OP_MSG message, + then performs the network round trip and response processing. + + :param conn: The AsyncConnection to send on. + :param dbname: The database the command runs against. + :param spec: A command document as an ordered dict type, e.g. SON. + :param read_preference: The read preference for this command. + :param codec_options: The CodecOptions used to decode the reply. + :param session: The AsyncClientSession for this command. + :param client: The AsyncMongoClient, for ``$clusterTime`` gossip and logging. + :param check: Raise OperationFailure if there are errors. + :param allowable_errors: Errors to ignore when ``check`` is True. + :param address: The (host, port) of ``conn`` for APM events. + :param listeners: The event listeners, or ``None`` to disable APM. + :param max_bson_size: The maximum encoded BSON size for this server. + :param read_concern: The read concern for this command. + :param parse_write_concern_error: Whether to parse the ``writeConcernError`` + field in the command response. + :param collation: The collation for this command. + :param compression_ctx: Optional compression context. + :param unacknowledged: True if this is an unacknowledged command. + :param user_fields: Response fields decoded with the codec's TypeDecoders, + passed to ``bson._decode_all_selective``. + :param exhaust_allowed: True if we should enable OP_MSG exhaustAllowed. + :param write_concern: The write concern for this command. Applied via CSOT. + """ + name = next(iter(spec)) + speculative_hello = False + + # Publish the original command document, perhaps with lsid and $clusterTime. + orig = spec + if read_concern and not (session and session.in_transaction): + if read_concern.level: + spec["readConcern"] = read_concern.document + if session: + session._update_read_concern(spec, conn) + if collation is not None: + spec["collation"] = collation + + publish = listeners is not None and listeners.enabled_for_commands + start = datetime.datetime.now() + if publish: + speculative_hello = _is_speculative_authenticate(name, spec) + + if compression_ctx and name.lower() in _NO_COMPRESSION: + compression_ctx = None + + if client and client._encrypter and not client._encrypter._bypass_auto_encryption: + spec = orig = await client._encrypter.encrypt(dbname, spec, codec_options) + + # Support CSOT + if client: + conn.apply_timeout(client, spec) + _csot.apply_write_concern(spec, write_concern) + + flags = _OpMsg.MORE_TO_COME if unacknowledged else 0 + flags |= _OpMsg.EXHAUST_ALLOWED if exhaust_allowed else 0 + request_id, msg, size, max_doc_size = message._op_msg( + flags, spec, dbname, read_preference, codec_options, ctx=compression_ctx + ) + # If this is an unacknowledged write then make sure the encoded doc(s) + # are small enough, otherwise rely on the server to return an error. + if unacknowledged and max_bson_size is not None and max_doc_size > max_bson_size: + message._raise_document_too_large(name, size, max_bson_size) + + if max_bson_size is not None and size > max_bson_size + message._COMMAND_OVERHEAD: + message._raise_document_too_large(name, size, max_bson_size + message._COMMAND_OVERHEAD) + docs, _, _ = await _run_command( + conn, + spec, + dbname, + request_id, + msg, + client=client, + session=session, + listeners=listeners, + address=address, + start=start, + codec_options=codec_options, + user_fields=user_fields, + orig=orig, + check=check, + allowable_errors=allowable_errors, + parse_write_concern_error=parse_write_concern_error, + speculative_hello=speculative_hello, + unacknowledged=unacknowledged, + set_conn_more_to_come=True, + ) + return docs[0] # type: ignore[return-value] diff --git a/pymongo/asynchronous/network.py b/pymongo/asynchronous/network.py deleted file mode 100644 index 16bca3e10e..0000000000 --- a/pymongo/asynchronous/network.py +++ /dev/null @@ -1,286 +0,0 @@ -# Copyright 2015-present MongoDB, Inc. -# -# Licensed under the Apache License, Version 2.0 (the "License"); -# you may not use this file except in compliance with the License. -# You may obtain a copy of the License at -# -# https://www.apache.org/licenses/LICENSE-2.0 -# -# Unless required by applicable law or agreed to in writing, software -# distributed under the License is distributed on an "AS IS" BASIS, -# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -# See the License for the specific language governing permissions and -# limitations under the License. - -"""Internal network layer helper methods.""" - -from __future__ import annotations - -import datetime -import logging -from collections.abc import Mapping, MutableMapping, Sequence -from typing import ( - TYPE_CHECKING, - Any, - Optional, - Union, - cast, -) - -from bson import _decode_all_selective -from pymongo import _csot, helpers_shared, message -from pymongo.compression_support import _NO_COMPRESSION -from pymongo.errors import ( - NotPrimaryError, - OperationFailure, -) -from pymongo.logger import _COMMAND_LOGGER, _CommandStatusMessage, _debug_log -from pymongo.message import _OpMsg -from pymongo.monitoring import _is_speculative_authenticate -from pymongo.network_layer import ( - async_receive_message, - async_sendall, -) - -if TYPE_CHECKING: - from bson import CodecOptions - from pymongo.asynchronous.client_session import AsyncClientSession - from pymongo.asynchronous.mongo_client import AsyncMongoClient - from pymongo.asynchronous.pool import AsyncConnection - from pymongo.compression_support import SnappyContext, ZlibContext, ZstdContext - from pymongo.monitoring import _EventListeners - from pymongo.read_concern import ReadConcern - from pymongo.read_preferences import _ServerMode - from pymongo.typings import _Address, _CollationIn, _DocumentOut, _DocumentType - from pymongo.write_concern import WriteConcern - -_IS_SYNC = False - - -async def command( - conn: AsyncConnection, - dbname: str, - spec: MutableMapping[str, Any], - is_mongos: bool, # noqa: ARG001 - read_preference: Optional[_ServerMode], - codec_options: CodecOptions[_DocumentType], - session: Optional[AsyncClientSession], - client: Optional[AsyncMongoClient[Any]], - check: bool = True, - allowable_errors: Optional[Sequence[Union[str, int]]] = None, - address: Optional[_Address] = None, - listeners: Optional[_EventListeners] = None, - max_bson_size: Optional[int] = None, - read_concern: Optional[ReadConcern] = None, - parse_write_concern_error: bool = False, - collation: Optional[_CollationIn] = None, - compression_ctx: Union[SnappyContext, ZlibContext, ZstdContext, None] = None, - unacknowledged: bool = False, - user_fields: Optional[Mapping[str, Any]] = None, - exhaust_allowed: bool = False, - write_concern: Optional[WriteConcern] = None, -) -> _DocumentType: - """Execute a command over the socket, or raise socket.error. - - :param conn: a AsyncConnection instance - :param dbname: name of the database on which to run the command - :param spec: a command document as an ordered dict type, eg SON. - :param is_mongos: are we connected to a mongos? - :param read_preference: a read preference - :param codec_options: a CodecOptions instance - :param session: optional AsyncClientSession instance. - :param client: optional AsyncMongoClient instance for updating $clusterTime. - :param check: raise OperationFailure if there are errors - :param allowable_errors: errors to ignore if `check` is True - :param address: the (host, port) of `conn` - :param listeners: An instance of :class:`~pymongo.monitoring.EventListeners` - :param max_bson_size: The maximum encoded bson size for this server - :param read_concern: The read concern for this command. - :param parse_write_concern_error: Whether to parse the ``writeConcernError`` - field in the command response. - :param collation: The collation for this command. - :param compression_ctx: optional compression Context. - :param unacknowledged: True if this is an unacknowledged command. - :param user_fields: Response fields that should be decoded - using the TypeDecoders from codec_options, passed to - bson._decode_all_selective. - :param exhaust_allowed: True if we should enable OP_MSG exhaustAllowed. - """ - name = next(iter(spec)) - speculative_hello = False - - # Publish the original command document, perhaps with lsid and $clusterTime. - orig = spec - if read_concern and not (session and session.in_transaction): - if read_concern.level: - spec["readConcern"] = read_concern.document - if session: - session._update_read_concern(spec, conn) - if collation is not None: - spec["collation"] = collation - - publish = listeners is not None and listeners.enabled_for_commands - start = datetime.datetime.now() - if publish: - speculative_hello = _is_speculative_authenticate(name, spec) - - if compression_ctx and name.lower() in _NO_COMPRESSION: - compression_ctx = None - - if client and client._encrypter and not client._encrypter._bypass_auto_encryption: - spec = orig = await client._encrypter.encrypt(dbname, spec, codec_options) - - # Support CSOT - if client: - conn.apply_timeout(client, spec) - _csot.apply_write_concern(spec, write_concern) - - flags = _OpMsg.MORE_TO_COME if unacknowledged else 0 - flags |= _OpMsg.EXHAUST_ALLOWED if exhaust_allowed else 0 - request_id, msg, size, max_doc_size = message._op_msg( - flags, spec, dbname, read_preference, codec_options, ctx=compression_ctx - ) - # If this is an unacknowledged write then make sure the encoded doc(s) - # are small enough, otherwise rely on the server to return an error. - if unacknowledged and max_bson_size is not None and max_doc_size > max_bson_size: - message._raise_document_too_large(name, size, max_bson_size) - - if max_bson_size is not None and size > max_bson_size + message._COMMAND_OVERHEAD: - message._raise_document_too_large(name, size, max_bson_size + message._COMMAND_OVERHEAD) - if client is not None: - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.STARTED, - clientId=client._topology_settings._topology_id, - command=spec, - commandName=next(iter(spec)), - databaseName=dbname, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - ) - if publish: - assert listeners is not None - assert address is not None - listeners.publish_command_start( - orig, - dbname, - request_id, - address, - conn.server_connection_id, - service_id=conn.service_id, - ) - - try: - await async_sendall(conn.conn.get_conn, msg) - if unacknowledged: - # Unacknowledged, fake a successful command response. - reply = None - response_doc: _DocumentOut = {"ok": 1} - else: - reply = await async_receive_message(conn, request_id) - conn.more_to_come = reply.more_to_come - unpacked_docs = reply.unpack_response( - codec_options=codec_options, user_fields=user_fields - ) - - response_doc = unpacked_docs[0] - if not conn.ready: - cluster_time = response_doc.get("$clusterTime") - if cluster_time: - conn._cluster_time = cluster_time - if client: - await client._process_response(response_doc, session) - if check: - helpers_shared._check_command_response( - response_doc, - conn.max_wire_version, - allowable_errors, - parse_write_concern_error=parse_write_concern_error, - ) - except Exception as exc: - duration = datetime.datetime.now() - start - if isinstance(exc, (NotPrimaryError, OperationFailure)): - failure: _DocumentOut = exc.details # type: ignore[assignment] - else: - failure = message._convert_exception(exc) - if client is not None: - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.FAILED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - failure=failure, - commandName=next(iter(spec)), - databaseName=dbname, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - isServerSideError=isinstance(exc, OperationFailure), - ) - if publish: - assert listeners is not None - assert address is not None - listeners.publish_command_failure( - duration, - failure, - name, - request_id, - address, - conn.server_connection_id, - service_id=conn.service_id, - database_name=dbname, - ) - raise - duration = datetime.datetime.now() - start - if client is not None: - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.SUCCEEDED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - reply=response_doc, - commandName=next(iter(spec)), - databaseName=dbname, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - speculative_authenticate="speculativeAuthenticate" in orig, - ) - if publish: - assert listeners is not None - assert address is not None - listeners.publish_command_success( - duration, - response_doc, - name, - request_id, - address, - conn.server_connection_id, - service_id=conn.service_id, - speculative_hello=speculative_hello, - database_name=dbname, - ) - - if client and client._encrypter and reply: - decrypted = await client._encrypter.decrypt(reply.raw_command_response()) - response_doc = cast( - "_DocumentOut", _decode_all_selective(decrypted, codec_options, user_fields)[0] - ) - - return response_doc # type: ignore[return-value] diff --git a/pymongo/asynchronous/pool.py b/pymongo/asynchronous/pool.py index 71b8e2bcbb..60acb93fcd 100644 --- a/pymongo/asynchronous/pool.py +++ b/pymongo/asynchronous/pool.py @@ -36,8 +36,8 @@ from bson import DEFAULT_CODEC_OPTIONS from pymongo import _csot, helpers_shared from pymongo.asynchronous.client_session import _validate_session_write_concern +from pymongo.asynchronous.command_runner import run_command from pymongo.asynchronous.helpers import _handle_reauth -from pymongo.asynchronous.network import command from pymongo.common import ( MAX_BSON_SIZE, MAX_MESSAGE_SIZE, @@ -390,15 +390,15 @@ async def command( self.send_cluster_time(spec, session, client) listeners = self.listeners if publish_events else None unacknowledged = bool(write_concern and not write_concern.acknowledged) - self._raise_if_not_writable(unacknowledged) + if unacknowledged: + self._raise_if_not_writable() try: if session is not None and session._starting_transaction: session._transaction.set_in_progress() - return await command( + return await run_command( self, dbname, spec, - self.is_mongos, read_preference, codec_options, # type: ignore[arg-type] session, @@ -451,43 +451,11 @@ async def receive_message(self, request_id: Optional[int]) -> _OpMsg: except BaseException as error: await self._raise_connection_failure(error) - def _raise_if_not_writable(self, unacknowledged: bool) -> None: - """Raise NotPrimaryError on unacknowledged write if this socket is not - writable. - """ - if unacknowledged and not self.is_writable: - # Write won't succeed, bail as if we'd received a not primary error. + def _raise_if_not_writable(self) -> None: + """Raise NotPrimaryError if this connection is not writable.""" + if not self.is_writable: raise NotPrimaryError("not primary", {"ok": 0, "errmsg": "not primary", "code": 10107}) - async def unack_write(self, msg: bytes, max_doc_size: int) -> None: - """Send unack OP_MSG. - - Can raise ConnectionFailure or InvalidDocument. - - :param msg: bytes, an OP_MSG message. - :param max_doc_size: size in bytes of the largest document in `msg`. - """ - self._raise_if_not_writable(True) - await self.send_message(msg, max_doc_size) - - async def write_command( - self, request_id: int, msg: bytes, codec_options: CodecOptions[Mapping[str, Any]] - ) -> dict[str, Any]: - """Send "insert" etc. command, returning response as a dict. - - Can raise ConnectionFailure or OperationFailure. - - :param request_id: an int. - :param msg: bytes, the command message. - """ - await self.send_message(msg, 0) - reply = await self.receive_message(request_id) - result = reply.command_response(codec_options) - - # Raises NotPrimaryError or OperationFailure. - helpers_shared._check_command_response(result, self.max_wire_version) - return result - async def authenticate(self, reauthenticate: bool = False) -> None: """Authenticate to the server if needed. diff --git a/pymongo/asynchronous/server.py b/pymongo/asynchronous/server.py index 1ca2689229..9a6984f486 100644 --- a/pymongo/asynchronous/server.py +++ b/pymongo/asynchronous/server.py @@ -27,18 +27,14 @@ Union, ) -from bson import _decode_all_selective +from pymongo.asynchronous.command_runner import run_cursor_command from pymongo.asynchronous.helpers import _handle_reauth -from pymongo.errors import NotPrimaryError, OperationFailure -from pymongo.helpers_shared import _check_command_response from pymongo.logger import ( - _COMMAND_LOGGER, _SDAM_LOGGER, - _CommandStatusMessage, _debug_log, _SDAMStatusMessage, ) -from pymongo.message import _convert_exception, _GetMore, _OpMsg, _Query +from pymongo.message import _GetMore, _OpMsg, _Query from pymongo.response import PinnedResponse, Response if TYPE_CHECKING: @@ -159,152 +155,42 @@ async def run_operation( :param client: An AsyncMongoClient instance. """ assert listeners is not None - publish = listeners.enabled_for_commands start = datetime.now() use_cmd = operation.use_command(conn) - more_to_come = operation.conn_mgr and operation.conn_mgr.more_to_come + more_to_come = bool(operation.conn_mgr and operation.conn_mgr.more_to_come) cmd, dbn = await self.operation_to_command(operation, conn, use_cmd) if more_to_come: request_id = 0 + data = b"" + max_doc_size = 0 else: message = operation.get_message(read_preference, conn, use_cmd) request_id, data, max_doc_size = self._split_message(message) - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.STARTED, - clientId=client._topology_settings._topology_id, - command=cmd, - commandName=next(iter(cmd)), - databaseName=dbn, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - ) - - if publish: - if "$db" not in cmd: - cmd["$db"] = dbn - assert listeners is not None - listeners.publish_command_start( - cmd, - dbn, - request_id, - conn.address, - conn.server_connection_id, - service_id=conn.service_id, - ) - - try: - if more_to_come: - reply = await conn.receive_message(None) - else: - if operation.session is not None and operation.session._starting_transaction: - operation.session._transaction.set_in_progress() - await conn.send_message(data, max_doc_size) - reply = await conn.receive_message(request_id) - - # Unpack and check for command errors. - if use_cmd: - user_fields = _CURSOR_DOC_FIELDS - legacy_response = False - else: - user_fields = None - legacy_response = True - docs = unpack_res( - reply, - operation.cursor_id, - operation.codec_options, - legacy_response=legacy_response, - user_fields=user_fields, - ) - if use_cmd: - first = docs[0] - await operation.client._process_response(first, operation.session) # type: ignore[misc, arg-type] - _check_command_response(first, conn.max_wire_version, pool_opts=conn.opts) # type:ignore[has-type] - except Exception as exc: - duration = datetime.now() - start - if isinstance(exc, (NotPrimaryError, OperationFailure)): - failure: _DocumentOut = exc.details # type: ignore[assignment] - else: - failure = _convert_exception(exc) - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.FAILED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - failure=failure, - commandName=next(iter(cmd)), - databaseName=dbn, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - isServerSideError=isinstance(exc, OperationFailure), - ) - if publish: - assert listeners is not None - listeners.publish_command_failure( - duration, - failure, - operation.name, - request_id, - conn.address, - conn.server_connection_id, - service_id=conn.service_id, - database_name=dbn, - ) - raise - duration = datetime.now() - start - # Must publish in find / getMore / explain command response - # format. - res = docs[0] - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.SUCCEEDED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - reply=res, - commandName=next(iter(cmd)), - databaseName=dbn, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - ) - if publish: - assert listeners is not None - listeners.publish_command_success( - duration, - res, - operation.name, - request_id, - conn.address, - conn.server_connection_id, - service_id=conn.service_id, - database_name=dbn, - ) - - # Decrypt response. - client = operation.client # type: ignore[assignment] - if client and client._encrypter: - if use_cmd: - decrypted = await client._encrypter.decrypt(reply.raw_command_response()) - docs = _decode_all_selective(decrypted, operation.codec_options, user_fields) + user_fields = _CURSOR_DOC_FIELDS if use_cmd else None + + docs, reply, duration = await run_cursor_command( + conn, + cmd, + dbn, + request_id, + data, + client=client, + session=operation.session, # type: ignore[arg-type] + listeners=listeners, + address=conn.address, + start=start, + codec_options=operation.codec_options, + user_fields=user_fields, + command_name=operation.name, + pool_opts=conn.opts, + max_doc_size=max_doc_size, + more_to_come=more_to_come, + unpack_res=unpack_res, + cursor_id=operation.cursor_id, + ) + assert reply is not None response: Response @@ -326,7 +212,7 @@ async def run_operation( duration=duration, request_id=request_id, from_command=use_cmd, - docs=docs, + docs=docs, # type: ignore[arg-type] more_to_come=more_to_come, ) else: @@ -336,7 +222,7 @@ async def run_operation( duration=duration, request_id=request_id, from_command=use_cmd, - docs=docs, + docs=docs, # type: ignore[arg-type] ) return response diff --git a/pymongo/message.py b/pymongo/message.py index cb1d9a4184..bcd2810895 100644 --- a/pymongo/message.py +++ b/pymongo/message.py @@ -68,7 +68,6 @@ _AgnosticClientSession, _AgnosticConnection, _AgnosticMongoClient, - _DocumentOut, ) @@ -145,34 +144,6 @@ def _convert_client_bulk_exception(exception: Exception) -> dict[str, Any]: } -def _convert_write_result( - operation: str, command: Mapping[str, Any], result: Mapping[str, Any] -) -> dict[str, Any]: - """Convert a legacy write result to write command format.""" - # Based on _merge_legacy from bulk.py - affected = result.get("n", 0) - res = {"ok": 1, "n": affected} - errmsg = result.get("errmsg", result.get("err", "")) - if errmsg: - # The write was successful on at least the primary so don't return. - if result.get("wtimeout"): - res["writeConcernError"] = {"errmsg": errmsg, "code": 64, "errInfo": {"wtimeout": True}} - else: - # The write failed. - error = {"index": 0, "code": result.get("code", 8), "errmsg": errmsg} - if "errInfo" in result: - error["errInfo"] = result["errInfo"] - res["writeErrors"] = [error] - return res - if operation == "insert": - # GLE result for insert is always 0 in most MongoDB versions. - res["n"] = len(command["documents"]) - elif operation == "update": - if "upserted" in result: - res["upserted"] = [{"index": 0, "_id": result["upserted"]}] - return res - - _OPTIONS = { "tailable": 2, "oplogReplay": 8, @@ -479,7 +450,6 @@ class _BulkWriteContextBase: "name", "op_id", "op_type", - "publish", "session", "start_time", ) @@ -499,7 +469,6 @@ def __init__( self.conn = conn self.op_id = operation_id self.listeners = listeners - self.publish = listeners.enabled_for_commands self.name = cmd_name self.field = _FIELD_MAP[self.name] self.start_time = datetime.datetime.now() @@ -531,34 +500,6 @@ def max_split_size(self) -> int: """The maximum size of a BSON command before batch splitting.""" return self.max_bson_size - def _succeed(self, request_id: int, reply: _DocumentOut, duration: datetime.timedelta) -> None: - """Publish a CommandSucceededEvent.""" - self.listeners.publish_command_success( - duration, - reply, - self.name, - request_id, - self.conn.address, - self.conn.server_connection_id, - self.op_id, - self.conn.service_id, - database_name=self.db_name, - ) - - def _fail(self, request_id: int, failure: _DocumentOut, duration: datetime.timedelta) -> None: - """Publish a CommandFailedEvent.""" - self.listeners.publish_command_failure( - duration, - failure, - self.name, - request_id, - self.conn.address, - self.conn.server_connection_id, - self.op_id, - self.conn.service_id, - database_name=self.db_name, - ) - class _BulkWriteContext(_BulkWriteContextBase): """A wrapper around AsyncConnection/Connection for use with the collection-level bulk write API.""" @@ -598,22 +539,6 @@ def batch_command( raise InvalidOperation("cannot do an empty bulk write") return request_id, msg, to_send - def _start( - self, cmd: MutableMapping[str, Any], request_id: int, docs: list[Mapping[str, Any]] - ) -> MutableMapping[str, Any]: - """Publish a CommandStartedEvent.""" - cmd[self.field] = docs - self.listeners.publish_command_start( - cmd, - self.db_name, - request_id, - self.conn.address, - self.conn.server_connection_id, - self.op_id, - self.conn.service_id, - ) - return cmd - class _EncryptedBulkWriteContext(_BulkWriteContext): __slots__ = () @@ -858,27 +783,6 @@ def batch_command( raise InvalidOperation("cannot do an empty bulk write") return request_id, msg, to_send_ops, to_send_ns - def _start( - self, - cmd: MutableMapping[str, Any], - request_id: int, - op_docs: list[Mapping[str, Any]], - ns_docs: list[Mapping[str, Any]], - ) -> MutableMapping[str, Any]: - """Publish a CommandStartedEvent.""" - cmd["ops"] = op_docs - cmd["nsInfo"] = ns_docs - self.listeners.publish_command_start( - cmd, - self.db_name, - request_id, - self.conn.address, - self.conn.server_connection_id, - self.op_id, - self.conn.service_id, - ) - return cmd - _OP_MSG_OVERHEAD = 1000 diff --git a/pymongo/synchronous/bulk.py b/pymongo/synchronous/bulk.py index 5dfcec27c5..36081fe222 100644 --- a/pymongo/synchronous/bulk.py +++ b/pymongo/synchronous/bulk.py @@ -20,8 +20,6 @@ from __future__ import annotations import copy -import datetime -import logging from collections.abc import Iterator, Mapping, MutableMapping from itertools import islice from typing import ( @@ -49,25 +47,21 @@ from pymongo.errors import ( ConfigurationError, InvalidOperation, - NotPrimaryError, OperationFailure, ) from pymongo.helpers_shared import _RETRYABLE_ERROR_CODES -from pymongo.logger import _COMMAND_LOGGER, _CommandStatusMessage, _debug_log from pymongo.message import ( _DELETE, _INSERT, _UPDATE, _BulkWriteContext, - _convert_exception, - _convert_write_result, _EncryptedBulkWriteContext, _randint, ) from pymongo.read_preferences import ReadPreference -from pymongo.synchronous.client_session import ( - ClientSession, - _validate_session_write_concern, +from pymongo.synchronous.client_session import ClientSession, _validate_session_write_concern +from pymongo.synchronous.command_runner import ( + run_bulk_write_command, ) from pymongo.synchronous.helpers import _handle_reauth from pymongo.write_concern import WriteConcern @@ -251,83 +245,16 @@ def write_command( docs: list[Mapping[str, Any]], client: MongoClient[Any], ) -> dict[str, Any]: - """A proxy for SocketInfo.write_command that handles event publishing.""" + """Run a batch write command, returning the response as a dict.""" cmd[bwc.field] = docs - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.STARTED, - clientId=client._topology_settings._topology_id, - command=cmd, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - bwc._start(cmd, request_id, docs) - try: - if bwc.session is not None and bwc.session._starting_transaction: - bwc.session._transaction.set_in_progress() - reply = bwc.conn.write_command(request_id, msg, bwc.codec) # type: ignore[misc] - duration = datetime.datetime.now() - bwc.start_time - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.SUCCEEDED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - reply=reply, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - bwc._succeed(request_id, reply, duration) # type: ignore[arg-type] - client._process_response(reply, bwc.session) # type: ignore[arg-type] - except Exception as exc: - duration = datetime.datetime.now() - bwc.start_time - if isinstance(exc, (NotPrimaryError, OperationFailure)): - failure: _DocumentOut = exc.details # type: ignore[assignment] - else: - failure = _convert_exception(exc) - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.FAILED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - failure=failure, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - isServerSideError=isinstance(exc, OperationFailure), - ) - - if bwc.publish: - bwc._fail(request_id, failure, duration) - # Process the response from the server. - if isinstance(exc, (NotPrimaryError, OperationFailure)): - client._process_response(exc.details, bwc.session) # type: ignore[arg-type] - raise - return reply # type: ignore[return-value] + result_docs, _, _ = run_bulk_write_command( + bwc, + cmd, + request_id, + msg, + client=client, + ) + return result_docs[0] def unack_write( self, @@ -339,83 +266,23 @@ def unack_write( docs: list[Mapping[str, Any]], client: MongoClient[Any], ) -> Optional[Mapping[str, Any]]: - """A proxy for Connection.unack_write that handles event publishing.""" - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.STARTED, - clientId=client._topology_settings._topology_id, - command=cmd, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - cmd = bwc._start(cmd, request_id, docs) - try: - result = bwc.conn.unack_write(msg, max_doc_size) # type: ignore[func-returns-value, misc, override] - duration = datetime.datetime.now() - bwc.start_time - if result is not None: - reply = _convert_write_result(bwc.name, cmd, result) # type: ignore[arg-type] - else: - # Comply with APM spec. - reply = {"ok": 1} - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.SUCCEEDED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - reply=reply, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - bwc._succeed(request_id, reply, duration) - except Exception as exc: - duration = datetime.datetime.now() - bwc.start_time - if isinstance(exc, OperationFailure): - failure: _DocumentOut = _convert_write_result(bwc.name, cmd, exc.details) # type: ignore[arg-type] - elif isinstance(exc, NotPrimaryError): - failure = exc.details # type: ignore[assignment] - else: - failure = _convert_exception(exc) - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.FAILED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - failure=failure, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - isServerSideError=isinstance(exc, OperationFailure), - ) - if bwc.publish: - assert bwc.start_time is not None - bwc._fail(request_id, failure, duration) - raise - return result # type: ignore[return-value] + """Send an unacknowledged batch write command.""" + # Historically the STARTED log omits the documents while the published + # CommandStartedEvent includes them, so log ``cmd`` but publish a copy + # carrying the ``docs`` field. + published = dict(cmd) + published[bwc.field] = docs + run_bulk_write_command( + bwc, + cmd, + request_id, + msg, + client=client, + orig=published, + max_doc_size=max_doc_size, + unacknowledged=True, + ) + return None def _execute_batch_unack( self, @@ -487,7 +354,7 @@ def _execute_command( run = self.current_run # Connection.command validates the session, but we use - # Connection.write_command + # run_bulk_write_command. conn.validate_session(client, session) last_run = False diff --git a/pymongo/synchronous/client_bulk.py b/pymongo/synchronous/client_bulk.py index 600b20a761..4cf1d9dbb0 100644 --- a/pymongo/synchronous/client_bulk.py +++ b/pymongo/synchronous/client_bulk.py @@ -20,8 +20,6 @@ from __future__ import annotations import copy -import datetime -import logging from collections.abc import Mapping, MutableMapping from itertools import islice from typing import ( @@ -40,6 +38,9 @@ ) from pymongo.synchronous.collection import Collection from pymongo.synchronous.command_cursor import CommandCursor +from pymongo.synchronous.command_runner import ( + run_bulk_write_command, +) from pymongo.synchronous.database import Database from pymongo.synchronous.helpers import _handle_reauth @@ -65,12 +66,9 @@ WaitQueueTimeoutError, ) from pymongo.helpers_shared import _RETRYABLE_ERROR_CODES -from pymongo.logger import _COMMAND_LOGGER, _CommandStatusMessage, _debug_log from pymongo.message import ( _ClientBulkWriteContext, _convert_client_bulk_exception, - _convert_exception, - _convert_write_result, _randint, ) from pymongo.read_preferences import ReadPreference @@ -238,87 +236,21 @@ def write_command( ns_docs: list[Mapping[str, Any]], client: MongoClient[Any], ) -> dict[str, Any]: - """A proxy for Connection.write_command that handles event publishing.""" + """Run a client-level batch write command, returning the response as a dict.""" cmd["ops"] = op_docs cmd["nsInfo"] = ns_docs - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.STARTED, - clientId=client._topology_settings._topology_id, - command=cmd, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - bwc._start(cmd, request_id, op_docs, ns_docs) try: - if bwc.session is not None and bwc.session._starting_transaction: - bwc.session._transaction.set_in_progress() - reply = bwc.conn.write_command(request_id, msg, bwc.codec) # type: ignore[misc, arg-type] - duration = datetime.datetime.now() - bwc.start_time - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.SUCCEEDED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - reply=reply, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - bwc._succeed(request_id, reply, duration) # type: ignore[arg-type] - # Process the response from the server. - self.client._process_response(reply, bwc.session) # type: ignore[arg-type] + result_docs, _, _ = run_bulk_write_command( + bwc, + cmd, + request_id, + msg, # type: ignore[arg-type] + client=client, + ) + reply = result_docs[0] except Exception as exc: - duration = datetime.datetime.now() - bwc.start_time - if isinstance(exc, (NotPrimaryError, OperationFailure)): - failure: _DocumentOut = exc.details # type: ignore[assignment] - else: - failure = _convert_exception(exc) - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.FAILED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - failure=failure, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - isServerSideError=isinstance(exc, OperationFailure), - ) - - if bwc.publish: - bwc._fail(request_id, failure, duration) # Top-level error will be embedded in ClientBulkWriteException. reply = {"error": exc} - # Process the response from the server. - if isinstance(exc, OperationFailure): - self.client._process_response(exc.details, bwc.session) # type: ignore[arg-type] - else: - self.client._process_response({}, bwc.session) # type: ignore[arg-type] return reply # type: ignore[return-value] def unack_write( @@ -331,81 +263,26 @@ def unack_write( ns_docs: list[Mapping[str, Any]], client: MongoClient[Any], ) -> Optional[Mapping[str, Any]]: - """A proxy for Connection.unack_write that handles event publishing.""" - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.STARTED, - clientId=client._topology_settings._topology_id, - command=cmd, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - cmd = bwc._start(cmd, request_id, op_docs, ns_docs) + """Send an unacknowledged client-level batch write command.""" + # Historically the STARTED log omits the ops/nsInfo while the published + # CommandStartedEvent includes them, so log ``cmd`` but publish a copy + # carrying those fields. + published = dict(cmd) + published["ops"] = op_docs + published["nsInfo"] = ns_docs try: - result = bwc.conn.unack_write(msg, bwc.max_bson_size) # type: ignore[func-returns-value, misc, override] - duration = datetime.datetime.now() - bwc.start_time - if result is not None: - reply = _convert_write_result(bwc.name, cmd, result) # type: ignore[arg-type] - else: - # Comply with APM spec. - reply = {"ok": 1} - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.SUCCEEDED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - reply=reply, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - ) - if bwc.publish: - bwc._succeed(request_id, reply, duration) + result_docs, _, _ = run_bulk_write_command( + bwc, + cmd, + request_id, + msg, + client=client, + orig=published, + max_doc_size=bwc.max_bson_size, + unacknowledged=True, + ) + reply: Mapping[str, Any] = result_docs[0] except Exception as exc: - duration = datetime.datetime.now() - bwc.start_time - if isinstance(exc, OperationFailure): - failure: _DocumentOut = _convert_write_result(bwc.name, cmd, exc.details) # type: ignore[arg-type] - elif isinstance(exc, NotPrimaryError): - failure = exc.details # type: ignore[assignment] - else: - failure = _convert_exception(exc) - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.FAILED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - failure=failure, - commandName=next(iter(cmd)), - databaseName=bwc.db_name, - requestId=request_id, - operationId=request_id, - driverConnectionId=bwc.conn.id, - serverConnectionId=bwc.conn.server_connection_id, - serverHost=bwc.conn.address[0], - serverPort=bwc.conn.address[1], - serviceId=bwc.conn.service_id, - isServerSideError=isinstance(exc, OperationFailure), - ) - if bwc.publish: - assert bwc.start_time is not None - bwc._fail(request_id, failure, duration) # Top-level error will be embedded in ClientBulkWriteException. reply = {"error": exc} return reply @@ -502,7 +379,7 @@ def _execute_command( listeners = self.client._event_listeners # Connection.command validates the session, but we use - # Connection.write_command + # run_bulk_write_command. conn.validate_session(self.client, session) bwc = self.bulk_ctx_class( diff --git a/pymongo/synchronous/command_runner.py b/pymongo/synchronous/command_runner.py new file mode 100644 index 0000000000..7402451c7c --- /dev/null +++ b/pymongo/synchronous/command_runner.py @@ -0,0 +1,544 @@ +# Copyright 2015-present MongoDB, Inc. +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# https://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +"""Encoding and execution of commands over a connection (previously ``network.py``). + +Three public entry points each wrap the private :func:`_run_command`: + +- :func:`run_command` — the standard entry point used by ``pool.py``. Applies + read concern, collation, ``$clusterTime``, compression, auto-encryption, and + CSOT to a raw spec dict, encodes it as OP_MSG, then delegates to + :func:`_run_command`. +- :func:`run_bulk_write_command` — collection-level and client-level bulk write + batches. Pre-encrypted, so decryption is skipped. Callers: ``bulk.py``, + ``client_bulk.py``. +- :func:`run_cursor_command` — cursor ``find``/``getMore`` operations with + exhaust-cursor handling. Caller: ``server.py``. + +:func:`_run_command` owns the entire shared skeleton: command logging, APM +event publishing, ``send``/``receive``, ``$clusterTime`` gossip, +``_process_response``, ``_check_command_response``, failure conversion, and +auto-encryption decryption. Each public wrapper hardcodes the flags for its +command type so callers only pass what varies. +""" + +from __future__ import annotations + +import datetime +import logging +from collections.abc import Mapping, MutableMapping, Sequence +from typing import ( + TYPE_CHECKING, + Any, + Callable, + Optional, + Union, + cast, +) + +from bson import _decode_all_selective +from pymongo import _csot, helpers_shared, message +from pymongo.compression_support import _NO_COMPRESSION +from pymongo.errors import NotPrimaryError, OperationFailure +from pymongo.logger import _COMMAND_LOGGER, _CommandStatusMessage, _debug_log +from pymongo.message import _BulkWriteContextBase, _convert_exception, _OpMsg +from pymongo.monitoring import _is_speculative_authenticate + +if TYPE_CHECKING: + from bson import CodecOptions + from pymongo.compression_support import SnappyContext, ZlibContext, ZstdContext + from pymongo.monitoring import _EventListeners + from pymongo.pool_options import PoolOptions + from pymongo.read_concern import ReadConcern + from pymongo.read_preferences import _ServerMode + from pymongo.synchronous.client_session import ClientSession + from pymongo.synchronous.mongo_client import MongoClient + from pymongo.synchronous.pool import Connection + from pymongo.typings import _Address, _CollationIn, _DocumentOut, _DocumentType + from pymongo.write_concern import WriteConcern + +_IS_SYNC = True + + +def _run_command( + conn: Connection, + cmd: MutableMapping[str, Any], + dbname: str, + request_id: int, + msg: bytes, + *, + client: Optional[MongoClient[Any]], + session: Optional[ClientSession], + listeners: Optional[_EventListeners], + address: Optional[_Address], + start: datetime.datetime, + codec_options: CodecOptions[_DocumentType], + user_fields: Optional[Mapping[str, Any]] = None, + orig: Optional[MutableMapping[str, Any]] = None, + op_id: Optional[int] = None, + command_name: Optional[str] = None, + check: bool = True, + allowable_errors: Optional[Sequence[Union[str, int]]] = None, + parse_write_concern_error: bool = False, + pool_opts: Optional[PoolOptions] = None, + unacknowledged: bool = False, + speculative_hello: bool = False, + ensure_db: bool = False, + decrypt_reply: bool = True, + max_doc_size: int = 0, + more_to_come: bool = False, + set_conn_more_to_come: bool = False, + unpack_res: Optional[Callable[..., Any]] = None, + cursor_id: Optional[int] = None, +) -> tuple[list[dict[str, Any]], Optional[_OpMsg], datetime.timedelta]: + """Send ``msg`` over ``conn`` and return ``(docs, reply, duration)``. + + Private shared implementation. Should not be called directly outside this module. Use :func:`run_command`, :func:`run_bulk_write_command`, or :func:`run_cursor_command` instead. + + Publishes the + ``STARTED``/``SUCCEEDED``/``FAILED`` command log and APM events, performs + the network round trip, gossips ``$clusterTime``, runs + ``client._process_response`` and ``_check_command_response``, and decrypts + the reply when auto-encryption is enabled. + + :param conn: The Connection to send on. + :param cmd: The command document, used for the ``STARTED`` log/APM event. + :param dbname: The database the command runs against. + :param request_id: The request id of the encoded message (``0`` when + ``more_to_come`` and no message is sent). + :param msg: The encoded bytes to send (ignored when ``more_to_come``). + :param client: The MongoClient, for ``$clusterTime`` gossip, logging, + and decryption. ``None`` disables those steps (e.g. during handshake). + :param session: The session to update from the response. + :param listeners: The event listeners, or ``None`` to disable APM. + :param address: The (host, port) of ``conn`` for APM events. + :param start: The ``datetime`` the operation began, for duration timing. + :param codec_options: The CodecOptions used to decode the reply. + :param user_fields: Response fields decoded with the codec's TypeDecoders. + :param orig: The command document published in the ``STARTED`` APM event; + defaults to ``cmd`` (differs only when the wire command was mutated, + e.g. with a read preference or after encryption). + :param op_id: The APM operation id; defaults to ``request_id``. + :param command_name: The command name for the ``SUCCEEDED``/``FAILED`` APM + events; defaults to the first key of ``cmd``. + :param check: Raise OperationFailure on a command error. + :param allowable_errors: Errors to ignore when ``check`` is True. + :param parse_write_concern_error: Parse the ``writeConcernError`` field. + :param pool_opts: PoolOptions forwarded to ``_check_command_response`` (the + cursor path uses this in place of ``allowable_errors``). + :param unacknowledged: True for an unacknowledged write: send only and fake + an ``{"ok": 1}`` reply. + :param speculative_hello: True if the command carried speculative auth, for + APM redaction. + :param ensure_db: Add ``$db`` to the published command if missing (cursor + path), after the ``STARTED`` log has been emitted. + :param decrypt_reply: Decrypt the reply when auto-encryption is enabled; + the bulk paths pass False (their commands are encrypted up front). + :param max_doc_size: The largest document size, for ``conn.send_message``. + :param more_to_come: Receive only, without sending (exhaust ``getMore``). + :param set_conn_more_to_come: Store ``reply.more_to_come`` on ``conn`` (the + network/streaming-monitor path); the cursor path manages exhaust + separately and must leave ``conn.more_to_come`` untouched. + :param unpack_res: A callable decoding the wire response (cursor path); when + ``None`` the reply's own ``unpack_response`` is used. + :param cursor_id: The cursor id passed to ``unpack_res``. + """ + name = next(iter(cmd)) + if command_name is None: + command_name = name + if orig is None: + orig = cmd + publish = listeners is not None and listeners.enabled_for_commands + + if client is not None and _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): + _debug_log( + _COMMAND_LOGGER, + message=_CommandStatusMessage.STARTED, + clientId=client._topology_settings._topology_id, + command=cmd, + commandName=name, + databaseName=dbname, + requestId=request_id, + operationId=request_id, + driverConnectionId=conn.id, + serverConnectionId=conn.server_connection_id, + serverHost=conn.address[0], + serverPort=conn.address[1], + serviceId=conn.service_id, + ) + if publish: + assert listeners is not None + assert address is not None + if ensure_db and "$db" not in orig: + orig["$db"] = dbname + listeners.publish_command_start( + orig, + dbname, + request_id, + address, + conn.server_connection_id, + op_id, + service_id=conn.service_id, + ) + + reply: Optional[_OpMsg] = None + docs: list[dict[str, Any]] = [{"ok": 1}] + try: + if more_to_come: + reply = conn.receive_message(None) + else: + if unacknowledged: + conn._raise_if_not_writable() + elif session is not None and session._starting_transaction: + session._transaction.set_in_progress() + conn.send_message(msg, max_doc_size) + if not unacknowledged: + reply = conn.receive_message(request_id) + + if reply: + if set_conn_more_to_come: + conn.more_to_come = reply.more_to_come + if unpack_res is not None: + docs = unpack_res( + reply, + cursor_id, + codec_options, + user_fields=user_fields, + ) + else: + docs = reply.unpack_response(codec_options=codec_options, user_fields=user_fields) + response_doc = docs[0] + if not conn.ready: + cluster_time = response_doc.get("$clusterTime") + if cluster_time: + conn._cluster_time = cluster_time + if client: + client._process_response(response_doc, session) + if check: + helpers_shared._check_command_response( + response_doc, + conn.max_wire_version, + allowable_errors, + parse_write_concern_error=parse_write_concern_error, + pool_opts=pool_opts, + ) + except Exception as exc: + duration = datetime.datetime.now() - start + if isinstance(exc, (NotPrimaryError, OperationFailure)): + failure: _DocumentOut = exc.details # type: ignore[assignment] + else: + failure = _convert_exception(exc) + if client is not None and _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): + _debug_log( + _COMMAND_LOGGER, + message=_CommandStatusMessage.FAILED, + clientId=client._topology_settings._topology_id, + durationMS=duration, + failure=failure, + commandName=name, + databaseName=dbname, + requestId=request_id, + operationId=request_id, + driverConnectionId=conn.id, + serverConnectionId=conn.server_connection_id, + serverHost=conn.address[0], + serverPort=conn.address[1], + serviceId=conn.service_id, + isServerSideError=isinstance(exc, OperationFailure), + ) + if publish: + assert listeners is not None + assert address is not None + listeners.publish_command_failure( + duration, + failure, + command_name, + request_id, + address, + conn.server_connection_id, + op_id, + service_id=conn.service_id, + database_name=dbname, + ) + raise + + duration = datetime.datetime.now() - start + published_reply = docs[0] + if client is not None and _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): + _debug_log( + _COMMAND_LOGGER, + message=_CommandStatusMessage.SUCCEEDED, + clientId=client._topology_settings._topology_id, + durationMS=duration, + reply=published_reply, + commandName=name, + databaseName=dbname, + requestId=request_id, + operationId=request_id, + driverConnectionId=conn.id, + serverConnectionId=conn.server_connection_id, + serverHost=conn.address[0], + serverPort=conn.address[1], + serviceId=conn.service_id, + speculative_authenticate="speculativeAuthenticate" in orig, + ) + if publish: + assert listeners is not None + assert address is not None + listeners.publish_command_success( + duration, + published_reply, + command_name, + request_id, + address, + conn.server_connection_id, + op_id, + service_id=conn.service_id, + speculative_hello=speculative_hello, + database_name=dbname, + ) + + if client and client._encrypter and reply and decrypt_reply: + decrypted = client._encrypter.decrypt(reply.raw_command_response()) + docs = cast( + "list[dict[str, Any]]", _decode_all_selective(decrypted, codec_options, user_fields) + ) + + return docs, reply, duration + + +def run_bulk_write_command( + bwc: _BulkWriteContextBase, + cmd: MutableMapping[str, Any], + request_id: int, + msg: bytes, + *, + client: Optional[MongoClient[Any]], + orig: Optional[MutableMapping[str, Any]] = None, + max_doc_size: int = 0, + unacknowledged: bool = False, +) -> tuple[list[dict[str, Any]], Optional[_OpMsg], datetime.timedelta]: + """Send a bulk write batch and return ``(docs, reply, duration)``. + + :param bwc: Bulk write context supplying the connection, session, listeners, etc. + :param cmd: The encoded command document. + :param request_id: The request id of the encoded message. + :param msg: The encoded bytes to send. + :param client: The MongoClient, for ``$clusterTime`` gossip and logging. + :param orig: The original command document for the APM ``STARTED`` event; + defaults to ``cmd``. + :param max_doc_size: The largest document size in the batch, passed to ``conn.send_message``. + :param unacknowledged: When ``True``, send only and fake an ``{"ok": 1}`` reply. + """ + return _run_command( + bwc.conn, # type: ignore[arg-type] + cmd, + bwc.db_name, + request_id, + msg, + client=client, + session=bwc.session, # type: ignore[arg-type] + listeners=bwc.listeners, + address=bwc.conn.address, # type: ignore[union-attr] + start=bwc.start_time, + codec_options=bwc.codec, + op_id=bwc.op_id, + command_name=bwc.name, + orig=orig, + max_doc_size=max_doc_size, + unacknowledged=unacknowledged, + decrypt_reply=False, + ) + + +def run_cursor_command( + conn: Connection, + cmd: MutableMapping[str, Any], + dbname: str, + request_id: int, + msg: bytes, + *, + client: Optional[MongoClient[Any]], + session: Optional[ClientSession], + listeners: Optional[_EventListeners], + address: Optional[_Address], + start: datetime.datetime, + codec_options: CodecOptions[_DocumentType], + command_name: str, + user_fields: Optional[Mapping[str, Any]] = None, + pool_opts: Optional[PoolOptions] = None, + max_doc_size: int = 0, + more_to_come: bool = False, + unpack_res: Optional[Callable[..., Any]] = None, + cursor_id: Optional[int] = None, +) -> tuple[list[dict[str, Any]], Optional[_OpMsg], datetime.timedelta]: + """Run a cursor ``find``/``getMore`` operation over ``conn``. + + :param conn: The Connection to send on. + :param cmd: The command document, used for the ``STARTED`` log/APM event. + :param dbname: The database the command runs against. + :param request_id: The request id of the encoded message. + :param msg: The encoded bytes to send (ignored when ``more_to_come``). + :param client: The MongoClient, for ``$clusterTime`` gossip and logging. + :param session: The session to update from the response. + :param listeners: The event listeners, or ``None`` to disable APM. + :param address: The (host, port) of ``conn`` for APM events. + :param start: The ``datetime`` the operation began, for duration timing. + :param codec_options: The CodecOptions used to decode the reply. + :param command_name: The command name for APM events. + :param user_fields: Response fields decoded with the codec's TypeDecoders. + :param pool_opts: PoolOptions forwarded to ``_check_command_response``. + :param max_doc_size: The largest document size, for ``conn.send_message``. + :param more_to_come: Receive only, without sending. Used for ``getMore`` on exhaust cursors. + :param unpack_res: A callable decoding the wire response; when ``None`` the + reply's own ``unpack_response`` is used. + :param cursor_id: The cursor id passed to ``unpack_res``. + """ + return _run_command( + conn, + cmd, + dbname, + request_id, + msg, + client=client, + session=session, + listeners=listeners, + address=address, + start=start, + codec_options=codec_options, + user_fields=user_fields, + command_name=command_name, + pool_opts=pool_opts, + ensure_db=True, + max_doc_size=max_doc_size, + more_to_come=more_to_come, + unpack_res=unpack_res, + cursor_id=cursor_id, + ) + + +def run_command( + conn: Connection, + dbname: str, + spec: MutableMapping[str, Any], + read_preference: Optional[_ServerMode], + codec_options: CodecOptions[_DocumentType], + session: Optional[ClientSession], + client: Optional[MongoClient[Any]], + check: bool = True, + allowable_errors: Optional[Sequence[Union[str, int]]] = None, + address: Optional[_Address] = None, + listeners: Optional[_EventListeners] = None, + max_bson_size: Optional[int] = None, + read_concern: Optional[ReadConcern] = None, + parse_write_concern_error: bool = False, + collation: Optional[_CollationIn] = None, + compression_ctx: Union[SnappyContext, ZlibContext, ZstdContext, None] = None, + unacknowledged: bool = False, + user_fields: Optional[Mapping[str, Any]] = None, + exhaust_allowed: bool = False, + write_concern: Optional[WriteConcern] = None, +) -> _DocumentType: + """Encode and execute a command over ``conn``, or raise socket.error. + + Applies read preference, read concern, collation, ``$clusterTime``, + auto-encryption, and CSOT to ``spec``, encodes it as an OP_MSG message, + then performs the network round trip and response processing. + + :param conn: The Connection to send on. + :param dbname: The database the command runs against. + :param spec: A command document as an ordered dict type, e.g. SON. + :param read_preference: The read preference for this command. + :param codec_options: The CodecOptions used to decode the reply. + :param session: The ClientSession for this command. + :param client: The MongoClient, for ``$clusterTime`` gossip and logging. + :param check: Raise OperationFailure if there are errors. + :param allowable_errors: Errors to ignore when ``check`` is True. + :param address: The (host, port) of ``conn`` for APM events. + :param listeners: The event listeners, or ``None`` to disable APM. + :param max_bson_size: The maximum encoded BSON size for this server. + :param read_concern: The read concern for this command. + :param parse_write_concern_error: Whether to parse the ``writeConcernError`` + field in the command response. + :param collation: The collation for this command. + :param compression_ctx: Optional compression context. + :param unacknowledged: True if this is an unacknowledged command. + :param user_fields: Response fields decoded with the codec's TypeDecoders, + passed to ``bson._decode_all_selective``. + :param exhaust_allowed: True if we should enable OP_MSG exhaustAllowed. + :param write_concern: The write concern for this command. Applied via CSOT. + """ + name = next(iter(spec)) + speculative_hello = False + + # Publish the original command document, perhaps with lsid and $clusterTime. + orig = spec + if read_concern and not (session and session.in_transaction): + if read_concern.level: + spec["readConcern"] = read_concern.document + if session: + session._update_read_concern(spec, conn) + if collation is not None: + spec["collation"] = collation + + publish = listeners is not None and listeners.enabled_for_commands + start = datetime.datetime.now() + if publish: + speculative_hello = _is_speculative_authenticate(name, spec) + + if compression_ctx and name.lower() in _NO_COMPRESSION: + compression_ctx = None + + if client and client._encrypter and not client._encrypter._bypass_auto_encryption: + spec = orig = client._encrypter.encrypt(dbname, spec, codec_options) + + # Support CSOT + if client: + conn.apply_timeout(client, spec) + _csot.apply_write_concern(spec, write_concern) + + flags = _OpMsg.MORE_TO_COME if unacknowledged else 0 + flags |= _OpMsg.EXHAUST_ALLOWED if exhaust_allowed else 0 + request_id, msg, size, max_doc_size = message._op_msg( + flags, spec, dbname, read_preference, codec_options, ctx=compression_ctx + ) + # If this is an unacknowledged write then make sure the encoded doc(s) + # are small enough, otherwise rely on the server to return an error. + if unacknowledged and max_bson_size is not None and max_doc_size > max_bson_size: + message._raise_document_too_large(name, size, max_bson_size) + + if max_bson_size is not None and size > max_bson_size + message._COMMAND_OVERHEAD: + message._raise_document_too_large(name, size, max_bson_size + message._COMMAND_OVERHEAD) + docs, _, _ = _run_command( + conn, + spec, + dbname, + request_id, + msg, + client=client, + session=session, + listeners=listeners, + address=address, + start=start, + codec_options=codec_options, + user_fields=user_fields, + orig=orig, + check=check, + allowable_errors=allowable_errors, + parse_write_concern_error=parse_write_concern_error, + speculative_hello=speculative_hello, + unacknowledged=unacknowledged, + set_conn_more_to_come=True, + ) + return docs[0] # type: ignore[return-value] diff --git a/pymongo/synchronous/network.py b/pymongo/synchronous/network.py deleted file mode 100644 index e7bde29eb2..0000000000 --- a/pymongo/synchronous/network.py +++ /dev/null @@ -1,286 +0,0 @@ -# Copyright 2015-present MongoDB, Inc. -# -# Licensed under the Apache License, Version 2.0 (the "License"); -# you may not use this file except in compliance with the License. -# You may obtain a copy of the License at -# -# https://www.apache.org/licenses/LICENSE-2.0 -# -# Unless required by applicable law or agreed to in writing, software -# distributed under the License is distributed on an "AS IS" BASIS, -# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -# See the License for the specific language governing permissions and -# limitations under the License. - -"""Internal network layer helper methods.""" - -from __future__ import annotations - -import datetime -import logging -from collections.abc import Mapping, MutableMapping, Sequence -from typing import ( - TYPE_CHECKING, - Any, - Optional, - Union, - cast, -) - -from bson import _decode_all_selective -from pymongo import _csot, helpers_shared, message -from pymongo.compression_support import _NO_COMPRESSION -from pymongo.errors import ( - NotPrimaryError, - OperationFailure, -) -from pymongo.logger import _COMMAND_LOGGER, _CommandStatusMessage, _debug_log -from pymongo.message import _OpMsg -from pymongo.monitoring import _is_speculative_authenticate -from pymongo.network_layer import ( - receive_message, - sendall, -) - -if TYPE_CHECKING: - from bson import CodecOptions - from pymongo.compression_support import SnappyContext, ZlibContext, ZstdContext - from pymongo.monitoring import _EventListeners - from pymongo.read_concern import ReadConcern - from pymongo.read_preferences import _ServerMode - from pymongo.synchronous.client_session import ClientSession - from pymongo.synchronous.mongo_client import MongoClient - from pymongo.synchronous.pool import Connection - from pymongo.typings import _Address, _CollationIn, _DocumentOut, _DocumentType - from pymongo.write_concern import WriteConcern - -_IS_SYNC = True - - -def command( - conn: Connection, - dbname: str, - spec: MutableMapping[str, Any], - is_mongos: bool, # noqa: ARG001 - read_preference: Optional[_ServerMode], - codec_options: CodecOptions[_DocumentType], - session: Optional[ClientSession], - client: Optional[MongoClient[Any]], - check: bool = True, - allowable_errors: Optional[Sequence[Union[str, int]]] = None, - address: Optional[_Address] = None, - listeners: Optional[_EventListeners] = None, - max_bson_size: Optional[int] = None, - read_concern: Optional[ReadConcern] = None, - parse_write_concern_error: bool = False, - collation: Optional[_CollationIn] = None, - compression_ctx: Union[SnappyContext, ZlibContext, ZstdContext, None] = None, - unacknowledged: bool = False, - user_fields: Optional[Mapping[str, Any]] = None, - exhaust_allowed: bool = False, - write_concern: Optional[WriteConcern] = None, -) -> _DocumentType: - """Execute a command over the socket, or raise socket.error. - - :param conn: a Connection instance - :param dbname: name of the database on which to run the command - :param spec: a command document as an ordered dict type, eg SON. - :param is_mongos: are we connected to a mongos? - :param read_preference: a read preference - :param codec_options: a CodecOptions instance - :param session: optional ClientSession instance. - :param client: optional MongoClient instance for updating $clusterTime. - :param check: raise OperationFailure if there are errors - :param allowable_errors: errors to ignore if `check` is True - :param address: the (host, port) of `conn` - :param listeners: An instance of :class:`~pymongo.monitoring.EventListeners` - :param max_bson_size: The maximum encoded bson size for this server - :param read_concern: The read concern for this command. - :param parse_write_concern_error: Whether to parse the ``writeConcernError`` - field in the command response. - :param collation: The collation for this command. - :param compression_ctx: optional compression Context. - :param unacknowledged: True if this is an unacknowledged command. - :param user_fields: Response fields that should be decoded - using the TypeDecoders from codec_options, passed to - bson._decode_all_selective. - :param exhaust_allowed: True if we should enable OP_MSG exhaustAllowed. - """ - name = next(iter(spec)) - speculative_hello = False - - # Publish the original command document, perhaps with lsid and $clusterTime. - orig = spec - if read_concern and not (session and session.in_transaction): - if read_concern.level: - spec["readConcern"] = read_concern.document - if session: - session._update_read_concern(spec, conn) - if collation is not None: - spec["collation"] = collation - - publish = listeners is not None and listeners.enabled_for_commands - start = datetime.datetime.now() - if publish: - speculative_hello = _is_speculative_authenticate(name, spec) - - if compression_ctx and name.lower() in _NO_COMPRESSION: - compression_ctx = None - - if client and client._encrypter and not client._encrypter._bypass_auto_encryption: - spec = orig = client._encrypter.encrypt(dbname, spec, codec_options) - - # Support CSOT - if client: - conn.apply_timeout(client, spec) - _csot.apply_write_concern(spec, write_concern) - - flags = _OpMsg.MORE_TO_COME if unacknowledged else 0 - flags |= _OpMsg.EXHAUST_ALLOWED if exhaust_allowed else 0 - request_id, msg, size, max_doc_size = message._op_msg( - flags, spec, dbname, read_preference, codec_options, ctx=compression_ctx - ) - # If this is an unacknowledged write then make sure the encoded doc(s) - # are small enough, otherwise rely on the server to return an error. - if unacknowledged and max_bson_size is not None and max_doc_size > max_bson_size: - message._raise_document_too_large(name, size, max_bson_size) - - if max_bson_size is not None and size > max_bson_size + message._COMMAND_OVERHEAD: - message._raise_document_too_large(name, size, max_bson_size + message._COMMAND_OVERHEAD) - if client is not None: - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.STARTED, - clientId=client._topology_settings._topology_id, - command=spec, - commandName=next(iter(spec)), - databaseName=dbname, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - ) - if publish: - assert listeners is not None - assert address is not None - listeners.publish_command_start( - orig, - dbname, - request_id, - address, - conn.server_connection_id, - service_id=conn.service_id, - ) - - try: - sendall(conn.conn.get_conn, msg) - if unacknowledged: - # Unacknowledged, fake a successful command response. - reply = None - response_doc: _DocumentOut = {"ok": 1} - else: - reply = receive_message(conn, request_id) - conn.more_to_come = reply.more_to_come - unpacked_docs = reply.unpack_response( - codec_options=codec_options, user_fields=user_fields - ) - - response_doc = unpacked_docs[0] - if not conn.ready: - cluster_time = response_doc.get("$clusterTime") - if cluster_time: - conn._cluster_time = cluster_time - if client: - client._process_response(response_doc, session) - if check: - helpers_shared._check_command_response( - response_doc, - conn.max_wire_version, - allowable_errors, - parse_write_concern_error=parse_write_concern_error, - ) - except Exception as exc: - duration = datetime.datetime.now() - start - if isinstance(exc, (NotPrimaryError, OperationFailure)): - failure: _DocumentOut = exc.details # type: ignore[assignment] - else: - failure = message._convert_exception(exc) - if client is not None: - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.FAILED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - failure=failure, - commandName=next(iter(spec)), - databaseName=dbname, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - isServerSideError=isinstance(exc, OperationFailure), - ) - if publish: - assert listeners is not None - assert address is not None - listeners.publish_command_failure( - duration, - failure, - name, - request_id, - address, - conn.server_connection_id, - service_id=conn.service_id, - database_name=dbname, - ) - raise - duration = datetime.datetime.now() - start - if client is not None: - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.SUCCEEDED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - reply=response_doc, - commandName=next(iter(spec)), - databaseName=dbname, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - speculative_authenticate="speculativeAuthenticate" in orig, - ) - if publish: - assert listeners is not None - assert address is not None - listeners.publish_command_success( - duration, - response_doc, - name, - request_id, - address, - conn.server_connection_id, - service_id=conn.service_id, - speculative_hello=speculative_hello, - database_name=dbname, - ) - - if client and client._encrypter and reply: - decrypted = client._encrypter.decrypt(reply.raw_command_response()) - response_doc = cast( - "_DocumentOut", _decode_all_selective(decrypted, codec_options, user_fields)[0] - ) - - return response_doc # type: ignore[return-value] diff --git a/pymongo/synchronous/pool.py b/pymongo/synchronous/pool.py index 83282e12b2..b3929b674a 100644 --- a/pymongo/synchronous/pool.py +++ b/pymongo/synchronous/pool.py @@ -85,8 +85,8 @@ from pymongo.server_type import SERVER_TYPE from pymongo.socket_checker import SocketChecker from pymongo.synchronous.client_session import _validate_session_write_concern +from pymongo.synchronous.command_runner import run_command from pymongo.synchronous.helpers import _handle_reauth -from pymongo.synchronous.network import command if TYPE_CHECKING: from bson import CodecOptions @@ -390,15 +390,15 @@ def command( self.send_cluster_time(spec, session, client) listeners = self.listeners if publish_events else None unacknowledged = bool(write_concern and not write_concern.acknowledged) - self._raise_if_not_writable(unacknowledged) + if unacknowledged: + self._raise_if_not_writable() try: if session is not None and session._starting_transaction: session._transaction.set_in_progress() - return command( + return run_command( self, dbname, spec, - self.is_mongos, read_preference, codec_options, # type: ignore[arg-type] session, @@ -451,43 +451,11 @@ def receive_message(self, request_id: Optional[int]) -> _OpMsg: except BaseException as error: self._raise_connection_failure(error) - def _raise_if_not_writable(self, unacknowledged: bool) -> None: - """Raise NotPrimaryError on unacknowledged write if this socket is not - writable. - """ - if unacknowledged and not self.is_writable: - # Write won't succeed, bail as if we'd received a not primary error. + def _raise_if_not_writable(self) -> None: + """Raise NotPrimaryError if this connection is not writable.""" + if not self.is_writable: raise NotPrimaryError("not primary", {"ok": 0, "errmsg": "not primary", "code": 10107}) - def unack_write(self, msg: bytes, max_doc_size: int) -> None: - """Send unack OP_MSG. - - Can raise ConnectionFailure or InvalidDocument. - - :param msg: bytes, an OP_MSG message. - :param max_doc_size: size in bytes of the largest document in `msg`. - """ - self._raise_if_not_writable(True) - self.send_message(msg, max_doc_size) - - def write_command( - self, request_id: int, msg: bytes, codec_options: CodecOptions[Mapping[str, Any]] - ) -> dict[str, Any]: - """Send "insert" etc. command, returning response as a dict. - - Can raise ConnectionFailure or OperationFailure. - - :param request_id: an int. - :param msg: bytes, the command message. - """ - self.send_message(msg, 0) - reply = self.receive_message(request_id) - result = reply.command_response(codec_options) - - # Raises NotPrimaryError or OperationFailure. - helpers_shared._check_command_response(result, self.max_wire_version) - return result - def authenticate(self, reauthenticate: bool = False) -> None: """Authenticate to the server if needed. diff --git a/pymongo/synchronous/server.py b/pymongo/synchronous/server.py index 46db33dbce..7aa017134a 100644 --- a/pymongo/synchronous/server.py +++ b/pymongo/synchronous/server.py @@ -27,18 +27,14 @@ Union, ) -from bson import _decode_all_selective -from pymongo.errors import NotPrimaryError, OperationFailure -from pymongo.helpers_shared import _check_command_response from pymongo.logger import ( - _COMMAND_LOGGER, _SDAM_LOGGER, - _CommandStatusMessage, _debug_log, _SDAMStatusMessage, ) -from pymongo.message import _convert_exception, _GetMore, _OpMsg, _Query +from pymongo.message import _GetMore, _OpMsg, _Query from pymongo.response import PinnedResponse, Response +from pymongo.synchronous.command_runner import run_cursor_command from pymongo.synchronous.helpers import _handle_reauth if TYPE_CHECKING: @@ -159,152 +155,42 @@ def run_operation( :param client: A MongoClient instance. """ assert listeners is not None - publish = listeners.enabled_for_commands start = datetime.now() use_cmd = operation.use_command(conn) - more_to_come = operation.conn_mgr and operation.conn_mgr.more_to_come + more_to_come = bool(operation.conn_mgr and operation.conn_mgr.more_to_come) cmd, dbn = self.operation_to_command(operation, conn, use_cmd) if more_to_come: request_id = 0 + data = b"" + max_doc_size = 0 else: message = operation.get_message(read_preference, conn, use_cmd) request_id, data, max_doc_size = self._split_message(message) - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.STARTED, - clientId=client._topology_settings._topology_id, - command=cmd, - commandName=next(iter(cmd)), - databaseName=dbn, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - ) - - if publish: - if "$db" not in cmd: - cmd["$db"] = dbn - assert listeners is not None - listeners.publish_command_start( - cmd, - dbn, - request_id, - conn.address, - conn.server_connection_id, - service_id=conn.service_id, - ) - - try: - if more_to_come: - reply = conn.receive_message(None) - else: - if operation.session is not None and operation.session._starting_transaction: - operation.session._transaction.set_in_progress() - conn.send_message(data, max_doc_size) - reply = conn.receive_message(request_id) - - # Unpack and check for command errors. - if use_cmd: - user_fields = _CURSOR_DOC_FIELDS - legacy_response = False - else: - user_fields = None - legacy_response = True - docs = unpack_res( - reply, - operation.cursor_id, - operation.codec_options, - legacy_response=legacy_response, - user_fields=user_fields, - ) - if use_cmd: - first = docs[0] - operation.client._process_response(first, operation.session) # type: ignore[misc, arg-type] - _check_command_response(first, conn.max_wire_version, pool_opts=conn.opts) # type:ignore[has-type] - except Exception as exc: - duration = datetime.now() - start - if isinstance(exc, (NotPrimaryError, OperationFailure)): - failure: _DocumentOut = exc.details # type: ignore[assignment] - else: - failure = _convert_exception(exc) - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.FAILED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - failure=failure, - commandName=next(iter(cmd)), - databaseName=dbn, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - isServerSideError=isinstance(exc, OperationFailure), - ) - if publish: - assert listeners is not None - listeners.publish_command_failure( - duration, - failure, - operation.name, - request_id, - conn.address, - conn.server_connection_id, - service_id=conn.service_id, - database_name=dbn, - ) - raise - duration = datetime.now() - start - # Must publish in find / getMore / explain command response - # format. - res = docs[0] - if _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.SUCCEEDED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - reply=res, - commandName=next(iter(cmd)), - databaseName=dbn, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - ) - if publish: - assert listeners is not None - listeners.publish_command_success( - duration, - res, - operation.name, - request_id, - conn.address, - conn.server_connection_id, - service_id=conn.service_id, - database_name=dbn, - ) - - # Decrypt response. - client = operation.client # type: ignore[assignment] - if client and client._encrypter: - if use_cmd: - decrypted = client._encrypter.decrypt(reply.raw_command_response()) - docs = _decode_all_selective(decrypted, operation.codec_options, user_fields) + user_fields = _CURSOR_DOC_FIELDS if use_cmd else None + + docs, reply, duration = run_cursor_command( + conn, + cmd, + dbn, + request_id, + data, + client=client, + session=operation.session, # type: ignore[arg-type] + listeners=listeners, + address=conn.address, + start=start, + codec_options=operation.codec_options, + user_fields=user_fields, + command_name=operation.name, + pool_opts=conn.opts, + max_doc_size=max_doc_size, + more_to_come=more_to_come, + unpack_res=unpack_res, + cursor_id=operation.cursor_id, + ) + assert reply is not None response: Response @@ -326,7 +212,7 @@ def run_operation( duration=duration, request_id=request_id, from_command=use_cmd, - docs=docs, + docs=docs, # type: ignore[arg-type] more_to_come=more_to_come, ) else: @@ -336,7 +222,7 @@ def run_operation( duration=duration, request_id=request_id, from_command=use_cmd, - docs=docs, + docs=docs, # type: ignore[arg-type] ) return response diff --git a/test/test_message.py b/test/test_message.py index ceb3a98989..e3094d1e27 100644 --- a/test/test_message.py +++ b/test/test_message.py @@ -29,7 +29,6 @@ from pymongo.message import ( _convert_client_bulk_exception, _convert_exception, - _convert_write_result, _gen_find_command, _gen_get_more_command, _maybe_add_read_preference, @@ -99,54 +98,6 @@ def test_client_bulk_exception_includes_code(self): self.assertEqual(doc["code"], 11000) self.assertEqual(doc["errtype"], "OperationFailure") - # _convert_write_result - # In the update command spec, `q` is the query/filter and `u` is the update document. - - def test_insert_basic(self): - cmd = {"documents": [{"_id": 1}, {"_id": 2}]} - result = _convert_write_result("insert", cmd, {"n": 0}) - self.assertEqual(result["ok"], 1) - self.assertEqual(result["n"], 2) - - def test_update_basic(self): - cmd = {"updates": [{"q": {}, "u": {"$set": {"x": 1}}}]} - result = _convert_write_result("update", cmd, {"n": 1, "updatedExisting": True}) - self.assertEqual(result["ok"], 1) - self.assertNotIn("upserted", result) - - def test_update_with_upserted_id(self): - cmd = {"updates": [{"q": {}, "u": {"_id": 42}}]} - result = _convert_write_result("update", cmd, {"n": 1, "upserted": 42}) - self.assertIn("upserted", result) - self.assertEqual(result["upserted"][0]["_id"], 42) - - def test_delete_basic(self): - cmd = {"deletes": [{"q": {}, "limit": 1}]} - result = _convert_write_result("delete", cmd, {"n": 1}) - self.assertEqual(result["ok"], 1) - self.assertEqual(result["n"], 1) - - def test_write_error(self): - cmd = {"documents": [{"_id": 1}]} - gle = {"n": 0, "err": "duplicate key error", "code": 11000} - result = _convert_write_result("insert", cmd, gle) - self.assertIn("writeErrors", result) - self.assertEqual(result["writeErrors"][0]["code"], 11000) - - def test_write_concern_timeout(self): - cmd = {"documents": [{"_id": 1}]} - gle = {"n": 1, "errmsg": "timeout", "wtimeout": True} - result = _convert_write_result("insert", cmd, gle) - self.assertIn("writeConcernError", result) - self.assertEqual(result["writeConcernError"]["code"], 64) - - def test_write_error_with_err_info(self): - # Covers the `if "errInfo" in result:` branch, which test_write_error does not enter. - cmd = {"documents": [{"_id": 1}]} - gle = {"n": 0, "err": "err", "code": 123, "errInfo": {"detail": "x"}} - result = _convert_write_result("insert", cmd, gle) - self.assertIn("errInfo", result["writeErrors"][0]) - # _op_msg def test_op_msg_max_doc_size_zero_without_docs(self): From f65a451832a285fac62606896f26a8087a516f03 Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Wed, 24 Jun 2026 11:29:56 -0700 Subject: [PATCH 4/9] Bump codecov/codecov-action from 6.0.1 to 7.0.0 in the actions group (#2884) Signed-off-by: dependabot[bot] Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com> Co-authored-by: Iris <58442094+sleepyStick@users.noreply.github.com> --- .github/workflows/test-python.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/test-python.yml b/.github/workflows/test-python.yml index 123c94ce14..ce2ba071ea 100644 --- a/.github/workflows/test-python.yml +++ b/.github/workflows/test-python.yml @@ -110,7 +110,7 @@ jobs: - name: Generate xml report run: uv tool run --with "coverage[toml]" coverage xml - name: Upload test results to Codecov - uses: codecov/codecov-action@e79a6962e0d4c0c17b229090214935d2e33f8354 # v6.0.1 + uses: codecov/codecov-action@fb8b3582c8e4def4969c97caa2f19720cb33a72f # v7.0.0 with: token: ${{ secrets.CODECOV_TOKEN }} doctest: From c53a0f9b9c71e573501d1c190103182a0c71073c Mon Sep 17 00:00:00 2001 From: "mongodb-drivers-pr-bot[bot]" <147046816+mongodb-drivers-pr-bot[bot]@users.noreply.github.com> Date: Thu, 25 Jun 2026 13:08:13 -0700 Subject: [PATCH 5/9] [Spec Resync] 06-22-2026 (#2885) Co-authored-by: Cloud User Co-authored-by: Iris <58442094+sleepyStick@users.noreply.github.com> Co-authored-by: Iris --- .evergreen/scripts/resync-all-specs.py | 46 +-- .../{PYTHON-4201.patch => PYTHON-4261.patch} | 0 .../etc/data/encryptedFields-c10.json | 30 ++ .../encryptedFields-prefix-suffix-ci-di.json | 4 +- ...encryptedFields-prefix-suffix-preview.json | 44 +++ .../data/encryptedFields-prefix-suffix.json | 16 +- .../etc/data/encryptedFields-substring.json | 3 + ...-Text-cleanupStructuredEncryptionData.json | 7 +- ...-Text-compactStructuredEncryptionData.json | 9 +- .../spec/unified/QE-Text-prefix.json | 338 ++++++++++++++++++ .../spec/unified/QE-Text-prefixPreview.json | 2 +- .../spec/unified/QE-Text-suffix.json | 338 ++++++++++++++++++ .../spec/unified/QE-Text-suffixPreview.json | 4 +- test/transactions/unified/commit.json | 12 + 14 files changed, 811 insertions(+), 42 deletions(-) rename .evergreen/spec-patch/permanent/{PYTHON-4201.patch => PYTHON-4261.patch} (100%) create mode 100644 test/client-side-encryption/etc/data/encryptedFields-c10.json create mode 100644 test/client-side-encryption/etc/data/encryptedFields-prefix-suffix-preview.json create mode 100644 test/client-side-encryption/spec/unified/QE-Text-prefix.json create mode 100644 test/client-side-encryption/spec/unified/QE-Text-suffix.json diff --git a/.evergreen/scripts/resync-all-specs.py b/.evergreen/scripts/resync-all-specs.py index 51448b28f8..78afe8a4d8 100644 --- a/.evergreen/scripts/resync-all-specs.py +++ b/.evergreen/scripts/resync-all-specs.py @@ -37,29 +37,29 @@ def apply_patches(errored): ["bash", "./.evergreen/remove-unimplemented-tests.sh"], # noqa: S607 check=True, ) - try: - # Avoid shell=True by passing arguments as a list. - # Note: glob expansion doesn't work in shell=False, so we use a list of files. - spec_patch_dir = pathlib.Path("./.evergreen/spec-patch/") - patches = [str(p) for p in spec_patch_dir.glob("*.patch")] - patches += [str(p) for p in (spec_patch_dir / "permanent").glob("*.patch")] - if patches: - for patch in patches: - print(f"Applying patch {patch}") - subprocess.run( # noqa: S603 - [ # noqa: S607 - "git", - "apply", - "-R", - "--allow-empty", - "--whitespace=fix", - *patches, - ], - check=True, - stderr=subprocess.PIPE, - ) - except CalledProcessError as exc: - errored["applying patches"] = exc.stderr + # Avoid shell=True by passing arguments as a list. + # Note: glob expansion doesn't work in shell=False, so we use a list of files. + spec_patch_dir = pathlib.Path("./.evergreen/spec-patch/") + patches = [str(p) for p in spec_patch_dir.glob("*.patch")] + patches += [str(p) for p in (spec_patch_dir / "permanent").glob("*.patch")] + if patches: + for patch in patches: + print(f"Applying patch {patch}") + try: + subprocess.run( # noqa: S603 + [ # noqa: S607 + "git", + "apply", + "-R", + "--allow-empty", + "--whitespace=fix", + str(patch), + ], + check=True, + stderr=subprocess.PIPE, + ) + except CalledProcessError as exc: + errored[f"{patch}"] = exc.stderr def check_new_spec_directories(directory: pathlib.Path) -> list[str]: diff --git a/.evergreen/spec-patch/permanent/PYTHON-4201.patch b/.evergreen/spec-patch/permanent/PYTHON-4261.patch similarity index 100% rename from .evergreen/spec-patch/permanent/PYTHON-4201.patch rename to .evergreen/spec-patch/permanent/PYTHON-4261.patch diff --git a/test/client-side-encryption/etc/data/encryptedFields-c10.json b/test/client-side-encryption/etc/data/encryptedFields-c10.json new file mode 100644 index 0000000000..e9ed08bb39 --- /dev/null +++ b/test/client-side-encryption/etc/data/encryptedFields-c10.json @@ -0,0 +1,30 @@ +{ + "fields": [ + { + "keyId": { + "$binary": { + "base64": "EjRWeBI0mHYSNBI0VniQEg==", + "subType": "04" + } + }, + "path": "encryptedIndexed", + "bsonType": "string", + "queries": { + "queryType": "equality", + "contention": { + "$numberLong": "10" + } + } + }, + { + "keyId": { + "$binary": { + "base64": "q83vqxI0mHYSNBI0VniQEg==", + "subType": "04" + } + }, + "path": "encryptedUnindexed", + "bsonType": "string" + } + ] +} diff --git a/test/client-side-encryption/etc/data/encryptedFields-prefix-suffix-ci-di.json b/test/client-side-encryption/etc/data/encryptedFields-prefix-suffix-ci-di.json index c43bf9390d..3002c642b2 100644 --- a/test/client-side-encryption/etc/data/encryptedFields-prefix-suffix-ci-di.json +++ b/test/client-side-encryption/etc/data/encryptedFields-prefix-suffix-ci-di.json @@ -11,7 +11,7 @@ "bsonType": "string", "queries": [ { - "queryType": "prefixPreview", + "queryType": "prefix", "strMinQueryLength": { "$numberInt": "2" }, @@ -23,7 +23,7 @@ "diacriticSensitive": false }, { - "queryType": "suffixPreview", + "queryType": "suffix", "strMinQueryLength": { "$numberInt": "2" }, diff --git a/test/client-side-encryption/etc/data/encryptedFields-prefix-suffix-preview.json b/test/client-side-encryption/etc/data/encryptedFields-prefix-suffix-preview.json new file mode 100644 index 0000000000..047064beb1 --- /dev/null +++ b/test/client-side-encryption/etc/data/encryptedFields-prefix-suffix-preview.json @@ -0,0 +1,44 @@ +{ + "fields": [ + { + "keyId": { + "$binary": { + "base64": "EjRWeBI0mHYSNBI0VniQEg==", + "subType": "04" + } + }, + "path": "encryptedText", + "bsonType": "string", + "queries": [ + { + "queryType": "prefixPreview", + "strMinQueryLength": { + "$numberInt": "2" + }, + "strMaxQueryLength": { + "$numberInt": "10" + }, + "contention": { + "$numberLong": "0" + }, + "caseSensitive": true, + "diacriticSensitive": true + }, + { + "queryType": "suffixPreview", + "strMinQueryLength": { + "$numberInt": "2" + }, + "strMaxQueryLength": { + "$numberInt": "10" + }, + "contention": { + "$numberLong": "0" + }, + "caseSensitive": true, + "diacriticSensitive": true + } + ] + } + ] +} diff --git a/test/client-side-encryption/etc/data/encryptedFields-prefix-suffix.json b/test/client-side-encryption/etc/data/encryptedFields-prefix-suffix.json index ec4489fa09..a96e616723 100644 --- a/test/client-side-encryption/etc/data/encryptedFields-prefix-suffix.json +++ b/test/client-side-encryption/etc/data/encryptedFields-prefix-suffix.json @@ -1,6 +1,6 @@ { - "fields": [ - { + "fields": [ + { "keyId": { "$binary": { "base64": "EjRWeBI0mHYSNBI0VniQEg==", @@ -11,28 +11,34 @@ "bsonType": "string", "queries": [ { - "queryType": "prefixPreview", + "queryType": "prefix", "strMinQueryLength": { "$numberInt": "2" }, "strMaxQueryLength": { "$numberInt": "10" }, + "contention": { + "$numberLong": "0" + }, "caseSensitive": true, "diacriticSensitive": true }, { - "queryType": "suffixPreview", + "queryType": "suffix", "strMinQueryLength": { "$numberInt": "2" }, "strMaxQueryLength": { "$numberInt": "10" }, + "contention": { + "$numberLong": "0" + }, "caseSensitive": true, "diacriticSensitive": true } ] } - ] + ] } diff --git a/test/client-side-encryption/etc/data/encryptedFields-substring.json b/test/client-side-encryption/etc/data/encryptedFields-substring.json index ee22def77b..d321a32c5c 100644 --- a/test/client-side-encryption/etc/data/encryptedFields-substring.json +++ b/test/client-side-encryption/etc/data/encryptedFields-substring.json @@ -21,6 +21,9 @@ "strMaxQueryLength": { "$numberInt": "10" }, + "contention": { + "$numberLong": "0" + }, "caseSensitive": true, "diacriticSensitive": true } diff --git a/test/client-side-encryption/spec/unified/QE-Text-cleanupStructuredEncryptionData.json b/test/client-side-encryption/spec/unified/QE-Text-cleanupStructuredEncryptionData.json index fd74573ea2..dc979b5019 100644 --- a/test/client-side-encryption/spec/unified/QE-Text-cleanupStructuredEncryptionData.json +++ b/test/client-side-encryption/spec/unified/QE-Text-cleanupStructuredEncryptionData.json @@ -3,15 +3,14 @@ "schemaVersion": "1.25", "runOnRequirements": [ { - "minServerVersion": "8.2.0", - "maxServerVersion": "8.99.99", + "minServerVersion": "9.0.0", "topologies": [ "replicaset", "sharded", "load-balanced" ], "csfle": { - "minLibmongocryptVersion": "1.15.0" + "minLibmongocryptVersion": "1.19.0" } } ], @@ -102,7 +101,7 @@ "bsonType": "string", "queries": [ { - "queryType": "suffixPreview", + "queryType": "suffix", "contention": { "$numberLong": "0" }, diff --git a/test/client-side-encryption/spec/unified/QE-Text-compactStructuredEncryptionData.json b/test/client-side-encryption/spec/unified/QE-Text-compactStructuredEncryptionData.json index a89ab96fc4..1c3c6cc0de 100644 --- a/test/client-side-encryption/spec/unified/QE-Text-compactStructuredEncryptionData.json +++ b/test/client-side-encryption/spec/unified/QE-Text-compactStructuredEncryptionData.json @@ -3,15 +3,14 @@ "schemaVersion": "1.25", "runOnRequirements": [ { - "minServerVersion": "8.2.0", - "maxServerVersion": "8.99.99", + "minServerVersion": "9.0.0", "topologies": [ "replicaset", "sharded", "load-balanced" ], "csfle": { - "minLibmongocryptVersion": "1.15.0" + "minLibmongocryptVersion": "1.19.0" } } ], @@ -102,7 +101,7 @@ "bsonType": "string", "queries": [ { - "queryType": "suffixPreview", + "queryType": "suffix", "contention": { "$numberLong": "0" }, @@ -210,7 +209,7 @@ "bsonType": "string", "queries": [ { - "queryType": "suffixPreview", + "queryType": "suffix", "contention": { "$numberLong": "0" }, diff --git a/test/client-side-encryption/spec/unified/QE-Text-prefix.json b/test/client-side-encryption/spec/unified/QE-Text-prefix.json new file mode 100644 index 0000000000..25475e2c3a --- /dev/null +++ b/test/client-side-encryption/spec/unified/QE-Text-prefix.json @@ -0,0 +1,338 @@ +{ + "description": "QE-Text-prefix", + "schemaVersion": "1.25", + "runOnRequirements": [ + { + "minServerVersion": "9.0.0", + "topologies": [ + "replicaset", + "sharded", + "load-balanced" + ], + "csfle": { + "minLibmongocryptVersion": "1.19.0" + } + } + ], + "createEntities": [ + { + "client": { + "id": "client", + "autoEncryptOpts": { + "keyVaultNamespace": "keyvault.datakeys", + "kmsProviders": { + "local": { + "key": "Mng0NCt4ZHVUYUJCa1kxNkVyNUR1QURhZ2h2UzR2d2RrZzh0cFBwM3R6NmdWMDFBMUN3YkQ5aXRRMkhGRGdQV09wOGVNYUMxT2k3NjZKelhaQmRCZGJkTXVyZG9uSjFk" + } + } + }, + "observeEvents": [ + "commandStartedEvent" + ] + } + }, + { + "database": { + "id": "db", + "client": "client", + "databaseName": "db" + } + }, + { + "collection": { + "id": "coll", + "database": "db", + "collectionName": "coll" + } + } + ], + "initialData": [ + { + "databaseName": "keyvault", + "collectionName": "datakeys", + "documents": [ + { + "_id": { + "$binary": { + "base64": "q83vqxI0mHYSNBI0VniQEg==", + "subType": "04" + } + }, + "keyMaterial": { + "$binary": { + "base64": "HBk9BWihXExNDvTp1lUxOuxuZK2Pe2ZdVdlsxPEBkiO1bS4mG5NNDsQ7zVxJAH8BtdOYp72Ku4Y3nwc0BUpIKsvAKX4eYXtlhv5zUQxWdeNFhg9qK7qb8nqhnnLeT0f25jFSqzWJoT379hfwDeu0bebJHr35QrJ8myZdPMTEDYF08QYQ48ShRBli0S+QzBHHAQiM2iJNr4svg2WR8JSeWQ==", + "subType": "00" + } + }, + "creationDate": { + "$date": { + "$numberLong": "1648914851981" + } + }, + "updateDate": { + "$date": { + "$numberLong": "1648914851981" + } + }, + "status": { + "$numberInt": "0" + }, + "masterKey": { + "provider": "local" + } + } + ] + }, + { + "databaseName": "db", + "collectionName": "coll", + "documents": [], + "createOptions": { + "encryptedFields": { + "fields": [ + { + "keyId": { + "$binary": { + "base64": "q83vqxI0mHYSNBI0VniQEg==", + "subType": "04" + } + }, + "path": "encryptedText", + "bsonType": "string", + "queries": [ + { + "queryType": "prefix", + "contention": { + "$numberLong": "0" + }, + "strMinQueryLength": { + "$numberLong": "3" + }, + "strMaxQueryLength": { + "$numberLong": "30" + }, + "caseSensitive": true, + "diacriticSensitive": true + } + ] + } + ] + } + } + } + ], + "tests": [ + { + "description": "Insert QE prefix", + "operations": [ + { + "name": "insertOne", + "arguments": { + "document": { + "_id": 1, + "encryptedText": "foobar" + } + }, + "object": "coll" + } + ], + "expectEvents": [ + { + "client": "client", + "events": [ + { + "commandStartedEvent": { + "command": { + "listCollections": 1, + "filter": { + "name": "coll" + } + }, + "commandName": "listCollections" + } + }, + { + "commandStartedEvent": { + "command": { + "find": "datakeys", + "filter": { + "$or": [ + { + "_id": { + "$in": [ + { + "$binary": { + "base64": "q83vqxI0mHYSNBI0VniQEg==", + "subType": "04" + } + } + ] + } + }, + { + "keyAltNames": { + "$in": [] + } + } + ] + }, + "$db": "keyvault", + "readConcern": { + "level": "majority" + } + }, + "commandName": "find" + } + }, + { + "commandStartedEvent": { + "command": { + "insert": "coll", + "documents": [ + { + "_id": 1, + "encryptedText": { + "$$type": "binData" + } + } + ], + "ordered": true + }, + "commandName": "insert" + } + } + ] + } + ] + }, + { + "description": "Query with matching $encStrStartsWith", + "operations": [ + { + "name": "insertOne", + "arguments": { + "document": { + "_id": 1, + "encryptedText": "foobar" + } + }, + "object": "coll" + }, + { + "name": "find", + "arguments": { + "filter": { + "$expr": { + "$encStrStartsWith": { + "input": "$encryptedText", + "prefix": "foo" + } + } + } + }, + "object": "coll", + "expectResult": [ + { + "_id": { + "$numberInt": "1" + }, + "encryptedText": "foobar", + "__safeContent__": [ + { + "$binary": { + "base64": "wpaMBVDjL4bHf9EtSP52PJFzyNn1R19+iNI/hWtvzdk=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "fmUMXTMV/XRiN0IL3VXxSEn6SQG9E6Po30kJKB8JJlQ=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "vZIDMiFDgjmLNYVrrbnq1zT4hg7sGpe/PMtighSsnRc=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "26Z5G+sHTzV3D7F8Y0m08389USZ2afinyFV3ez9UEBQ=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "q/JEq8of7bE0QE5Id0XuOsNQ4qVpANYymcPQDUL2Ywk=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "Uvvv46LkfbgLoPqZ6xTBzpgoYRTM6FUgRdqZ9eaVojI=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "nMxdq2lladuBJA3lv3JC2MumIUtRJBNJVLp3PVE6nQk=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "hS3V0qq5CF/SkTl3ZWWWgXcAJ8G5yGtkY2RwcHNc5Oc=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "McgwYUxfKj5+4D0vskZymy4KA82s71MR25iV/Enutww=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "Ciqdk1b+t+Vrr6oIlFFk0Zdym5BPmwN3glQ0/VcsVdM=", + "subType": "00" + } + } + ] + } + ] + } + ] + }, + { + "description": "Query with non-matching $encStrStartsWith", + "operations": [ + { + "name": "insertOne", + "arguments": { + "document": { + "_id": 1, + "encryptedText": "foobar" + } + }, + "object": "coll" + }, + { + "name": "find", + "arguments": { + "filter": { + "$expr": { + "$encStrStartsWith": { + "input": "$encryptedText", + "prefix": "bar" + } + } + } + }, + "object": "coll", + "expectResult": [] + } + ] + } + ] +} diff --git a/test/client-side-encryption/spec/unified/QE-Text-prefixPreview.json b/test/client-side-encryption/spec/unified/QE-Text-prefixPreview.json index c193608e88..51e72fd3ca 100644 --- a/test/client-side-encryption/spec/unified/QE-Text-prefixPreview.json +++ b/test/client-side-encryption/spec/unified/QE-Text-prefixPreview.json @@ -11,7 +11,7 @@ "load-balanced" ], "csfle": { - "minLibmongocryptVersion": "1.15.0" + "minLibmongocryptVersion": "1.19.1" } } ], diff --git a/test/client-side-encryption/spec/unified/QE-Text-suffix.json b/test/client-side-encryption/spec/unified/QE-Text-suffix.json new file mode 100644 index 0000000000..ad6cdc06c9 --- /dev/null +++ b/test/client-side-encryption/spec/unified/QE-Text-suffix.json @@ -0,0 +1,338 @@ +{ + "description": "QE-Text-suffix", + "schemaVersion": "1.25", + "runOnRequirements": [ + { + "minServerVersion": "9.0.0", + "topologies": [ + "replicaset", + "sharded", + "load-balanced" + ], + "csfle": { + "minLibmongocryptVersion": "1.19.0" + } + } + ], + "createEntities": [ + { + "client": { + "id": "client", + "autoEncryptOpts": { + "keyVaultNamespace": "keyvault.datakeys", + "kmsProviders": { + "local": { + "key": "Mng0NCt4ZHVUYUJCa1kxNkVyNUR1QURhZ2h2UzR2d2RrZzh0cFBwM3R6NmdWMDFBMUN3YkQ5aXRRMkhGRGdQV09wOGVNYUMxT2k3NjZKelhaQmRCZGJkTXVyZG9uSjFk" + } + } + }, + "observeEvents": [ + "commandStartedEvent" + ] + } + }, + { + "database": { + "id": "db", + "client": "client", + "databaseName": "db" + } + }, + { + "collection": { + "id": "coll", + "database": "db", + "collectionName": "coll" + } + } + ], + "initialData": [ + { + "databaseName": "keyvault", + "collectionName": "datakeys", + "documents": [ + { + "_id": { + "$binary": { + "base64": "q83vqxI0mHYSNBI0VniQEg==", + "subType": "04" + } + }, + "keyMaterial": { + "$binary": { + "base64": "HBk9BWihXExNDvTp1lUxOuxuZK2Pe2ZdVdlsxPEBkiO1bS4mG5NNDsQ7zVxJAH8BtdOYp72Ku4Y3nwc0BUpIKsvAKX4eYXtlhv5zUQxWdeNFhg9qK7qb8nqhnnLeT0f25jFSqzWJoT379hfwDeu0bebJHr35QrJ8myZdPMTEDYF08QYQ48ShRBli0S+QzBHHAQiM2iJNr4svg2WR8JSeWQ==", + "subType": "00" + } + }, + "creationDate": { + "$date": { + "$numberLong": "1648914851981" + } + }, + "updateDate": { + "$date": { + "$numberLong": "1648914851981" + } + }, + "status": { + "$numberInt": "0" + }, + "masterKey": { + "provider": "local" + } + } + ] + }, + { + "databaseName": "db", + "collectionName": "coll", + "documents": [], + "createOptions": { + "encryptedFields": { + "fields": [ + { + "keyId": { + "$binary": { + "base64": "q83vqxI0mHYSNBI0VniQEg==", + "subType": "04" + } + }, + "path": "encryptedText", + "bsonType": "string", + "queries": [ + { + "queryType": "suffix", + "contention": { + "$numberLong": "0" + }, + "strMinQueryLength": { + "$numberLong": "3" + }, + "strMaxQueryLength": { + "$numberLong": "30" + }, + "caseSensitive": true, + "diacriticSensitive": true + } + ] + } + ] + } + } + } + ], + "tests": [ + { + "description": "Insert QE suffix", + "operations": [ + { + "name": "insertOne", + "arguments": { + "document": { + "_id": 1, + "encryptedText": "foobar" + } + }, + "object": "coll" + } + ], + "expectEvents": [ + { + "client": "client", + "events": [ + { + "commandStartedEvent": { + "command": { + "listCollections": 1, + "filter": { + "name": "coll" + } + }, + "commandName": "listCollections" + } + }, + { + "commandStartedEvent": { + "command": { + "find": "datakeys", + "filter": { + "$or": [ + { + "_id": { + "$in": [ + { + "$binary": { + "base64": "q83vqxI0mHYSNBI0VniQEg==", + "subType": "04" + } + } + ] + } + }, + { + "keyAltNames": { + "$in": [] + } + } + ] + }, + "$db": "keyvault", + "readConcern": { + "level": "majority" + } + }, + "commandName": "find" + } + }, + { + "commandStartedEvent": { + "command": { + "insert": "coll", + "documents": [ + { + "_id": 1, + "encryptedText": { + "$$type": "binData" + } + } + ], + "ordered": true + }, + "commandName": "insert" + } + } + ] + } + ] + }, + { + "description": "Query with matching $encStrEndsWith", + "operations": [ + { + "name": "insertOne", + "arguments": { + "document": { + "_id": 1, + "encryptedText": "foobar" + } + }, + "object": "coll" + }, + { + "name": "find", + "arguments": { + "filter": { + "$expr": { + "$encStrEndsWith": { + "input": "$encryptedText", + "suffix": "bar" + } + } + } + }, + "object": "coll", + "expectResult": [ + { + "_id": { + "$numberInt": "1" + }, + "encryptedText": "foobar", + "__safeContent__": [ + { + "$binary": { + "base64": "wpaMBVDjL4bHf9EtSP52PJFzyNn1R19+iNI/hWtvzdk=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "uDCWsucUsJemUP7pmeb+Kd8B9qupVzI8wnLFqX1rkiU=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "W3E1x4bHZ8SEHFz4zwXM0G5Z5WSwBhnxE8x5/qdP6JM=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "6g/TXVDDf6z+ntResIvTKWdmIy4ajQ1rhwdNZIiEG7A=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "hU+u/T3D6dHDpT3d/v5AlgtRoAufCXCAyO2jQlgsnCw=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "vrPnq0AtBIURNgNGA6HJL+5/p5SBWe+qz8505TRo/dE=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "W5pylBxdv2soY2NcBfPiHDVLTS6tx+0ULkI8gysBeFY=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "oWO3xX3x0bYUJGK2S1aPAmlU3Xtfsgb9lTZ6flGAlsg=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "SjZGucTEUbdpd86O8yj1pyMyBOOKxvAQ9C8ngZ9C5UE=", + "subType": "00" + } + }, + { + "$binary": { + "base64": "CEaMZkxVDVbnXr+To0DOyvsva04UQkIYP3KtgYVVwf8=", + "subType": "00" + } + } + ] + } + ] + } + ] + }, + { + "description": "Query with non-matching $encStrEndsWith", + "operations": [ + { + "name": "insertOne", + "arguments": { + "document": { + "_id": 1, + "encryptedText": "foobar" + } + }, + "object": "coll" + }, + { + "name": "find", + "arguments": { + "filter": { + "$expr": { + "$encStrEndsWith": { + "input": "$encryptedText", + "suffix": "foo" + } + } + } + }, + "object": "coll", + "expectResult": [] + } + ] + } + ] +} diff --git a/test/client-side-encryption/spec/unified/QE-Text-suffixPreview.json b/test/client-side-encryption/spec/unified/QE-Text-suffixPreview.json index 2de5cde4a4..e30d0cfd58 100644 --- a/test/client-side-encryption/spec/unified/QE-Text-suffixPreview.json +++ b/test/client-side-encryption/spec/unified/QE-Text-suffixPreview.json @@ -11,7 +11,7 @@ "load-balanced" ], "csfle": { - "minLibmongocryptVersion": "1.15.0" + "minLibmongocryptVersion": "1.19.1" } } ], @@ -207,7 +207,7 @@ ] }, { - "description": "Query with matching $encStrStartsWith", + "description": "Query with matching $encStrEndsWith", "operations": [ { "name": "insertOne", diff --git a/test/transactions/unified/commit.json b/test/transactions/unified/commit.json index f033906940..de3be30470 100644 --- a/test/transactions/unified/commit.json +++ b/test/transactions/unified/commit.json @@ -209,6 +209,9 @@ "readConcern": { "afterClusterTime": { "$$exists": true + }, + "level": { + "$$exists": false } }, "lsid": { @@ -870,6 +873,9 @@ "readConcern": { "afterClusterTime": { "$$exists": true + }, + "level": { + "$$exists": false } }, "lsid": { @@ -1042,6 +1048,9 @@ "readConcern": { "afterClusterTime": { "$$exists": true + }, + "level": { + "$$exists": false } }, "lsid": { @@ -1200,6 +1209,9 @@ "readConcern": { "afterClusterTime": { "$$exists": true + }, + "level": { + "$$exists": false } }, "lsid": { From 3a562a50861a661ab4e88ba6b1edb6153fedb753 Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Mon, 29 Jun 2026 09:28:16 -0400 Subject: [PATCH 6/9] Bump ruff from 0.15.16 to 0.15.18 (#2895) Signed-off-by: dependabot[bot] Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com> --- pyproject.toml | 2 +- uv.lock | 46 +++++++++++++++++++++++----------------------- 2 files changed, 24 insertions(+), 24 deletions(-) diff --git a/pyproject.toml b/pyproject.toml index f71dcbf133..6b439c5678 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -49,7 +49,7 @@ Tracker = "https://jira.mongodb.org/projects/PYTHON/issues" [dependency-groups] dev = [] lint = [ - "ruff==0.15.16", + "ruff==0.15.18", ] unasync = [ {include-group = "lint"}, diff --git a/uv.lock b/uv.lock index 5859e07aaf..f75ad964bf 100644 --- a/uv.lock +++ b/uv.lock @@ -1625,7 +1625,7 @@ provides-extras = ["aws", "docs", "encryption", "gssapi", "ocsp", "snappy", "tes coverage = [{ name = "coverage", extras = ["toml"], specifier = ">=5,<=7.10.7" }] dev = [] gevent = [{ name = "gevent", specifier = ">=21.12" }] -lint = [{ name = "ruff", specifier = "==0.15.16" }] +lint = [{ name = "ruff", specifier = "==0.15.18" }] mockupdb = [{ name = "mockupdb", git = "https://github.com/mongodb-labs/mongo-mockup-db?rev=master" }] perf = [{ name = "simplejson", specifier = ">=3.17.0" }] pip = [{ name = "pip", specifier = ">=20.2" }] @@ -1636,7 +1636,7 @@ typing = [ { name = "typing-extensions", specifier = ">=3.7.4.2" }, ] unasync = [ - { name = "ruff", specifier = "==0.15.16" }, + { name = "ruff", specifier = "==0.15.18" }, { name = "unasync" }, ] @@ -1847,27 +1847,27 @@ wheels = [ [[package]] name = "ruff" -version = "0.15.16" -source = { registry = "https://pypi.org/simple" } -sdist = { url = "https://files.pythonhosted.org/packages/a6/bd/5f7ec371001337d8fa61701c186ff8b613ecac1651848c5950f4c4d5f2e9/ruff-0.15.16.tar.gz", hash = "sha256:d05e78d38c78caf020b03789e25106c93017db5a0cb6e2819885018c61343b78", size = 4714267, upload-time = "2026-06-04T16:33:09.974Z" } -wheels = [ - { url = "https://files.pythonhosted.org/packages/0c/42/53ef1c3953f157956db9bf7861e3bc50b9b887ce93300aa48cdba8336fe6/ruff-0.15.16-py3-none-linux_armv6l.whl", hash = "sha256:6ac3c0b3969cc6cf6b158c4e2f8f682acb58e7d700d8a44b65ecdc72d66ab0b2", size = 10709025, upload-time = "2026-06-04T16:32:51.935Z" }, - { url = "https://files.pythonhosted.org/packages/93/9a/a79159346f19134a956607754e57d8d128f7a4c00f4ad2f7514d224c172c/ruff-0.15.16-py3-none-macosx_10_12_x86_64.whl", hash = "sha256:197c207ed75ffba54a0dec23db4aa939a27a3053073e085e0042433cbdc58e4a", size = 11063550, upload-time = "2026-06-04T16:32:42.24Z" }, - { url = "https://files.pythonhosted.org/packages/bc/72/3ce2ac000a5299ec238e01f51397b3b653c93b077d9b1bfe8715bb895f20/ruff-0.15.16-py3-none-macosx_11_0_arm64.whl", hash = "sha256:3a39fec45ab316cc23e7558f23fea4a70403ddb5648ea9a4a3854a16973d0071", size = 10421345, upload-time = "2026-06-04T16:32:37.251Z" }, - { url = "https://files.pythonhosted.org/packages/b0/c2/cc7fad3ec9169373f5b6a18f1917b91080feec40c3f9658334a1d28e2f03/ruff-0.15.16-py3-none-manylinux_2_17_aarch64.manylinux2014_aarch64.whl", hash = "sha256:ba93191d79003116b95128c9d306e045200fdbd0bccb782b110f3cd1d4abc5cf", size = 10757217, upload-time = "2026-06-04T16:32:54.722Z" }, - { url = "https://files.pythonhosted.org/packages/69/d2/3474009eaa0a65b31fa7152a2fad5e2f050c640ceb1e6b02ee6922e94c82/ruff-0.15.16-py3-none-manylinux_2_17_armv7l.manylinux2014_armv7l.whl", hash = "sha256:c6ee4b90520630120ef032aa5cc10db483852dff950e78b1d717e2993a61ac8d", size = 10507035, upload-time = "2026-06-04T16:33:05.343Z" }, - { url = "https://files.pythonhosted.org/packages/ca/81/b7ae6ccbd11f0c8dc3d5d67fc4be9b57ff57ca86ba56152021378e1277f2/ruff-0.15.16-py3-none-manylinux_2_17_i686.manylinux2014_i686.whl", hash = "sha256:4e4215bc938bc3c8215c1472c1aa437e310fee20cd427335fec9d7e609563628", size = 11255291, upload-time = "2026-06-04T16:32:49.49Z" }, - { url = "https://files.pythonhosted.org/packages/d9/e1/46e526f1a7cc90857ce6ddf25fbb77eb6568651ac38d71b033af07076dd5/ruff-0.15.16-py3-none-manylinux_2_17_ppc64le.manylinux2014_ppc64le.whl", hash = "sha256:7c8d26be963b090f10e29abc8b3e74a2a321f6fa34e02424e30b5af89350ecbb", size = 12124922, upload-time = "2026-06-04T16:33:07.821Z" }, - { url = "https://files.pythonhosted.org/packages/1a/da/5c791b088b596b24d0deb967fa28ae02ad751a140c0b9ea81c5ab915d6c0/ruff-0.15.16-py3-none-manylinux_2_17_s390x.manylinux2014_s390x.whl", hash = "sha256:f198cf4123602a2280ed46c307bcbafe41758d6fee5b456b6b6058ca1514b3b4", size = 11332186, upload-time = "2026-06-04T16:33:02.971Z" }, - { url = "https://files.pythonhosted.org/packages/72/11/5da87abe20047c8962361473923ebb2f62b595250126aadfad8c20649c1e/ruff-0.15.16-py3-none-manylinux_2_17_x86_64.manylinux2014_x86_64.whl", hash = "sha256:bb27515fa6240fb586ae82b901a59e67d24acff86f2190b433dc542fe0435aeb", size = 11373541, upload-time = "2026-06-04T16:32:47.007Z" }, - { url = "https://files.pythonhosted.org/packages/fe/2a/8554754c23a854ae3fd6b507e36ad61ddb121e298c6d5d617dec94ed0f14/ruff-0.15.16-py3-none-manylinux_2_31_riscv64.whl", hash = "sha256:a267c46ba1593fc26b8eecbea050b39d40c0b6bb7781ee11c90a02cd10032951", size = 11353014, upload-time = "2026-06-04T16:32:34.795Z" }, - { url = "https://files.pythonhosted.org/packages/62/25/62ea41529ec89f742ea3fed9cb1059c72877ec7cf9b9e99ac9cf3294d1d9/ruff-0.15.16-py3-none-musllinux_1_2_aarch64.whl", hash = "sha256:528c68f39a91498a8d50e91ff5985df3d105782bab49cc378e73ac26bff083e8", size = 10737467, upload-time = "2026-06-04T16:32:26.348Z" }, - { url = "https://files.pythonhosted.org/packages/90/17/334d3ad9de4d40f9dd58fdd09e35ce64553bb501e2f19a839e2fb6be14fc/ruff-0.15.16-py3-none-musllinux_1_2_armv7l.whl", hash = "sha256:7ed55c58950df60589a9a7a5d2f8fa5f54ebd287163be805adfe6ee95a9de123", size = 10521910, upload-time = "2026-06-04T16:32:32.54Z" }, - { url = "https://files.pythonhosted.org/packages/4d/bd/3ac7c6ae77a885c1004b3dda2446ea401768d24f851c14b4ad4b24f6639c/ruff-0.15.16-py3-none-musllinux_1_2_i686.whl", hash = "sha256:d482feaf51512b50f9790ceb417a56a61dd1e9d9bf967662b9ed27c01b34f53a", size = 10979190, upload-time = "2026-06-04T16:32:57.492Z" }, - { url = "https://files.pythonhosted.org/packages/33/d7/609546e6a413c3f216fbf2a50c928f97c80939154f6a0503114094a86191/ruff-0.15.16-py3-none-musllinux_1_2_x86_64.whl", hash = "sha256:1e15bc8c94513dae2a40cc9ef07c94fdd4ecc9e29dabebeebe170f952322c9e3", size = 11477014, upload-time = "2026-06-04T16:32:44.687Z" }, - { url = "https://files.pythonhosted.org/packages/74/0d/f2cd247ad32633a5c36e97141a2c21b11c6279f7957bc2ff360b1e08fddd/ruff-0.15.16-py3-none-win32.whl", hash = "sha256:580378f7bd4aa25f72e74aa54948a9622f142b1e509521dd10902e886681cc1e", size = 10735541, upload-time = "2026-06-04T16:32:30.145Z" }, - { url = "https://files.pythonhosted.org/packages/8b/9e/02e845ef151b1dee585e55c4739f8e1734ae1d9f1221dff65761c162208b/ruff-0.15.16-py3-none-win_amd64.whl", hash = "sha256:408256017284eddf98fff77b29aa4fb30f586042d535b2d9befc6512f400aaec", size = 11843403, upload-time = "2026-06-04T16:32:39.76Z" }, - { url = "https://files.pythonhosted.org/packages/15/19/016553f86f207450aebebc2b2b5088d086b901cc8186c02ac4284db3bd88/ruff-0.15.16-py3-none-win_arm64.whl", hash = "sha256:8cd61783afb39638a7133ef0d2dfb1e91277593962f81b5a8423eb0b888a6121", size = 11134555, upload-time = "2026-06-04T16:33:00.136Z" }, +version = "0.15.18" +source = { registry = "https://pypi.org/simple" } +sdist = { url = "https://files.pythonhosted.org/packages/74/98/1295ad5a5aa9bc85bdcdfa5d82fe7b49c61af5657df4f227637ff9de0da6/ruff-0.15.18.tar.gz", hash = "sha256:2698a964c70e8bf402dcb99c8810472d270d141e7aa8c4e13599fd52033a2f33", size = 4761437, upload-time = "2026-06-18T18:25:39.224Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/b9/d0/686e984941269621e2be72612d5c1e461f8f7b38415a2a7d7a81c8ae6715/ruff-0.15.18-py3-none-linux_armv6l.whl", hash = "sha256:8b6850172348c8381b8b3084c5915a4393c2373b9b54cd5b5e1ea15812bc10df", size = 10887308, upload-time = "2026-06-18T18:25:03.062Z" }, + { url = "https://files.pythonhosted.org/packages/ed/21/bc4123e3f5515ee99f8ce1eb93a14a0628fe4d1678663cd08f933ac16931/ruff-0.15.18-py3-none-macosx_10_12_x86_64.whl", hash = "sha256:3fccc153a85417dcd976883160cacce486997b0a0058dd18f54b8aaaac7d1ce2", size = 11281305, upload-time = "2026-06-18T18:25:30.026Z" }, + { url = "https://files.pythonhosted.org/packages/51/93/4769464c25cf7ab2acb3c7dda9cad3d867eb41c59565b3e2a9d17249c90c/ruff-0.15.18-py3-none-macosx_11_0_arm64.whl", hash = "sha256:08d4c86a68f2c3ec2c9d56380a71fb4a4f65373055cbb8caabd645e9102f38d4", size = 10641215, upload-time = "2026-06-18T18:25:15.802Z" }, + { url = "https://files.pythonhosted.org/packages/6c/42/56926d17120db2c208d76bf60a1a019644dd9e91dc27f0f95c9caddb1366/ruff-0.15.18-py3-none-manylinux_2_17_aarch64.manylinux2014_aarch64.whl", hash = "sha256:37e5108745c2c0705da916d7d4de533ddf547051ef45f62888c31bae73f66318", size = 10957224, upload-time = "2026-06-18T18:25:36.955Z" }, + { url = "https://files.pythonhosted.org/packages/22/4f/d43fab8d8189afde803103022d000a8ef9f230616d436d52a8b2b8d63b50/ruff-0.15.18-py3-none-manylinux_2_17_armv7l.manylinux2014_armv7l.whl", hash = "sha256:56949a6ce8b3abde54c0bcb22cebfe57e8771cadc84b407ae8b8eaf67ebdcd43", size = 10699024, upload-time = "2026-06-18T18:25:05.707Z" }, + { url = "https://files.pythonhosted.org/packages/63/42/1e3e4c68bd408b9768cf3e439acbe2c78245225faef253f7028a0cdb63e0/ruff-0.15.18-py3-none-manylinux_2_17_i686.manylinux2014_i686.whl", hash = "sha256:01a754cd6a1b630d3f97e33eb452cf7a98040482318e870f8bc52a5a30e62657", size = 11491458, upload-time = "2026-06-18T18:25:20.275Z" }, + { url = "https://files.pythonhosted.org/packages/20/77/47a3484bea8521e14a203d98c389c5c97846675e4f02734672da4a69b52a/ruff-0.15.18-py3-none-manylinux_2_17_ppc64le.manylinux2014_ppc64le.whl", hash = "sha256:6ba7a07e03a44dbf10bb086ee06705b173625014ec99f73a7e6836a5e5590a0c", size = 12383752, upload-time = "2026-06-18T18:25:22.535Z" }, + { url = "https://files.pythonhosted.org/packages/0a/ca/054159590787023d83b658a1a1819c4c8910114e7015069340b71c0961cb/ruff-0.15.18-py3-none-manylinux_2_17_s390x.manylinux2014_s390x.whl", hash = "sha256:5a2c40a41a4cadbcf5897b548ab29dfe248b20c540961c0247d98a3973c70403", size = 11577923, upload-time = "2026-06-18T18:25:10.702Z" }, + { url = "https://files.pythonhosted.org/packages/6d/ff/d353d6b7bbd73cc0ec37f4463d7540e45e894338abdd9964eee0de332708/ruff-0.15.18-py3-none-manylinux_2_17_x86_64.manylinux2014_x86_64.whl", hash = "sha256:5f0480ce690cbb6c4db6e5d08f19fce98e10ba131a8b60c1bcdac42771e3ae2d", size = 11583925, upload-time = "2026-06-18T18:25:32.391Z" }, + { url = "https://files.pythonhosted.org/packages/c1/4a/891f89b9c296ed3e5f3ece1a5629badc989d9a8fdaa30431aaf4774bc1c2/ruff-0.15.18-py3-none-manylinux_2_31_riscv64.whl", hash = "sha256:2330215f1f393fa8733f55edce04fcf94c36a2c460fcde31f78cc84e4951e9b1", size = 11582834, upload-time = "2026-06-18T18:25:27.309Z" }, + { url = "https://files.pythonhosted.org/packages/32/a3/ed9e370154bf85de360b93c03026157f02d4943b2d01ff4945f4429f8e8a/ruff-0.15.18-py3-none-musllinux_1_2_aarch64.whl", hash = "sha256:a6aa6a3d979e48ae617578183674bf264fbe7d0114a796a26bd678d67963c7ff", size = 10927328, upload-time = "2026-06-18T18:25:34.676Z" }, + { url = "https://files.pythonhosted.org/packages/f5/d1/5cf5909329fedb5d39d555ee818ba5cf4638e1a301b89785d34f2905bfcb/ruff-0.15.18-py3-none-musllinux_1_2_armv7l.whl", hash = "sha256:a81beadbbff2c9c245561ae3f77b16709d87f35eec650d0501679239d3449b22", size = 10693187, upload-time = "2026-06-18T18:25:08.245Z" }, + { url = "https://files.pythonhosted.org/packages/fd/44/ff6c635cf2c4f4e7b618b6640da057376baa36014695487d88aed4794268/ruff-0.15.18-py3-none-musllinux_1_2_i686.whl", hash = "sha256:2186d9e940ae332ab293623a75b5f4fe49565f449954d50a72a046683aa6b809", size = 11208721, upload-time = "2026-06-18T18:25:41.327Z" }, + { url = "https://files.pythonhosted.org/packages/88/d9/5baa2a30861adfb7022cf33c1e35b2fc18085b08c16f83eff4c7b99a5f48/ruff-0.15.18-py3-none-musllinux_1_2_x86_64.whl", hash = "sha256:5c2abf140438032bc77b2284a6c9944ecd8a19e5f1c7b52b1b8e4a0a80d19a7a", size = 11678599, upload-time = "2026-06-18T18:25:13.607Z" }, + { url = "https://files.pythonhosted.org/packages/c3/1a/0725a7cfdc32ff769efb96ee782bec882e16448c5d9e3be947ec4c04ce27/ruff-0.15.18-py3-none-win32.whl", hash = "sha256:02299e6e9fa5b297a3f6d5d10d7bcd655c925b028bb8b9d4588214549c6b9ec4", size = 10901903, upload-time = "2026-06-18T18:25:24.755Z" }, + { url = "https://files.pythonhosted.org/packages/f3/51/805d9f6fb7970505c3504794a5ec350f605361b807fef4dcf214ebd35e72/ruff-0.15.18-py3-none-win_amd64.whl", hash = "sha256:dac80dc8d26b2257dbefabed62f5d255c3937b4ccb122da1fc634794fa3578b3", size = 12041189, upload-time = "2026-06-18T18:25:17.915Z" }, + { url = "https://files.pythonhosted.org/packages/29/4c/67bb45e41609eb4726f1bfeb59e083cf91d14c696d4bd14c234a980be93d/ruff-0.15.18-py3-none-win_arm64.whl", hash = "sha256:b2c9257fcbd4a3e5b977a1904e6facca016bafe2edc17df24db67cfaee03b4e4", size = 11329958, upload-time = "2026-06-18T18:25:43.686Z" }, ] [[package]] From 7cea2671e75ff866dd8327b24b063030a8c3659f Mon Sep 17 00:00:00 2001 From: Noah Stapp Date: Mon, 29 Jun 2026 15:44:08 -0400 Subject: [PATCH 7/9] PYTHON-5859 - Remove mention and link to IWM from the changelog (#2899) --- doc/changelog.rst | 5 ++--- pymongo/asynchronous/mongo_client.py | 1 + pymongo/synchronous/mongo_client.py | 1 + 3 files changed, 4 insertions(+), 3 deletions(-) diff --git a/doc/changelog.rst b/doc/changelog.rst index 585ea045c8..b3e1c75319 100644 --- a/doc/changelog.rst +++ b/doc/changelog.rst @@ -21,9 +21,8 @@ PyMongo 4.17 brings a number of changes including: - Added the :meth:`~pymongo.asynchronous.client_session.AsyncClientSession.bind` and :meth:`~pymongo.client_session.ClientSession.bind` methods that allow users to bind a session to all database operations within the scope of a context manager instead of having to explicitly pass the session to each individual operation. See the `Transactions docs `_ for examples and more information. -- Added support for MongoDB's Intelligent Workload Management (IWM) and ingress connection rate limiting features. - The driver now gracefully handles write-blocking scenarios and optimizes connection establishment during high-load conditions to maintain application availability. - See the `IWM `_ or `Overload Errors `_ docs for more information. +- Added support for MongoDB's Intelligent Workload Management (IWM) and ingress connection rate limiting features in MongoDB server version 9.0. + The driver will gracefully handle write-blocking scenarios and optimizes connection establishment during high-load conditions to maintain application availability. Changes in Version 4.16.0 (2026/01/07) -------------------------------------- diff --git a/pymongo/asynchronous/mongo_client.py b/pymongo/asynchronous/mongo_client.py index 6aeea53f4c..834831c4ef 100644 --- a/pymongo/asynchronous/mongo_client.py +++ b/pymongo/asynchronous/mongo_client.py @@ -609,6 +609,7 @@ def __init__( details. | **Overload retry options:** + | (Requires MongoDB server version 9.0+.) - `max_adaptive_retries`: (int) How many retries to allow for overload errors. Defaults to ``2``. - `enable_overload_retargeting`: (boolean) Whether overload retargeting is enabled for this client. diff --git a/pymongo/synchronous/mongo_client.py b/pymongo/synchronous/mongo_client.py index 6b7c5d9c98..ac6974bbfa 100644 --- a/pymongo/synchronous/mongo_client.py +++ b/pymongo/synchronous/mongo_client.py @@ -610,6 +610,7 @@ def __init__( details. | **Overload retry options:** + | (Requires MongoDB server version 9.0+.) - `max_adaptive_retries`: (int) How many retries to allow for overload errors. Defaults to ``2``. - `enable_overload_retargeting`: (boolean) Whether overload retargeting is enabled for this client. From 19fd1b1debcbe8fe85109a6571f800b8324be430 Mon Sep 17 00:00:00 2001 From: Steven Silvester Date: Tue, 30 Jun 2026 06:34:38 -0500 Subject: [PATCH 8/9] PYTHON-5745 Consolidate command telemetry (#2891) --- pymongo/_telemetry.py | 185 +++++++++++++++++++++++++ pymongo/asynchronous/command_runner.py | 148 +++----------------- pymongo/asynchronous/mongo_client.py | 6 +- pymongo/asynchronous/pool.py | 4 +- pymongo/asynchronous/server.py | 4 - pymongo/message.py | 3 - pymongo/pool_shared.py | 11 ++ pymongo/synchronous/command_runner.py | 148 +++----------------- pymongo/synchronous/mongo_client.py | 6 +- pymongo/synchronous/pool.py | 4 +- pymongo/synchronous/server.py | 4 - 11 files changed, 252 insertions(+), 271 deletions(-) create mode 100644 pymongo/_telemetry.py diff --git a/pymongo/_telemetry.py b/pymongo/_telemetry.py new file mode 100644 index 0000000000..471a013eb9 --- /dev/null +++ b/pymongo/_telemetry.py @@ -0,0 +1,185 @@ +# Copyright 2026-present MongoDB, Inc. +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# https://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +"""Internal helpers combining structured logging with APM event publishing.""" + +from __future__ import annotations + +import datetime +import logging +from collections.abc import MutableMapping +from typing import TYPE_CHECKING, Any, Optional + +from pymongo.logger import _COMMAND_LOGGER, _CommandStatusMessage, _debug_log +from pymongo.pool_shared import _ConnectionTelemetryInfo + +if TYPE_CHECKING: + from bson.objectid import ObjectId + from pymongo.monitoring import _EventListeners + from pymongo.typings import _DocumentOut + + +class _CommandTelemetry: + """Combines structured logging and APM event publishing for a single command. + + Construct once per command, call :meth:`started` before the network send, + then call :meth:`succeeded` or :meth:`failed` when the outcome is known. + Duration is measured from the :meth:`started` call. + """ + + __slots__ = ( + "_active", + "_cmd", + "_conn", + "_dbname", + "_duration", + "_listeners", + "_name", + "_op_id", + "_publish", + "_request_id", + "_should_log", + "_start", + "_topology_id", + ) + + def __init__( + self, + topology_id: Optional[ObjectId], + conn: _ConnectionTelemetryInfo, + listeners: Optional[_EventListeners], + cmd: MutableMapping[str, Any], + dbname: str, + request_id: int, + op_id: Optional[int], + ) -> None: + self._topology_id = topology_id + self._should_log = topology_id is not None and _COMMAND_LOGGER.isEnabledFor(logging.DEBUG) + self._publish = listeners is not None and listeners.enabled_for_commands + self._active = self._should_log or self._publish + self._listeners = listeners + self._conn = conn + self._cmd = cmd + self._name = next(iter(cmd)) + self._dbname = dbname + self._request_id = request_id + self._op_id = op_id + self._start: datetime.datetime + self._duration: datetime.timedelta + + def _emit_log(self, message: _CommandStatusMessage, **extra: Any) -> None: + _debug_log( + _COMMAND_LOGGER, + message=message, + clientId=self._topology_id, + commandName=self._name, + databaseName=self._dbname, + requestId=self._request_id, + operationId=self._request_id, + driverConnectionId=self._conn.id, + serverConnectionId=self._conn.server_connection_id, + serverHost=self._conn.address[0], + serverPort=self._conn.address[1], + serviceId=self._conn.service_id, + **extra, + ) + + def started(self, orig: MutableMapping[str, Any], ensure_db: bool) -> None: + """Emit the STARTED log entry and APM event, and start the duration clock.""" + self._start = datetime.datetime.now() + if not self._active: + return + if self._should_log: + self._emit_log(_CommandStatusMessage.STARTED, command=self._cmd) + if self._publish: + assert self._listeners is not None + if ensure_db and "$db" not in orig: + orig["$db"] = self._dbname + self._listeners.publish_command_start( + orig, + self._dbname, + self._request_id, + self._conn.address, + self._conn.server_connection_id, + self._op_id, + service_id=self._conn.service_id, + ) + + @property + def duration(self) -> datetime.timedelta: + """Duration from :meth:`started` to :meth:`succeeded` or :meth:`failed`.""" + return self._duration + + def succeeded( + self, + reply: _DocumentOut, + command_name: str, + speculative_hello: bool, + ) -> None: + """Emit the SUCCEEDED log entry and APM event.""" + self._duration = datetime.datetime.now() - self._start + if not self._active: + return + if self._should_log: + self._emit_log( + _CommandStatusMessage.SUCCEEDED, + durationMS=self._duration, + reply=reply, + speculative_authenticate=speculative_hello, + ) + if self._publish: + assert self._listeners is not None + self._listeners.publish_command_success( + self._duration, + reply, + command_name, + self._request_id, + self._conn.address, + self._conn.server_connection_id, + self._op_id, + service_id=self._conn.service_id, + speculative_hello=speculative_hello, + database_name=self._dbname, + ) + + def failed( + self, + failure: _DocumentOut, + command_name: str, + is_server_side_error: bool, + ) -> None: + """Emit the FAILED log entry and APM event.""" + self._duration = datetime.datetime.now() - self._start + if not self._active: + return + if self._should_log: + self._emit_log( + _CommandStatusMessage.FAILED, + durationMS=self._duration, + failure=failure, + isServerSideError=is_server_side_error, + ) + if self._publish: + assert self._listeners is not None + self._listeners.publish_command_failure( + self._duration, + failure, + command_name, + self._request_id, + self._conn.address, + self._conn.server_connection_id, + self._op_id, + service_id=self._conn.service_id, + database_name=self._dbname, + ) diff --git a/pymongo/asynchronous/command_runner.py b/pymongo/asynchronous/command_runner.py index b663893a7b..1f32cc744e 100644 --- a/pymongo/asynchronous/command_runner.py +++ b/pymongo/asynchronous/command_runner.py @@ -36,7 +36,6 @@ from __future__ import annotations import datetime -import logging from collections.abc import Mapping, MutableMapping, Sequence from typing import ( TYPE_CHECKING, @@ -49,14 +48,15 @@ from bson import _decode_all_selective from pymongo import _csot, helpers_shared, message +from pymongo._telemetry import _CommandTelemetry from pymongo.compression_support import _NO_COMPRESSION from pymongo.errors import NotPrimaryError, OperationFailure -from pymongo.logger import _COMMAND_LOGGER, _CommandStatusMessage, _debug_log from pymongo.message import _BulkWriteContextBase, _convert_exception, _OpMsg from pymongo.monitoring import _is_speculative_authenticate if TYPE_CHECKING: from bson import CodecOptions + from bson.objectid import ObjectId from pymongo.asynchronous.client_session import AsyncClientSession from pymongo.asynchronous.mongo_client import AsyncMongoClient from pymongo.asynchronous.pool import AsyncConnection @@ -65,7 +65,7 @@ from pymongo.pool_options import PoolOptions from pymongo.read_concern import ReadConcern from pymongo.read_preferences import _ServerMode - from pymongo.typings import _Address, _CollationIn, _DocumentOut, _DocumentType + from pymongo.typings import _CollationIn, _DocumentOut, _DocumentType from pymongo.write_concern import WriteConcern _IS_SYNC = False @@ -81,8 +81,7 @@ async def _run_command( client: Optional[AsyncMongoClient[Any]], session: Optional[AsyncClientSession], listeners: Optional[_EventListeners], - address: Optional[_Address], - start: datetime.datetime, + topology_id: Optional[ObjectId], codec_options: CodecOptions[_DocumentType], user_fields: Optional[Mapping[str, Any]] = None, orig: Optional[MutableMapping[str, Any]] = None, @@ -118,12 +117,12 @@ async def _run_command( :param request_id: The request id of the encoded message (``0`` when ``more_to_come`` and no message is sent). :param msg: The encoded bytes to send (ignored when ``more_to_come``). - :param client: The AsyncMongoClient, for ``$clusterTime`` gossip, logging, - and decryption. ``None`` disables those steps (e.g. during handshake). + :param client: The AsyncMongoClient, for ``$clusterTime`` gossip and + decryption. ``None`` disables those steps (e.g. during handshake). :param session: The session to update from the response. :param listeners: The event listeners, or ``None`` to disable APM. - :param address: The (host, port) of ``conn`` for APM events. - :param start: The ``datetime`` the operation began, for duration timing. + :param topology_id: The client topology id for structured logging, or + ``None`` to disable command logging. :param codec_options: The CodecOptions used to decode the reply. :param user_fields: Response fields decoded with the codec's TypeDecoders. :param orig: The command document published in the ``STARTED`` APM event; @@ -159,38 +158,9 @@ async def _run_command( command_name = name if orig is None: orig = cmd - publish = listeners is not None and listeners.enabled_for_commands - - if client is not None and _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.STARTED, - clientId=client._topology_settings._topology_id, - command=cmd, - commandName=name, - databaseName=dbname, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - ) - if publish: - assert listeners is not None - assert address is not None - if ensure_db and "$db" not in orig: - orig["$db"] = dbname - listeners.publish_command_start( - orig, - dbname, - request_id, - address, - conn.server_connection_id, - op_id, - service_id=conn.service_id, - ) + + telemetry = _CommandTelemetry(topology_id, conn, listeners, cmd, dbname, request_id, op_id) + telemetry.started(orig, ensure_db) reply: Optional[_OpMsg] = None docs: list[dict[str, Any]] = [{"ok": 1}] @@ -234,80 +204,14 @@ async def _run_command( pool_opts=pool_opts, ) except Exception as exc: - duration = datetime.datetime.now() - start if isinstance(exc, (NotPrimaryError, OperationFailure)): failure: _DocumentOut = exc.details # type: ignore[assignment] else: failure = _convert_exception(exc) - if client is not None and _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.FAILED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - failure=failure, - commandName=name, - databaseName=dbname, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - isServerSideError=isinstance(exc, OperationFailure), - ) - if publish: - assert listeners is not None - assert address is not None - listeners.publish_command_failure( - duration, - failure, - command_name, - request_id, - address, - conn.server_connection_id, - op_id, - service_id=conn.service_id, - database_name=dbname, - ) + telemetry.failed(failure, command_name, isinstance(exc, OperationFailure)) raise - duration = datetime.datetime.now() - start - published_reply = docs[0] - if client is not None and _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.SUCCEEDED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - reply=published_reply, - commandName=name, - databaseName=dbname, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - speculative_authenticate="speculativeAuthenticate" in orig, - ) - if publish: - assert listeners is not None - assert address is not None - listeners.publish_command_success( - duration, - published_reply, - command_name, - request_id, - address, - conn.server_connection_id, - op_id, - service_id=conn.service_id, - speculative_hello=speculative_hello, - database_name=dbname, - ) + telemetry.succeeded(docs[0], command_name, speculative_hello) if client and client._encrypter and reply and decrypt_reply: decrypted = await client._encrypter.decrypt(reply.raw_command_response()) @@ -315,7 +219,7 @@ async def _run_command( "list[dict[str, Any]]", _decode_all_selective(decrypted, codec_options, user_fields) ) - return docs, reply, duration + return docs, reply, telemetry.duration async def run_bulk_write_command( @@ -341,6 +245,7 @@ async def run_bulk_write_command( :param max_doc_size: The largest document size in the batch, passed to ``conn.send_message``. :param unacknowledged: When ``True``, send only and fake an ``{"ok": 1}`` reply. """ + topology_id = client._topology_id if client is not None else None return await _run_command( bwc.conn, # type: ignore[arg-type] cmd, @@ -350,8 +255,7 @@ async def run_bulk_write_command( client=client, session=bwc.session, # type: ignore[arg-type] listeners=bwc.listeners, - address=bwc.conn.address, # type: ignore[union-attr] - start=bwc.start_time, + topology_id=topology_id, codec_options=bwc.codec, op_id=bwc.op_id, command_name=bwc.name, @@ -372,8 +276,6 @@ async def run_cursor_command( client: Optional[AsyncMongoClient[Any]], session: Optional[AsyncClientSession], listeners: Optional[_EventListeners], - address: Optional[_Address], - start: datetime.datetime, codec_options: CodecOptions[_DocumentType], command_name: str, user_fields: Optional[Mapping[str, Any]] = None, @@ -393,8 +295,6 @@ async def run_cursor_command( :param client: The AsyncMongoClient, for ``$clusterTime`` gossip and logging. :param session: The session to update from the response. :param listeners: The event listeners, or ``None`` to disable APM. - :param address: The (host, port) of ``conn`` for APM events. - :param start: The ``datetime`` the operation began, for duration timing. :param codec_options: The CodecOptions used to decode the reply. :param command_name: The command name for APM events. :param user_fields: Response fields decoded with the codec's TypeDecoders. @@ -405,6 +305,7 @@ async def run_cursor_command( reply's own ``unpack_response`` is used. :param cursor_id: The cursor id passed to ``unpack_res``. """ + topology_id = client._topology_id if client is not None else None return await _run_command( conn, cmd, @@ -414,8 +315,7 @@ async def run_cursor_command( client=client, session=session, listeners=listeners, - address=address, - start=start, + topology_id=topology_id, codec_options=codec_options, user_fields=user_fields, command_name=command_name, @@ -438,7 +338,6 @@ async def run_command( client: Optional[AsyncMongoClient[Any]], check: bool = True, allowable_errors: Optional[Sequence[Union[str, int]]] = None, - address: Optional[_Address] = None, listeners: Optional[_EventListeners] = None, max_bson_size: Optional[int] = None, read_concern: Optional[ReadConcern] = None, @@ -465,7 +364,6 @@ async def run_command( :param client: The AsyncMongoClient, for ``$clusterTime`` gossip and logging. :param check: Raise OperationFailure if there are errors. :param allowable_errors: Errors to ignore when ``check`` is True. - :param address: The (host, port) of ``conn`` for APM events. :param listeners: The event listeners, or ``None`` to disable APM. :param max_bson_size: The maximum encoded BSON size for this server. :param read_concern: The read concern for this command. @@ -480,7 +378,6 @@ async def run_command( :param write_concern: The write concern for this command. Applied via CSOT. """ name = next(iter(spec)) - speculative_hello = False # Publish the original command document, perhaps with lsid and $clusterTime. orig = spec @@ -492,10 +389,8 @@ async def run_command( if collation is not None: spec["collation"] = collation - publish = listeners is not None and listeners.enabled_for_commands - start = datetime.datetime.now() - if publish: - speculative_hello = _is_speculative_authenticate(name, spec) + topology_id = client._topology_id if client is not None else None + speculative_hello = _is_speculative_authenticate(name, spec) if compression_ctx and name.lower() in _NO_COMPRESSION: compression_ctx = None @@ -529,8 +424,7 @@ async def run_command( client=client, session=session, listeners=listeners, - address=address, - start=start, + topology_id=topology_id, codec_options=codec_options, user_fields=user_fields, orig=orig, diff --git a/pymongo/asynchronous/mongo_client.py b/pymongo/asynchronous/mongo_client.py index 834831c4ef..a558f96356 100644 --- a/pymongo/asynchronous/mongo_client.py +++ b/pymongo/asynchronous/mongo_client.py @@ -1249,6 +1249,10 @@ def topology_description(self) -> TopologyDescription: ) return self._topology.description + @property + def _topology_id(self) -> Optional[ObjectId]: + return self._topology_settings._topology_id + @property def nodes(self) -> frozenset[_Address]: """Set of all currently connected servers. @@ -3013,7 +3017,7 @@ async def _write(self) -> T: _debug_log( _COMMAND_LOGGER, message=f"Retrying write attempt number {self._attempt_number}", - clientId=self._client._topology_settings._topology_id, + clientId=self._client._topology_id, commandName=self._operation, operationId=self._operation_id, ) diff --git a/pymongo/asynchronous/pool.py b/pymongo/asynchronous/pool.py index 60acb93fcd..4ed3b85dbf 100644 --- a/pymongo/asynchronous/pool.py +++ b/pymongo/asynchronous/pool.py @@ -81,6 +81,7 @@ SSLErrors, _CancellationContext, _configured_protocol_interface, + _ConnectionTelemetryInfo, _raise_connection_failure, ) from pymongo.read_preferences import ReadPreference @@ -109,7 +110,7 @@ _IS_SYNC = False -class AsyncConnection: +class AsyncConnection(_ConnectionTelemetryInfo): """Store a connection with some metadata. :param conn: a raw connection object @@ -405,7 +406,6 @@ async def command( client, check, allowable_errors, - self.address, listeners, self.max_bson_size, read_concern, diff --git a/pymongo/asynchronous/server.py b/pymongo/asynchronous/server.py index 9a6984f486..57158dfc44 100644 --- a/pymongo/asynchronous/server.py +++ b/pymongo/asynchronous/server.py @@ -18,7 +18,6 @@ import logging from contextlib import AbstractAsyncContextManager -from datetime import datetime from typing import ( TYPE_CHECKING, Any, @@ -155,7 +154,6 @@ async def run_operation( :param client: An AsyncMongoClient instance. """ assert listeners is not None - start = datetime.now() use_cmd = operation.use_command(conn) more_to_come = bool(operation.conn_mgr and operation.conn_mgr.more_to_come) @@ -179,8 +177,6 @@ async def run_operation( client=client, session=operation.session, # type: ignore[arg-type] listeners=listeners, - address=conn.address, - start=start, codec_options=operation.codec_options, user_fields=user_fields, command_name=operation.name, diff --git a/pymongo/message.py b/pymongo/message.py index bcd2810895..2e3aa1dcbd 100644 --- a/pymongo/message.py +++ b/pymongo/message.py @@ -22,7 +22,6 @@ from __future__ import annotations -import datetime import random import struct from collections.abc import Iterable, Mapping, MutableMapping @@ -451,7 +450,6 @@ class _BulkWriteContextBase: "op_id", "op_type", "session", - "start_time", ) def __init__( @@ -471,7 +469,6 @@ def __init__( self.listeners = listeners self.name = cmd_name self.field = _FIELD_MAP[self.name] - self.start_time = datetime.datetime.now() self.session = session self.compress = bool(conn.compression_context) self.op_type = op_type diff --git a/pymongo/pool_shared.py b/pymongo/pool_shared.py index c97b0eb217..410ffd8189 100644 --- a/pymongo/pool_shared.py +++ b/pymongo/pool_shared.py @@ -26,6 +26,7 @@ Any, NoReturn, Optional, + Protocol, Union, ) @@ -44,10 +45,20 @@ SSLErrors = (PYSSLError, SSLError) if TYPE_CHECKING: + from bson.objectid import ObjectId from pymongo.pyopenssl_context import _sslConn from pymongo.typings import _Address +class _ConnectionTelemetryInfo(Protocol): + """Protocol for connection fields consumed by :class:`~pymongo._telemetry._CommandTelemetry`.""" + + id: int + server_connection_id: Optional[int] + address: tuple[str, int] + service_id: Optional[ObjectId] + + def _get_ssl_session(ssl_sock: Any) -> Optional[Any]: """Return the TLS session from an SSL socket, handling both PyOpenSSL and stdlib ssl.""" if hasattr(ssl_sock, "get_session"): diff --git a/pymongo/synchronous/command_runner.py b/pymongo/synchronous/command_runner.py index 7402451c7c..077e0f9409 100644 --- a/pymongo/synchronous/command_runner.py +++ b/pymongo/synchronous/command_runner.py @@ -36,7 +36,6 @@ from __future__ import annotations import datetime -import logging from collections.abc import Mapping, MutableMapping, Sequence from typing import ( TYPE_CHECKING, @@ -49,14 +48,15 @@ from bson import _decode_all_selective from pymongo import _csot, helpers_shared, message +from pymongo._telemetry import _CommandTelemetry from pymongo.compression_support import _NO_COMPRESSION from pymongo.errors import NotPrimaryError, OperationFailure -from pymongo.logger import _COMMAND_LOGGER, _CommandStatusMessage, _debug_log from pymongo.message import _BulkWriteContextBase, _convert_exception, _OpMsg from pymongo.monitoring import _is_speculative_authenticate if TYPE_CHECKING: from bson import CodecOptions + from bson.objectid import ObjectId from pymongo.compression_support import SnappyContext, ZlibContext, ZstdContext from pymongo.monitoring import _EventListeners from pymongo.pool_options import PoolOptions @@ -65,7 +65,7 @@ from pymongo.synchronous.client_session import ClientSession from pymongo.synchronous.mongo_client import MongoClient from pymongo.synchronous.pool import Connection - from pymongo.typings import _Address, _CollationIn, _DocumentOut, _DocumentType + from pymongo.typings import _CollationIn, _DocumentOut, _DocumentType from pymongo.write_concern import WriteConcern _IS_SYNC = True @@ -81,8 +81,7 @@ def _run_command( client: Optional[MongoClient[Any]], session: Optional[ClientSession], listeners: Optional[_EventListeners], - address: Optional[_Address], - start: datetime.datetime, + topology_id: Optional[ObjectId], codec_options: CodecOptions[_DocumentType], user_fields: Optional[Mapping[str, Any]] = None, orig: Optional[MutableMapping[str, Any]] = None, @@ -118,12 +117,12 @@ def _run_command( :param request_id: The request id of the encoded message (``0`` when ``more_to_come`` and no message is sent). :param msg: The encoded bytes to send (ignored when ``more_to_come``). - :param client: The MongoClient, for ``$clusterTime`` gossip, logging, - and decryption. ``None`` disables those steps (e.g. during handshake). + :param client: The MongoClient, for ``$clusterTime`` gossip and + decryption. ``None`` disables those steps (e.g. during handshake). :param session: The session to update from the response. :param listeners: The event listeners, or ``None`` to disable APM. - :param address: The (host, port) of ``conn`` for APM events. - :param start: The ``datetime`` the operation began, for duration timing. + :param topology_id: The client topology id for structured logging, or + ``None`` to disable command logging. :param codec_options: The CodecOptions used to decode the reply. :param user_fields: Response fields decoded with the codec's TypeDecoders. :param orig: The command document published in the ``STARTED`` APM event; @@ -159,38 +158,9 @@ def _run_command( command_name = name if orig is None: orig = cmd - publish = listeners is not None and listeners.enabled_for_commands - - if client is not None and _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.STARTED, - clientId=client._topology_settings._topology_id, - command=cmd, - commandName=name, - databaseName=dbname, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - ) - if publish: - assert listeners is not None - assert address is not None - if ensure_db and "$db" not in orig: - orig["$db"] = dbname - listeners.publish_command_start( - orig, - dbname, - request_id, - address, - conn.server_connection_id, - op_id, - service_id=conn.service_id, - ) + + telemetry = _CommandTelemetry(topology_id, conn, listeners, cmd, dbname, request_id, op_id) + telemetry.started(orig, ensure_db) reply: Optional[_OpMsg] = None docs: list[dict[str, Any]] = [{"ok": 1}] @@ -234,80 +204,14 @@ def _run_command( pool_opts=pool_opts, ) except Exception as exc: - duration = datetime.datetime.now() - start if isinstance(exc, (NotPrimaryError, OperationFailure)): failure: _DocumentOut = exc.details # type: ignore[assignment] else: failure = _convert_exception(exc) - if client is not None and _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.FAILED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - failure=failure, - commandName=name, - databaseName=dbname, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - isServerSideError=isinstance(exc, OperationFailure), - ) - if publish: - assert listeners is not None - assert address is not None - listeners.publish_command_failure( - duration, - failure, - command_name, - request_id, - address, - conn.server_connection_id, - op_id, - service_id=conn.service_id, - database_name=dbname, - ) + telemetry.failed(failure, command_name, isinstance(exc, OperationFailure)) raise - duration = datetime.datetime.now() - start - published_reply = docs[0] - if client is not None and _COMMAND_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _COMMAND_LOGGER, - message=_CommandStatusMessage.SUCCEEDED, - clientId=client._topology_settings._topology_id, - durationMS=duration, - reply=published_reply, - commandName=name, - databaseName=dbname, - requestId=request_id, - operationId=request_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=conn.address[0], - serverPort=conn.address[1], - serviceId=conn.service_id, - speculative_authenticate="speculativeAuthenticate" in orig, - ) - if publish: - assert listeners is not None - assert address is not None - listeners.publish_command_success( - duration, - published_reply, - command_name, - request_id, - address, - conn.server_connection_id, - op_id, - service_id=conn.service_id, - speculative_hello=speculative_hello, - database_name=dbname, - ) + telemetry.succeeded(docs[0], command_name, speculative_hello) if client and client._encrypter and reply and decrypt_reply: decrypted = client._encrypter.decrypt(reply.raw_command_response()) @@ -315,7 +219,7 @@ def _run_command( "list[dict[str, Any]]", _decode_all_selective(decrypted, codec_options, user_fields) ) - return docs, reply, duration + return docs, reply, telemetry.duration def run_bulk_write_command( @@ -341,6 +245,7 @@ def run_bulk_write_command( :param max_doc_size: The largest document size in the batch, passed to ``conn.send_message``. :param unacknowledged: When ``True``, send only and fake an ``{"ok": 1}`` reply. """ + topology_id = client._topology_id if client is not None else None return _run_command( bwc.conn, # type: ignore[arg-type] cmd, @@ -350,8 +255,7 @@ def run_bulk_write_command( client=client, session=bwc.session, # type: ignore[arg-type] listeners=bwc.listeners, - address=bwc.conn.address, # type: ignore[union-attr] - start=bwc.start_time, + topology_id=topology_id, codec_options=bwc.codec, op_id=bwc.op_id, command_name=bwc.name, @@ -372,8 +276,6 @@ def run_cursor_command( client: Optional[MongoClient[Any]], session: Optional[ClientSession], listeners: Optional[_EventListeners], - address: Optional[_Address], - start: datetime.datetime, codec_options: CodecOptions[_DocumentType], command_name: str, user_fields: Optional[Mapping[str, Any]] = None, @@ -393,8 +295,6 @@ def run_cursor_command( :param client: The MongoClient, for ``$clusterTime`` gossip and logging. :param session: The session to update from the response. :param listeners: The event listeners, or ``None`` to disable APM. - :param address: The (host, port) of ``conn`` for APM events. - :param start: The ``datetime`` the operation began, for duration timing. :param codec_options: The CodecOptions used to decode the reply. :param command_name: The command name for APM events. :param user_fields: Response fields decoded with the codec's TypeDecoders. @@ -405,6 +305,7 @@ def run_cursor_command( reply's own ``unpack_response`` is used. :param cursor_id: The cursor id passed to ``unpack_res``. """ + topology_id = client._topology_id if client is not None else None return _run_command( conn, cmd, @@ -414,8 +315,7 @@ def run_cursor_command( client=client, session=session, listeners=listeners, - address=address, - start=start, + topology_id=topology_id, codec_options=codec_options, user_fields=user_fields, command_name=command_name, @@ -438,7 +338,6 @@ def run_command( client: Optional[MongoClient[Any]], check: bool = True, allowable_errors: Optional[Sequence[Union[str, int]]] = None, - address: Optional[_Address] = None, listeners: Optional[_EventListeners] = None, max_bson_size: Optional[int] = None, read_concern: Optional[ReadConcern] = None, @@ -465,7 +364,6 @@ def run_command( :param client: The MongoClient, for ``$clusterTime`` gossip and logging. :param check: Raise OperationFailure if there are errors. :param allowable_errors: Errors to ignore when ``check`` is True. - :param address: The (host, port) of ``conn`` for APM events. :param listeners: The event listeners, or ``None`` to disable APM. :param max_bson_size: The maximum encoded BSON size for this server. :param read_concern: The read concern for this command. @@ -480,7 +378,6 @@ def run_command( :param write_concern: The write concern for this command. Applied via CSOT. """ name = next(iter(spec)) - speculative_hello = False # Publish the original command document, perhaps with lsid and $clusterTime. orig = spec @@ -492,10 +389,8 @@ def run_command( if collation is not None: spec["collation"] = collation - publish = listeners is not None and listeners.enabled_for_commands - start = datetime.datetime.now() - if publish: - speculative_hello = _is_speculative_authenticate(name, spec) + topology_id = client._topology_id if client is not None else None + speculative_hello = _is_speculative_authenticate(name, spec) if compression_ctx and name.lower() in _NO_COMPRESSION: compression_ctx = None @@ -529,8 +424,7 @@ def run_command( client=client, session=session, listeners=listeners, - address=address, - start=start, + topology_id=topology_id, codec_options=codec_options, user_fields=user_fields, orig=orig, diff --git a/pymongo/synchronous/mongo_client.py b/pymongo/synchronous/mongo_client.py index ac6974bbfa..5f321afe5c 100644 --- a/pymongo/synchronous/mongo_client.py +++ b/pymongo/synchronous/mongo_client.py @@ -1250,6 +1250,10 @@ def topology_description(self) -> TopologyDescription: ) return self._topology.description + @property + def _topology_id(self) -> Optional[ObjectId]: + return self._topology_settings._topology_id + @property def nodes(self) -> frozenset[_Address]: """Set of all currently connected servers. @@ -3004,7 +3008,7 @@ def _write(self) -> T: _debug_log( _COMMAND_LOGGER, message=f"Retrying write attempt number {self._attempt_number}", - clientId=self._client._topology_settings._topology_id, + clientId=self._client._topology_id, commandName=self._operation, operationId=self._operation_id, ) diff --git a/pymongo/synchronous/pool.py b/pymongo/synchronous/pool.py index b3929b674a..1006735444 100644 --- a/pymongo/synchronous/pool.py +++ b/pymongo/synchronous/pool.py @@ -78,6 +78,7 @@ SSLErrors, _CancellationContext, _configured_socket_interface, + _ConnectionTelemetryInfo, _raise_connection_failure, ) from pymongo.read_preferences import ReadPreference @@ -109,7 +110,7 @@ _IS_SYNC = True -class Connection: +class Connection(_ConnectionTelemetryInfo): """Store a connection with some metadata. :param conn: a raw connection object @@ -405,7 +406,6 @@ def command( client, check, allowable_errors, - self.address, listeners, self.max_bson_size, read_concern, diff --git a/pymongo/synchronous/server.py b/pymongo/synchronous/server.py index 7aa017134a..09d8fb75e1 100644 --- a/pymongo/synchronous/server.py +++ b/pymongo/synchronous/server.py @@ -18,7 +18,6 @@ import logging from contextlib import AbstractContextManager -from datetime import datetime from typing import ( TYPE_CHECKING, Any, @@ -155,7 +154,6 @@ def run_operation( :param client: A MongoClient instance. """ assert listeners is not None - start = datetime.now() use_cmd = operation.use_command(conn) more_to_come = bool(operation.conn_mgr and operation.conn_mgr.more_to_come) @@ -179,8 +177,6 @@ def run_operation( client=client, session=operation.session, # type: ignore[arg-type] listeners=listeners, - address=conn.address, - start=start, codec_options=operation.codec_options, user_fields=user_fields, command_name=operation.name, From 8c0f314a1ea2c8584d86ed55ba6d6b25aa1c57d6 Mon Sep 17 00:00:00 2001 From: Steven Silvester Date: Tue, 30 Jun 2026 08:27:54 -0500 Subject: [PATCH 9/9] PYTHON-5846 Consolidate CMAP, heartbeat, and SDAM telemetry into _telemetry.py Add _CmapTelemetry, _HeartbeatTelemetry, and _SdamTelemetry classes to eliminate the repetitive if-enabled_for_cmap / if-logger.isEnabledFor boilerplate spread across pool.py, monitor.py, topology.py, and server.py. --- pymongo/_telemetry.py | 340 ++++++++++++++++++++++++++++++- pymongo/asynchronous/monitor.py | 67 ++---- pymongo/asynchronous/pool.py | 285 ++++---------------------- pymongo/asynchronous/server.py | 26 +-- pymongo/asynchronous/topology.py | 120 ++--------- pymongo/synchronous/monitor.py | 67 ++---- pymongo/synchronous/pool.py | 285 ++++---------------------- pymongo/synchronous/server.py | 26 +-- pymongo/synchronous/topology.py | 120 ++--------- 9 files changed, 466 insertions(+), 870 deletions(-) diff --git a/pymongo/_telemetry.py b/pymongo/_telemetry.py index 471a013eb9..c796041487 100644 --- a/pymongo/_telemetry.py +++ b/pymongo/_telemetry.py @@ -18,16 +18,26 @@ import datetime import logging +import queue from collections.abc import MutableMapping from typing import TYPE_CHECKING, Any, Optional -from pymongo.logger import _COMMAND_LOGGER, _CommandStatusMessage, _debug_log +from pymongo.logger import ( + _COMMAND_LOGGER, + _CONNECTION_LOGGER, + _SDAM_LOGGER, + _CommandStatusMessage, + _ConnectionStatusMessage, + _debug_log, + _SDAMStatusMessage, + _verbose_connection_error_reason, +) from pymongo.pool_shared import _ConnectionTelemetryInfo if TYPE_CHECKING: from bson.objectid import ObjectId from pymongo.monitoring import _EventListeners - from pymongo.typings import _DocumentOut + from pymongo.typings import _Address, _DocumentOut class _CommandTelemetry: @@ -183,3 +193,329 @@ def failed( service_id=self._conn.service_id, database_name=self._dbname, ) + + +class _CmapTelemetry: + """Combines CMAP structured logging and APM event publishing for pool and connection events.""" + + __slots__ = ("_address", "_client_id", "_listeners", "_should_log", "_should_publish") + + def __init__( + self, + client_id: Optional[ObjectId], + address: _Address, + listeners: Optional[_EventListeners], + is_sdam: bool, + ) -> None: + self._client_id = client_id + self._address = address + self._listeners = listeners + self._should_publish = not is_sdam and listeners is not None and listeners.enabled_for_cmap + self._should_log = not is_sdam + + def _log(self, message: _ConnectionStatusMessage, **extra: Any) -> None: + if self._should_log and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): + _debug_log( + _CONNECTION_LOGGER, + message=message, + clientId=self._client_id, + serverHost=self._address[0], + serverPort=self._address[1], + **extra, + ) + + def pool_created(self, non_default_options: dict[str, Any]) -> None: + # Log before publishing to prevent potential listener preemption in tests. + self._log(_ConnectionStatusMessage.POOL_CREATED, **non_default_options) + if self._should_publish: + assert self._listeners is not None + self._listeners.publish_pool_created(self._address, non_default_options) + + def pool_ready(self) -> None: + # Log before publishing to prevent potential listener preemption in tests. + self._log(_ConnectionStatusMessage.POOL_READY) + if self._should_publish: + assert self._listeners is not None + self._listeners.publish_pool_ready(self._address) + + def pool_cleared(self, service_id: Optional[ObjectId], interrupt_connections: bool) -> None: + # Log before publishing to prevent potential listener preemption in tests. + self._log(_ConnectionStatusMessage.POOL_CLEARED, serviceId=service_id) + if self._should_publish: + assert self._listeners is not None + self._listeners.publish_pool_cleared( + self._address, + service_id=service_id, + interrupt_connections=interrupt_connections, + ) + + def pool_closed(self) -> None: + # Log before publishing to prevent potential listener preemption in tests. + self._log(_ConnectionStatusMessage.POOL_CLOSED) + if self._should_publish: + assert self._listeners is not None + self._listeners.publish_pool_closed(self._address) + + def connection_created(self, conn_id: int) -> None: + # Log before publishing to prevent potential listener preemption in tests. + self._log(_ConnectionStatusMessage.CONN_CREATED, driverConnectionId=conn_id) + if self._should_publish: + assert self._listeners is not None + self._listeners.publish_connection_created(self._address, conn_id) + + def connection_ready(self, conn_id: int, duration: float) -> None: + # Log before publishing to prevent potential listener preemption in tests. + self._log( + _ConnectionStatusMessage.CONN_READY, + driverConnectionId=conn_id, + durationMS=duration, + ) + if self._should_publish: + assert self._listeners is not None + self._listeners.publish_connection_ready(self._address, conn_id, duration) + + def connection_closed(self, conn_id: int, reason: str) -> None: + if self._should_publish: + assert self._listeners is not None + self._listeners.publish_connection_closed(self._address, conn_id, reason) + self._log( + _ConnectionStatusMessage.CONN_CLOSED, + driverConnectionId=conn_id, + reason=_verbose_connection_error_reason(reason), + error=reason, + ) + + def checkout_started(self) -> None: + if self._should_publish: + assert self._listeners is not None + self._listeners.publish_connection_check_out_started(self._address) + self._log(_ConnectionStatusMessage.CHECKOUT_STARTED) + + def checkout_succeeded(self, conn_id: int, duration: float) -> None: + if self._should_publish: + assert self._listeners is not None + self._listeners.publish_connection_checked_out(self._address, conn_id, duration) + self._log( + _ConnectionStatusMessage.CHECKOUT_SUCCEEDED, + driverConnectionId=conn_id, + durationMS=duration, + ) + + def checkout_failed(self, reason: str, error: str, duration: float) -> None: + if self._should_publish: + assert self._listeners is not None + self._listeners.publish_connection_check_out_failed(self._address, error, duration) + self._log( + _ConnectionStatusMessage.CHECKOUT_FAILED, + reason=reason, + error=error, + durationMS=duration, + ) + + def checked_in(self, conn_id: int) -> None: + if self._should_publish: + assert self._listeners is not None + self._listeners.publish_connection_checked_in(self._address, conn_id) + self._log(_ConnectionStatusMessage.CHECKEDIN, driverConnectionId=conn_id) + + +class _HeartbeatTelemetry: + """Combines SDAM structured logging and APM event publishing for server heartbeats. + + The APM started event is published before connection checkout (no conn_id yet); + the log entry for started is emitted after checkout once the conn_id is known. + Call :meth:`apm_started` first, then :meth:`log_started` inside the checkout + context, then :meth:`succeeded` or :meth:`failed` when the outcome is known. + """ + + __slots__ = ("_address", "_awaited", "_listeners", "_publish", "_topology_id") + + def __init__( + self, + topology_id: ObjectId, + address: _Address, + listeners: Optional[_EventListeners], + publish: bool, + awaited: bool, + ) -> None: + self._topology_id = topology_id + self._address = address + self._listeners = listeners + self._publish = publish + self._awaited = awaited + + def apm_started(self) -> None: + """Publish the APM heartbeat-started event (before connection checkout).""" + if self._publish: + assert self._listeners is not None + self._listeners.publish_server_heartbeat_started(self._address, self._awaited) + + def log_started(self, conn_id: int, server_conn_id: Optional[int]) -> None: + """Emit the log entry for heartbeat started (after connection checkout).""" + if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): + _debug_log( + _SDAM_LOGGER, + message=_SDAMStatusMessage.HEARTBEAT_START, + topologyId=self._topology_id, + driverConnectionId=conn_id, + serverConnectionId=server_conn_id, + serverHost=self._address[0], + serverPort=self._address[1], + awaited=self._awaited, + ) + + def succeeded( + self, + round_trip_time: float, + response: Any, + conn_id: int, + server_conn_id: Optional[int], + ) -> None: + """Emit the SUCCEEDED log entry and APM event.""" + if self._publish: + assert self._listeners is not None + self._listeners.publish_server_heartbeat_succeeded( + self._address, round_trip_time, response, self._awaited + ) + if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): + _debug_log( + _SDAM_LOGGER, + message=_SDAMStatusMessage.HEARTBEAT_SUCCESS, + topologyId=self._topology_id, + driverConnectionId=conn_id, + serverConnectionId=server_conn_id, + serverHost=self._address[0], + serverPort=self._address[1], + awaited=self._awaited, + durationMS=round_trip_time * 1000, + reply=response.document, + ) + + def failed(self, duration: float, error: Exception, conn_id: Optional[int]) -> None: + """Emit the FAILED log entry and APM event.""" + if self._publish: + assert self._listeners is not None + self._listeners.publish_server_heartbeat_failed( + self._address, duration, error, self._awaited + ) + if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): + _debug_log( + _SDAM_LOGGER, + message=_SDAMStatusMessage.HEARTBEAT_FAIL, + topologyId=self._topology_id, + serverHost=self._address[0], + serverPort=self._address[1], + awaited=self._awaited, + durationMS=duration * 1000, + failure=error, + driverConnectionId=conn_id, + ) + + +class _SdamTelemetry: + """Combines SDAM structured logging and APM event publishing for topology and server events. + + Topology events are queued for asynchronous delivery; log entries are emitted inline. + """ + + __slots__ = ("_events", "_listeners", "_publish_server", "_publish_tp", "_topology_id") + + def __init__( + self, + topology_id: ObjectId, + listeners: Optional[_EventListeners], + events: Optional[queue.Queue[Any]], + ) -> None: + self._topology_id = topology_id + self._listeners = listeners + self._events = events + self._publish_server = listeners is not None and listeners.enabled_for_server + self._publish_tp = listeners is not None and listeners.enabled_for_topology + + def _enqueue(self, fn: Any, args: tuple[Any, ...]) -> None: + if self._events is not None: + self._events.put((fn, args)) + + def topology_opened(self) -> None: + if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): + _debug_log( + _SDAM_LOGGER, + message=_SDAMStatusMessage.START_TOPOLOGY, + topologyId=self._topology_id, + ) + if self._publish_tp: + assert self._listeners is not None + self._enqueue(self._listeners.publish_topology_opened, (self._topology_id,)) + + def topology_description_changed(self, old_td: Any, new_td: Any) -> None: + if self._publish_tp: + assert self._listeners is not None + self._enqueue( + self._listeners.publish_topology_description_changed, + (old_td, new_td, self._topology_id), + ) + if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): + _debug_log( + _SDAM_LOGGER, + message=_SDAMStatusMessage.TOPOLOGY_CHANGE, + topologyId=self._topology_id, + previousDescription=repr(old_td), + newDescription=repr(new_td), + ) + + def topology_closed(self, old_td: Any, new_td: Any) -> None: + """Emit APM and log events for topology description change + topology closed.""" + if self._publish_tp: + assert self._listeners is not None + self._enqueue( + self._listeners.publish_topology_description_changed, + (old_td, new_td, self._topology_id), + ) + self._enqueue(self._listeners.publish_topology_closed, (self._topology_id,)) + if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): + _debug_log( + _SDAM_LOGGER, + message=_SDAMStatusMessage.TOPOLOGY_CHANGE, + topologyId=self._topology_id, + previousDescription=repr(old_td), + newDescription=repr(new_td), + ) + _debug_log( + _SDAM_LOGGER, + message=_SDAMStatusMessage.STOP_TOPOLOGY, + topologyId=self._topology_id, + ) + + def server_opened(self, address: _Address) -> None: + if self._publish_server: + assert self._listeners is not None + self._enqueue(self._listeners.publish_server_opened, (address, self._topology_id)) + if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): + _debug_log( + _SDAM_LOGGER, + message=_SDAMStatusMessage.START_SERVER, + topologyId=self._topology_id, + serverHost=address[0], + serverPort=address[1], + ) + + def server_description_changed(self, sd_old: Any, sd_new: Any, address: _Address) -> None: + if self._publish_server: + assert self._listeners is not None + self._enqueue( + self._listeners.publish_server_description_changed, + (sd_old, sd_new, address, self._topology_id), + ) + + def server_closed(self, address: _Address) -> None: + if self._publish_server: + assert self._listeners is not None + self._enqueue(self._listeners.publish_server_closed, (address, self._topology_id)) + if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): + _debug_log( + _SDAM_LOGGER, + message=_SDAMStatusMessage.STOP_SERVER, + topologyId=self._topology_id, + serverHost=address[0], + serverPort=address[1], + ) diff --git a/pymongo/asynchronous/monitor.py b/pymongo/asynchronous/monitor.py index 45c12b219f..f6b636a7ae 100644 --- a/pymongo/asynchronous/monitor.py +++ b/pymongo/asynchronous/monitor.py @@ -18,18 +18,18 @@ import asyncio import atexit -import logging import time import weakref from typing import TYPE_CHECKING, Any, Optional from pymongo import common, periodic_executor from pymongo._csot import MovingMinimum +from pymongo._telemetry import _HeartbeatTelemetry from pymongo.asynchronous.srv_resolver import _SrvResolver from pymongo.errors import NetworkTimeout, _OperationCancelled from pymongo.hello import Hello from pymongo.lock import _async_create_lock -from pymongo.logger import _SDAM_LOGGER, _debug_log, _SDAMStatusMessage +from pymongo.logger import _SDAM_LOGGER, _debug_log from pymongo.periodic_executor import _shutdown_executors from pymongo.pool_options import _is_faas from pymongo.read_preferences import MovingAverage @@ -154,6 +154,7 @@ def __init__( self._publish = self._listeners is not None and self._listeners.enabled_for_server_heartbeat self._cancel_context: Optional[_CancellationContext] = None self._conn_id: Optional[int] = None + self._current_hb: Optional[_HeartbeatTelemetry] = None self._rtt_monitor = _RttMonitor( topology, topology_settings, @@ -257,6 +258,7 @@ async def _check_server(self) -> ServerDescription: Returns a ServerDescription. """ self._conn_id = None + self._current_hb = None start = time.monotonic() try: return await self._check_once() @@ -264,25 +266,10 @@ async def _check_server(self) -> ServerDescription: raise except Exception as error: _sanitize(error) - sd = self._server_description - address = sd.address + address = self._server_description.address duration = _monotonic_duration(start) - awaited = bool(self._stream and sd.is_server_type_known and sd.topology_version) - if self._publish: - assert self._listeners is not None - self._listeners.publish_server_heartbeat_failed(address, duration, error, awaited) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.HEARTBEAT_FAIL, - topologyId=self._topology._topology_id, - serverHost=address[0], - serverPort=address[1], - awaited=awaited, - durationMS=duration * 1000, - failure=error, - driverConnectionId=self._conn_id, - ) + if self._current_hb is not None: + self._current_hb.failed(duration, error, self._conn_id) await self._reset_connection() if isinstance(error, _OperationCancelled): raise @@ -303,25 +290,16 @@ async def _check_once(self) -> ServerDescription: awaited = bool( self._pool.conns and self._stream and sd.is_server_type_known and sd.topology_version ) - if self._publish: - assert self._listeners is not None - self._listeners.publish_server_heartbeat_started(address, awaited) + hb = _HeartbeatTelemetry( + self._topology._topology_id, address, self._listeners, self._publish, awaited + ) + self._current_hb = hb + hb.apm_started() if self._cancel_context and self._cancel_context.cancelled: await self._reset_connection() async with self._pool.checkout() as conn: - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.HEARTBEAT_START, - topologyId=self._topology._topology_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=address[0], - serverPort=address[1], - awaited=awaited, - ) - + hb.log_started(conn.id, conn.server_connection_id) self._cancel_context = conn.cancel_context # Record the connection id so we can later attach it to the failed log message. self._conn_id = conn.id @@ -331,24 +309,7 @@ async def _check_once(self) -> ServerDescription: avg_rtt, min_rtt = await self._rtt_monitor.get() sd = ServerDescription(address, response, avg_rtt, min_round_trip_time=min_rtt) - if self._publish: - assert self._listeners is not None - self._listeners.publish_server_heartbeat_succeeded( - address, round_trip_time, response, response.awaitable - ) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.HEARTBEAT_SUCCESS, - topologyId=self._topology._topology_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=address[0], - serverPort=address[1], - awaited=awaited, - durationMS=round_trip_time * 1000, - reply=response.document, - ) + hb.succeeded(round_trip_time, response, conn.id, conn.server_connection_id) return sd async def _check_with_socket(self, conn: AsyncConnection) -> tuple[Hello, float]: # type: ignore[type-arg] diff --git a/pymongo/asynchronous/pool.py b/pymongo/asynchronous/pool.py index 4ed3b85dbf..d2f2356a47 100644 --- a/pymongo/asynchronous/pool.py +++ b/pymongo/asynchronous/pool.py @@ -17,7 +17,6 @@ import asyncio import collections import contextlib -import logging import os import socket import ssl @@ -35,6 +34,7 @@ from bson import DEFAULT_CODEC_OPTIONS from pymongo import _csot, helpers_shared +from pymongo._telemetry import _CmapTelemetry from pymongo.asynchronous.client_session import _validate_session_write_concern from pymongo.asynchronous.command_runner import run_command from pymongo.asynchronous.helpers import _handle_reauth @@ -65,12 +65,6 @@ _async_create_condition, _async_create_lock, ) -from pymongo.logger import ( - _CONNECTION_LOGGER, - _ConnectionStatusMessage, - _debug_log, - _verbose_connection_error_reason, -) from pymongo.monitoring import ( ConnectionCheckOutFailedReason, ConnectionClosedReason, @@ -145,8 +139,7 @@ def __init__( self.hello_ok: bool = False self.is_mongos = False self.listeners = pool.opts._event_listeners - self.enabled_for_cmap = pool.enabled_for_cmap - self.enabled_for_logging = pool.enabled_for_logging + self._telemetry = pool._telemetry self.compression_settings = pool.opts._compression_settings self.compression_context: Union[SnappyContext, ZlibContext, ZstdContext, None] = None self.socket_checker: SocketChecker = SocketChecker() @@ -173,7 +166,6 @@ def __init__( self.active = False self.last_timeout = self.opts.socket_timeout self.connect_rtt = 0.0 - self._client_id = pool._client_id self.creation_time = time.monotonic() # For gossiping $clusterTime from the connection handshake to the client. self._cluster_time = None @@ -476,20 +468,7 @@ async def authenticate(self, reauthenticate: bool = False) -> None: await auth.authenticate(creds, self, reauthenticate=reauthenticate) self.ready = True duration = time.monotonic() - self.creation_time - # Log before publishing event to prevent potential listener preemption in tests - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CONN_READY, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - driverConnectionId=self.id, - durationMS=duration, - ) - if self.enabled_for_cmap: - assert self.listeners is not None - self.listeners.publish_connection_ready(self.address, self.id, duration) + self._telemetry.connection_ready(self.id, duration) def validate_session( self, client: Optional[AsyncMongoClient[Any]], session: Optional[AsyncClientSession] @@ -510,20 +489,7 @@ async def close_conn(self, reason: Optional[str]) -> None: return await self._close_conn() if reason: - if self.enabled_for_cmap: - assert self.listeners is not None - self.listeners.publish_connection_closed(self.address, self.id, reason) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CONN_CLOSED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - driverConnectionId=self.id, - reason=_verbose_connection_error_reason(reason), - error=reason, - ) + self._telemetry.connection_closed(self.id, reason) async def _close_conn(self) -> None: """Close this connection.""" @@ -699,13 +665,6 @@ def __init__( self.address = address self.opts = options self.is_sdam = is_sdam - # Don't publish events or logs in Monitor pools. - self.enabled_for_cmap = ( - not self.is_sdam - and self.opts._event_listeners is not None - and self.opts._event_listeners.enabled_for_cmap - ) - self.enabled_for_logging = not self.is_sdam # The first portion of the wait queue. # Enforces: maxPoolSize @@ -721,25 +680,11 @@ def __init__( self._max_connecting_cond = _async_create_condition(self.lock) self._pending = 0 self._max_connecting = self.opts.max_connecting - self._client_id = client_id self._ssl_session_cache: Optional[list[Any]] = ( [None] if self.opts._ssl_context is not None else None ) - # Log before publishing event to prevent potential listener preemption in tests - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.POOL_CREATED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - **self.opts.non_default_options, - ) - if self.enabled_for_cmap: - assert self.opts._event_listeners is not None - self.opts._event_listeners.publish_pool_created( - self.address, self.opts.non_default_options - ) + self._telemetry = _CmapTelemetry(client_id, address, options._event_listeners, is_sdam) + self._telemetry.pool_created(self.opts.non_default_options) # Similar to active_sockets but includes threads in the wait queue. self.operation_count: int = 0 # Retain references to pinned connections to prevent the CPython GC @@ -754,17 +699,7 @@ async def ready(self) -> None: async with self.lock: if self.state != PoolState.READY: self.state = PoolState.READY - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.POOL_READY, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - ) - if self.enabled_for_cmap: - assert self.opts._event_listeners is not None - self.opts._event_listeners.publish_pool_ready(self.address) + self._telemetry.pool_ready() @property def closed(self) -> bool: @@ -812,23 +747,7 @@ async def _reset( # and free-threaded Python causes ConnectionCheckOutFailedEvent to # arrive before PoolClearedEvent (PYTHON-3519). if not close and old_state != PoolState.PAUSED: - _listeners = self.opts._event_listeners - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.POOL_CLEARED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - serviceId=service_id, - ) - if self.enabled_for_cmap: - assert _listeners is not None - _listeners.publish_pool_cleared( - self.address, - service_id=service_id, - interrupt_connections=interrupt_connections, - ) + self._telemetry.pool_cleared(service_id, interrupt_connections) # Clear the wait queue self._max_connecting_cond.notify_all() @@ -838,7 +757,6 @@ async def _reset( for context in self.active_contexts: context.cancel() - listeners = self.opts._event_listeners # CMAP spec says that close() MUST close sockets before publishing the # PoolClosedEvent but that reset() SHOULD close sockets *after* # publishing the PoolClearedEvent. @@ -851,17 +769,7 @@ async def _reset( else: for conn in sockets: await conn.close_conn(ConnectionClosedReason.POOL_CLOSED) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.POOL_CLOSED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - ) - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_pool_closed(self.address) + self._telemetry.pool_closed() else: if not _IS_SYNC: await asyncio.gather( @@ -996,20 +904,7 @@ async def connect(self, handler: Optional[_MongoClientErrorHandler] = None) -> A tmp_context = _CancellationContext() self.active_contexts.add(tmp_context) - listeners = self.opts._event_listeners - # Log before publishing event to prevent potential listener preemption in tests - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CONN_CREATED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - driverConnectionId=conn_id, - ) - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_connection_created(self.address, conn_id) + self._telemetry.connection_created(conn_id) try: networking_interface = await _configured_protocol_interface( @@ -1019,22 +914,7 @@ async def connect(self, handler: Optional[_MongoClientErrorHandler] = None) -> A except BaseException as error: async with self.lock: self.active_contexts.discard(tmp_context) - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_connection_closed( - self.address, conn_id, ConnectionClosedReason.ERROR - ) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CONN_CLOSED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - driverConnectionId=conn_id, - reason=_verbose_connection_error_reason(ConnectionClosedReason.ERROR), - error=ConnectionClosedReason.ERROR, - ) + self._telemetry.connection_closed(conn_id, ConnectionClosedReason.ERROR) if isinstance(error, (IOError, OSError, *SSLErrors)): details = _get_timeout_details(self.opts) # Wrap to AutoReconnect/NetworkTimeout BEFORE labeling so the @@ -1096,36 +976,13 @@ async def checkout( :param handler: A _MongoClientErrorHandler. """ - listeners = self.opts._event_listeners checkout_started_time = time.monotonic() - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_connection_check_out_started(self.address) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CHECKOUT_STARTED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - ) + self._telemetry.checkout_started() conn = await self._get_conn(checkout_started_time, handler=handler) duration = time.monotonic() - checkout_started_time - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_connection_checked_out(self.address, conn.id, duration) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CHECKOUT_SUCCEEDED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - driverConnectionId=conn.id, - durationMS=duration, - ) + self._telemetry.checkout_succeeded(conn.id, duration) try: async with self.lock: self.active_contexts.add(conn.cancel_context) @@ -1160,22 +1017,11 @@ def _raise_if_not_ready(self, checkout_started_time: float, emit_event: bool) -> if self.state != PoolState.READY: if emit_event: duration = time.monotonic() - checkout_started_time - if self.enabled_for_cmap: - assert self.opts._event_listeners is not None - self.opts._event_listeners.publish_connection_check_out_failed( - self.address, ConnectionCheckOutFailedReason.CONN_ERROR, duration - ) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CHECKOUT_FAILED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - reason="An error occurred while trying to establish a new connection", - error=ConnectionCheckOutFailedReason.CONN_ERROR, - durationMS=duration, - ) + self._telemetry.checkout_failed( + "An error occurred while trying to establish a new connection", + ConnectionCheckOutFailedReason.CONN_ERROR, + duration, + ) details = _get_timeout_details(self.opts) _raise_connection_failure( @@ -1194,22 +1040,11 @@ async def _get_conn( if self.closed: duration = time.monotonic() - checkout_started_time - if self.enabled_for_cmap: - assert self.opts._event_listeners is not None - self.opts._event_listeners.publish_connection_check_out_failed( - self.address, ConnectionCheckOutFailedReason.POOL_CLOSED, duration - ) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CHECKOUT_FAILED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - reason="Connection pool was closed", - error=ConnectionCheckOutFailedReason.POOL_CLOSED, - durationMS=duration, - ) + self._telemetry.checkout_failed( + "Connection pool was closed", + ConnectionCheckOutFailedReason.POOL_CLOSED, + duration, + ) raise _PoolClosedError( "Attempted to check out a connection from closed connection pool" ) @@ -1290,22 +1125,11 @@ async def _get_conn( if not emitted_event: duration = time.monotonic() - checkout_started_time - if self.enabled_for_cmap: - assert self.opts._event_listeners is not None - self.opts._event_listeners.publish_connection_check_out_failed( - self.address, ConnectionCheckOutFailedReason.CONN_ERROR, duration - ) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CHECKOUT_FAILED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - reason="An error occurred while trying to establish a new connection", - error=ConnectionCheckOutFailedReason.CONN_ERROR, - durationMS=duration, - ) + self._telemetry.checkout_failed( + "An error occurred while trying to establish a new connection", + ConnectionCheckOutFailedReason.CONN_ERROR, + duration, + ) raise conn.active = True @@ -1322,21 +1146,9 @@ async def checkin(self, conn: AsyncConnection) -> None: conn.pinned_txn = False conn.pinned_cursor = False self.__pinned_sockets.discard(conn) - listeners = self.opts._event_listeners async with self.lock: self.active_contexts.discard(conn.cancel_context) - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_connection_checked_in(self.address, conn.id) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CHECKEDIN, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - driverConnectionId=conn.id, - ) + self._telemetry.checked_in(conn.id) if self.pid != os.getpid(): await self.reset_without_pause() else: @@ -1344,22 +1156,7 @@ async def checkin(self, conn: AsyncConnection) -> None: await conn.close_conn(ConnectionClosedReason.POOL_CLOSED) elif conn.closed: # CMAP requires the closed event be emitted after the check in. - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_connection_closed( - self.address, conn.id, ConnectionClosedReason.ERROR - ) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CONN_CLOSED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - driverConnectionId=conn.id, - reason=_verbose_connection_error_reason(ConnectionClosedReason.ERROR), - error=ConnectionClosedReason.ERROR, - ) + self._telemetry.connection_closed(conn.id, ConnectionClosedReason.ERROR) else: close_conn = False async with self.lock: @@ -1424,24 +1221,12 @@ async def _perished(self, conn: AsyncConnection) -> bool: return False def _raise_wait_queue_timeout(self, checkout_started_time: float) -> NoReturn: - listeners = self.opts._event_listeners duration = time.monotonic() - checkout_started_time - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_connection_check_out_failed( - self.address, ConnectionCheckOutFailedReason.TIMEOUT, duration - ) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CHECKOUT_FAILED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - reason="Wait queue timeout elapsed without a connection becoming available", - error=ConnectionCheckOutFailedReason.TIMEOUT, - durationMS=duration, - ) + self._telemetry.checkout_failed( + "Wait queue timeout elapsed without a connection becoming available", + ConnectionCheckOutFailedReason.TIMEOUT, + duration, + ) timeout = _csot.get_timeout() or self.opts.wait_queue_timeout if self.opts.load_balanced: other_ops = self.active_sockets - self.ncursors - self.ntxns diff --git a/pymongo/asynchronous/server.py b/pymongo/asynchronous/server.py index 57158dfc44..dff297dc58 100644 --- a/pymongo/asynchronous/server.py +++ b/pymongo/asynchronous/server.py @@ -16,7 +16,6 @@ from __future__ import annotations -import logging from contextlib import AbstractAsyncContextManager from typing import ( TYPE_CHECKING, @@ -26,13 +25,9 @@ Union, ) +from pymongo._telemetry import _SdamTelemetry from pymongo.asynchronous.command_runner import run_cursor_command from pymongo.asynchronous.helpers import _handle_reauth -from pymongo.logger import ( - _SDAM_LOGGER, - _debug_log, - _SDAMStatusMessage, -) from pymongo.message import _GetMore, _OpMsg, _Query from pymongo.response import PinnedResponse, Response @@ -74,6 +69,7 @@ def __init__( self._events = None if self._publish: self._events = events() # type: ignore[misc] + self._sdam = _SdamTelemetry(topology_id, listeners, self._events) # type: ignore[arg-type] async def open(self) -> None: """Start monitoring, or restart after a fork. @@ -92,23 +88,7 @@ async def close(self) -> None: Reconnect with open(). """ - if self._publish: - assert self._listener is not None - assert self._events is not None - self._events.put( - ( - self._listener.publish_server_closed, - (self._description.address, self._topology_id), - ) - ) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.STOP_SERVER, - topologyId=self._topology_id, - serverHost=self._description.address[0], - serverPort=self._description.address[1], - ) + self._sdam.server_closed(self._description.address) await self._monitor.close() await self._pool.close() diff --git a/pymongo/asynchronous/topology.py b/pymongo/asynchronous/topology.py index 6af075cdc2..b3046a7b21 100644 --- a/pymongo/asynchronous/topology.py +++ b/pymongo/asynchronous/topology.py @@ -30,6 +30,7 @@ from typing import TYPE_CHECKING, Any, Callable, Optional, cast from pymongo import _csot, common, helpers_shared, periodic_executor +from pymongo._telemetry import _SdamTelemetry from pymongo.asynchronous.client_session import _ServerSession, _ServerSessionPool from pymongo.asynchronous.monitor import MonitorBase, SrvMonitor from pymongo.asynchronous.pool import Pool @@ -52,10 +53,8 @@ _async_create_lock, ) from pymongo.logger import ( - _SDAM_LOGGER, _SERVER_SELECTION_LOGGER, _debug_log, - _SDAMStatusMessage, _ServerSelectionStatusMessage, ) from pymongo.pool_options import PoolOptions @@ -118,17 +117,9 @@ def __init__(self, topology_settings: TopologySettings): if self._publish_server or self._publish_tp: self._events = queue.Queue(maxsize=100) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.START_TOPOLOGY, - topologyId=self._topology_id, - ) + self._sdam = _SdamTelemetry(self._topology_id, self._listeners, self._events) + self._sdam.topology_opened() - if self._publish_tp: - assert self._events is not None - assert self._listeners is not None - self._events.put((self._listeners.publish_topology_opened, (self._topology_id,))) self._settings = topology_settings topology_description = TopologyDescription( topology_settings.get_topology_type(), @@ -143,37 +134,10 @@ def __init__(self, topology_settings: TopologySettings): initial_td = TopologyDescription( TOPOLOGY_TYPE.Unknown, {}, None, None, None, self._settings ) - if self._publish_tp: - assert self._events is not None - assert self._listeners is not None - self._events.put( - ( - self._listeners.publish_topology_description_changed, - (initial_td, self._description, self._topology_id), - ) - ) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.TOPOLOGY_CHANGE, - topologyId=self._topology_id, - previousDescription=repr(initial_td), - newDescription=repr(self._description), - ) + self._sdam.topology_description_changed(initial_td, self._description) for seed in topology_settings.seeds: - if self._publish_server: - assert self._events is not None - assert self._listeners is not None - self._events.put((self._listeners.publish_server_opened, (seed, self._topology_id))) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.START_SERVER, - topologyId=self._topology_id, - serverHost=seed[0], - serverPort=seed[1], - ) + self._sdam.server_opened(seed) # Store the seed list to help diagnose errors in _error_message(). self._seed_addresses = list(topology_description.server_descriptions()) @@ -508,36 +472,16 @@ async def _process_change( await server.pool.ready() suppress_event = sd_old == server_description - if self._publish_server and not suppress_event: - assert self._events is not None - assert self._listeners is not None - self._events.put( - ( - self._listeners.publish_server_description_changed, - (sd_old, server_description, server_description.address, self._topology_id), - ) + if not suppress_event: + self._sdam.server_description_changed( + sd_old, server_description, server_description.address ) self._description = new_td await self._update_servers() - if self._publish_tp and not suppress_event: - assert self._events is not None - assert self._listeners is not None - self._events.put( - ( - self._listeners.publish_topology_description_changed, - (td_old, self._description, self._topology_id), - ) - ) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG) and not suppress_event: - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.TOPOLOGY_CHANGE, - topologyId=self._topology_id, - previousDescription=repr(td_old), - newDescription=repr(self._description), - ) + if not suppress_event: + self._sdam.topology_description_changed(td_old, self._description) # Shutdown SRV polling for unsupported cluster types. # This is only applicable if the old topology was Unknown, and the @@ -588,24 +532,7 @@ async def _process_srv_update(self, seedlist: list[tuple[str, Any]]) -> None: self._description = _updated_topology_description_srv_polling(self._description, seedlist) await self._update_servers() - - if self._publish_tp: - assert self._events is not None - assert self._listeners is not None - self._events.put( - ( - self._listeners.publish_topology_description_changed, - (td_old, self._description, self._topology_id), - ) - ) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.TOPOLOGY_CHANGE, - topologyId=self._topology_id, - previousDescription=repr(td_old), - newDescription=repr(self._description), - ) + self._sdam.topology_description_changed(td_old, self._description) async def on_srv_update(self, seedlist: list[tuple[str, Any]]) -> None: """Process a new list of nodes obtained from scanning SRV records.""" @@ -744,8 +671,6 @@ async def close(self) -> None: # Publish only after releasing the lock. if self._publish_tp: - assert self._events is not None - assert self._listeners is not None self._description = TopologyDescription( TOPOLOGY_TYPE.Unknown, {}, @@ -754,28 +679,7 @@ async def close(self) -> None: self._description.max_election_id, self._description._topology_settings, ) - self._events.put( - ( - self._listeners.publish_topology_description_changed, - ( - old_td, - self._description, - self._topology_id, - ), - ) - ) - self._events.put((self._listeners.publish_topology_closed, (self._topology_id,))) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.TOPOLOGY_CHANGE, - topologyId=self._topology_id, - previousDescription=repr(old_td), - newDescription=repr(self._description), - ) - _debug_log( - _SDAM_LOGGER, message=_SDAMStatusMessage.STOP_TOPOLOGY, topologyId=self._topology_id - ) + self._sdam.topology_closed(old_td, self._description) if self._publish_server or self._publish_tp: # Make sure the events executor thread is fully closed before publishing the remaining events diff --git a/pymongo/synchronous/monitor.py b/pymongo/synchronous/monitor.py index f395588814..053ec8d8b4 100644 --- a/pymongo/synchronous/monitor.py +++ b/pymongo/synchronous/monitor.py @@ -18,17 +18,17 @@ import asyncio import atexit -import logging import time import weakref from typing import TYPE_CHECKING, Any, Optional from pymongo import common, periodic_executor from pymongo._csot import MovingMinimum +from pymongo._telemetry import _HeartbeatTelemetry from pymongo.errors import NetworkTimeout, _OperationCancelled from pymongo.hello import Hello from pymongo.lock import _create_lock -from pymongo.logger import _SDAM_LOGGER, _debug_log, _SDAMStatusMessage +from pymongo.logger import _SDAM_LOGGER, _debug_log from pymongo.periodic_executor import _shutdown_executors from pymongo.pool_options import _is_faas from pymongo.read_preferences import MovingAverage @@ -154,6 +154,7 @@ def __init__( self._publish = self._listeners is not None and self._listeners.enabled_for_server_heartbeat self._cancel_context: Optional[_CancellationContext] = None self._conn_id: Optional[int] = None + self._current_hb: Optional[_HeartbeatTelemetry] = None self._rtt_monitor = _RttMonitor( topology, topology_settings, @@ -255,6 +256,7 @@ def _check_server(self) -> ServerDescription: Returns a ServerDescription. """ self._conn_id = None + self._current_hb = None start = time.monotonic() try: return self._check_once() @@ -262,25 +264,10 @@ def _check_server(self) -> ServerDescription: raise except Exception as error: _sanitize(error) - sd = self._server_description - address = sd.address + address = self._server_description.address duration = _monotonic_duration(start) - awaited = bool(self._stream and sd.is_server_type_known and sd.topology_version) - if self._publish: - assert self._listeners is not None - self._listeners.publish_server_heartbeat_failed(address, duration, error, awaited) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.HEARTBEAT_FAIL, - topologyId=self._topology._topology_id, - serverHost=address[0], - serverPort=address[1], - awaited=awaited, - durationMS=duration * 1000, - failure=error, - driverConnectionId=self._conn_id, - ) + if self._current_hb is not None: + self._current_hb.failed(duration, error, self._conn_id) self._reset_connection() if isinstance(error, _OperationCancelled): raise @@ -301,25 +288,16 @@ def _check_once(self) -> ServerDescription: awaited = bool( self._pool.conns and self._stream and sd.is_server_type_known and sd.topology_version ) - if self._publish: - assert self._listeners is not None - self._listeners.publish_server_heartbeat_started(address, awaited) + hb = _HeartbeatTelemetry( + self._topology._topology_id, address, self._listeners, self._publish, awaited + ) + self._current_hb = hb + hb.apm_started() if self._cancel_context and self._cancel_context.cancelled: self._reset_connection() with self._pool.checkout() as conn: - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.HEARTBEAT_START, - topologyId=self._topology._topology_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=address[0], - serverPort=address[1], - awaited=awaited, - ) - + hb.log_started(conn.id, conn.server_connection_id) self._cancel_context = conn.cancel_context # Record the connection id so we can later attach it to the failed log message. self._conn_id = conn.id @@ -329,24 +307,7 @@ def _check_once(self) -> ServerDescription: avg_rtt, min_rtt = self._rtt_monitor.get() sd = ServerDescription(address, response, avg_rtt, min_round_trip_time=min_rtt) - if self._publish: - assert self._listeners is not None - self._listeners.publish_server_heartbeat_succeeded( - address, round_trip_time, response, response.awaitable - ) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.HEARTBEAT_SUCCESS, - topologyId=self._topology._topology_id, - driverConnectionId=conn.id, - serverConnectionId=conn.server_connection_id, - serverHost=address[0], - serverPort=address[1], - awaited=awaited, - durationMS=round_trip_time * 1000, - reply=response.document, - ) + hb.succeeded(round_trip_time, response, conn.id, conn.server_connection_id) return sd def _check_with_socket(self, conn: Connection) -> tuple[Hello, float]: # type: ignore[type-arg] diff --git a/pymongo/synchronous/pool.py b/pymongo/synchronous/pool.py index 1006735444..7eb6125326 100644 --- a/pymongo/synchronous/pool.py +++ b/pymongo/synchronous/pool.py @@ -17,7 +17,6 @@ import asyncio import collections import contextlib -import logging import os import socket import ssl @@ -35,6 +34,7 @@ from bson import DEFAULT_CODEC_OPTIONS from pymongo import _csot, helpers_shared +from pymongo._telemetry import _CmapTelemetry from pymongo.common import ( MAX_BSON_SIZE, MAX_MESSAGE_SIZE, @@ -62,12 +62,6 @@ _create_condition, _create_lock, ) -from pymongo.logger import ( - _CONNECTION_LOGGER, - _ConnectionStatusMessage, - _debug_log, - _verbose_connection_error_reason, -) from pymongo.monitoring import ( ConnectionCheckOutFailedReason, ConnectionClosedReason, @@ -145,8 +139,7 @@ def __init__( self.hello_ok: bool = False self.is_mongos = False self.listeners = pool.opts._event_listeners - self.enabled_for_cmap = pool.enabled_for_cmap - self.enabled_for_logging = pool.enabled_for_logging + self._telemetry = pool._telemetry self.compression_settings = pool.opts._compression_settings self.compression_context: Union[SnappyContext, ZlibContext, ZstdContext, None] = None self.socket_checker: SocketChecker = SocketChecker() @@ -173,7 +166,6 @@ def __init__( self.active = False self.last_timeout = self.opts.socket_timeout self.connect_rtt = 0.0 - self._client_id = pool._client_id self.creation_time = time.monotonic() # For gossiping $clusterTime from the connection handshake to the client. self._cluster_time = None @@ -476,20 +468,7 @@ def authenticate(self, reauthenticate: bool = False) -> None: auth.authenticate(creds, self, reauthenticate=reauthenticate) self.ready = True duration = time.monotonic() - self.creation_time - # Log before publishing event to prevent potential listener preemption in tests - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CONN_READY, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - driverConnectionId=self.id, - durationMS=duration, - ) - if self.enabled_for_cmap: - assert self.listeners is not None - self.listeners.publish_connection_ready(self.address, self.id, duration) + self._telemetry.connection_ready(self.id, duration) def validate_session( self, client: Optional[MongoClient[Any]], session: Optional[ClientSession] @@ -508,20 +487,7 @@ def close_conn(self, reason: Optional[str]) -> None: return self._close_conn() if reason: - if self.enabled_for_cmap: - assert self.listeners is not None - self.listeners.publish_connection_closed(self.address, self.id, reason) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CONN_CLOSED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - driverConnectionId=self.id, - reason=_verbose_connection_error_reason(reason), - error=reason, - ) + self._telemetry.connection_closed(self.id, reason) def _close_conn(self) -> None: """Close this connection.""" @@ -697,13 +663,6 @@ def __init__( self.address = address self.opts = options self.is_sdam = is_sdam - # Don't publish events or logs in Monitor pools. - self.enabled_for_cmap = ( - not self.is_sdam - and self.opts._event_listeners is not None - and self.opts._event_listeners.enabled_for_cmap - ) - self.enabled_for_logging = not self.is_sdam # The first portion of the wait queue. # Enforces: maxPoolSize @@ -719,25 +678,11 @@ def __init__( self._max_connecting_cond = _create_condition(self.lock) self._pending = 0 self._max_connecting = self.opts.max_connecting - self._client_id = client_id self._ssl_session_cache: Optional[list[Any]] = ( [None] if self.opts._ssl_context is not None else None ) - # Log before publishing event to prevent potential listener preemption in tests - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.POOL_CREATED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - **self.opts.non_default_options, - ) - if self.enabled_for_cmap: - assert self.opts._event_listeners is not None - self.opts._event_listeners.publish_pool_created( - self.address, self.opts.non_default_options - ) + self._telemetry = _CmapTelemetry(client_id, address, options._event_listeners, is_sdam) + self._telemetry.pool_created(self.opts.non_default_options) # Similar to active_sockets but includes threads in the wait queue. self.operation_count: int = 0 # Retain references to pinned connections to prevent the CPython GC @@ -752,17 +697,7 @@ def ready(self) -> None: with self.lock: if self.state != PoolState.READY: self.state = PoolState.READY - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.POOL_READY, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - ) - if self.enabled_for_cmap: - assert self.opts._event_listeners is not None - self.opts._event_listeners.publish_pool_ready(self.address) + self._telemetry.pool_ready() @property def closed(self) -> bool: @@ -810,23 +745,7 @@ def _reset( # and free-threaded Python causes ConnectionCheckOutFailedEvent to # arrive before PoolClearedEvent (PYTHON-3519). if not close and old_state != PoolState.PAUSED: - _listeners = self.opts._event_listeners - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.POOL_CLEARED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - serviceId=service_id, - ) - if self.enabled_for_cmap: - assert _listeners is not None - _listeners.publish_pool_cleared( - self.address, - service_id=service_id, - interrupt_connections=interrupt_connections, - ) + self._telemetry.pool_cleared(service_id, interrupt_connections) # Clear the wait queue self._max_connecting_cond.notify_all() @@ -836,7 +755,6 @@ def _reset( for context in self.active_contexts: context.cancel() - listeners = self.opts._event_listeners # CMAP spec says that close() MUST close sockets before publishing the # PoolClosedEvent but that reset() SHOULD close sockets *after* # publishing the PoolClearedEvent. @@ -849,17 +767,7 @@ def _reset( else: for conn in sockets: conn.close_conn(ConnectionClosedReason.POOL_CLOSED) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.POOL_CLOSED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - ) - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_pool_closed(self.address) + self._telemetry.pool_closed() else: if not _IS_SYNC: asyncio.gather( @@ -992,20 +900,7 @@ def connect(self, handler: Optional[_MongoClientErrorHandler] = None) -> Connect tmp_context = _CancellationContext() self.active_contexts.add(tmp_context) - listeners = self.opts._event_listeners - # Log before publishing event to prevent potential listener preemption in tests - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CONN_CREATED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - driverConnectionId=conn_id, - ) - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_connection_created(self.address, conn_id) + self._telemetry.connection_created(conn_id) try: networking_interface = _configured_socket_interface( @@ -1015,22 +910,7 @@ def connect(self, handler: Optional[_MongoClientErrorHandler] = None) -> Connect except BaseException as error: with self.lock: self.active_contexts.discard(tmp_context) - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_connection_closed( - self.address, conn_id, ConnectionClosedReason.ERROR - ) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CONN_CLOSED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - driverConnectionId=conn_id, - reason=_verbose_connection_error_reason(ConnectionClosedReason.ERROR), - error=ConnectionClosedReason.ERROR, - ) + self._telemetry.connection_closed(conn_id, ConnectionClosedReason.ERROR) if isinstance(error, (IOError, OSError, *SSLErrors)): details = _get_timeout_details(self.opts) # Wrap to AutoReconnect/NetworkTimeout BEFORE labeling so the @@ -1092,36 +972,13 @@ def checkout( :param handler: A _MongoClientErrorHandler. """ - listeners = self.opts._event_listeners checkout_started_time = time.monotonic() - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_connection_check_out_started(self.address) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CHECKOUT_STARTED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - ) + self._telemetry.checkout_started() conn = self._get_conn(checkout_started_time, handler=handler) duration = time.monotonic() - checkout_started_time - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_connection_checked_out(self.address, conn.id, duration) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CHECKOUT_SUCCEEDED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - driverConnectionId=conn.id, - durationMS=duration, - ) + self._telemetry.checkout_succeeded(conn.id, duration) try: with self.lock: self.active_contexts.add(conn.cancel_context) @@ -1156,22 +1013,11 @@ def _raise_if_not_ready(self, checkout_started_time: float, emit_event: bool) -> if self.state != PoolState.READY: if emit_event: duration = time.monotonic() - checkout_started_time - if self.enabled_for_cmap: - assert self.opts._event_listeners is not None - self.opts._event_listeners.publish_connection_check_out_failed( - self.address, ConnectionCheckOutFailedReason.CONN_ERROR, duration - ) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CHECKOUT_FAILED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - reason="An error occurred while trying to establish a new connection", - error=ConnectionCheckOutFailedReason.CONN_ERROR, - durationMS=duration, - ) + self._telemetry.checkout_failed( + "An error occurred while trying to establish a new connection", + ConnectionCheckOutFailedReason.CONN_ERROR, + duration, + ) details = _get_timeout_details(self.opts) _raise_connection_failure( @@ -1190,22 +1036,11 @@ def _get_conn( if self.closed: duration = time.monotonic() - checkout_started_time - if self.enabled_for_cmap: - assert self.opts._event_listeners is not None - self.opts._event_listeners.publish_connection_check_out_failed( - self.address, ConnectionCheckOutFailedReason.POOL_CLOSED, duration - ) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CHECKOUT_FAILED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - reason="Connection pool was closed", - error=ConnectionCheckOutFailedReason.POOL_CLOSED, - durationMS=duration, - ) + self._telemetry.checkout_failed( + "Connection pool was closed", + ConnectionCheckOutFailedReason.POOL_CLOSED, + duration, + ) raise _PoolClosedError( "Attempted to check out a connection from closed connection pool" ) @@ -1286,22 +1121,11 @@ def _get_conn( if not emitted_event: duration = time.monotonic() - checkout_started_time - if self.enabled_for_cmap: - assert self.opts._event_listeners is not None - self.opts._event_listeners.publish_connection_check_out_failed( - self.address, ConnectionCheckOutFailedReason.CONN_ERROR, duration - ) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CHECKOUT_FAILED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - reason="An error occurred while trying to establish a new connection", - error=ConnectionCheckOutFailedReason.CONN_ERROR, - durationMS=duration, - ) + self._telemetry.checkout_failed( + "An error occurred while trying to establish a new connection", + ConnectionCheckOutFailedReason.CONN_ERROR, + duration, + ) raise conn.active = True @@ -1318,21 +1142,9 @@ def checkin(self, conn: Connection) -> None: conn.pinned_txn = False conn.pinned_cursor = False self.__pinned_sockets.discard(conn) - listeners = self.opts._event_listeners with self.lock: self.active_contexts.discard(conn.cancel_context) - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_connection_checked_in(self.address, conn.id) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CHECKEDIN, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - driverConnectionId=conn.id, - ) + self._telemetry.checked_in(conn.id) if self.pid != os.getpid(): self.reset_without_pause() else: @@ -1340,22 +1152,7 @@ def checkin(self, conn: Connection) -> None: conn.close_conn(ConnectionClosedReason.POOL_CLOSED) elif conn.closed: # CMAP requires the closed event be emitted after the check in. - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_connection_closed( - self.address, conn.id, ConnectionClosedReason.ERROR - ) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CONN_CLOSED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - driverConnectionId=conn.id, - reason=_verbose_connection_error_reason(ConnectionClosedReason.ERROR), - error=ConnectionClosedReason.ERROR, - ) + self._telemetry.connection_closed(conn.id, ConnectionClosedReason.ERROR) else: close_conn = False with self.lock: @@ -1420,24 +1217,12 @@ def _perished(self, conn: Connection) -> bool: return False def _raise_wait_queue_timeout(self, checkout_started_time: float) -> NoReturn: - listeners = self.opts._event_listeners duration = time.monotonic() - checkout_started_time - if self.enabled_for_cmap: - assert listeners is not None - listeners.publish_connection_check_out_failed( - self.address, ConnectionCheckOutFailedReason.TIMEOUT, duration - ) - if self.enabled_for_logging and _CONNECTION_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _CONNECTION_LOGGER, - message=_ConnectionStatusMessage.CHECKOUT_FAILED, - clientId=self._client_id, - serverHost=self.address[0], - serverPort=self.address[1], - reason="Wait queue timeout elapsed without a connection becoming available", - error=ConnectionCheckOutFailedReason.TIMEOUT, - durationMS=duration, - ) + self._telemetry.checkout_failed( + "Wait queue timeout elapsed without a connection becoming available", + ConnectionCheckOutFailedReason.TIMEOUT, + duration, + ) timeout = _csot.get_timeout() or self.opts.wait_queue_timeout if self.opts.load_balanced: other_ops = self.active_sockets - self.ncursors - self.ntxns diff --git a/pymongo/synchronous/server.py b/pymongo/synchronous/server.py index 09d8fb75e1..8564b84750 100644 --- a/pymongo/synchronous/server.py +++ b/pymongo/synchronous/server.py @@ -16,7 +16,6 @@ from __future__ import annotations -import logging from contextlib import AbstractContextManager from typing import ( TYPE_CHECKING, @@ -26,11 +25,7 @@ Union, ) -from pymongo.logger import ( - _SDAM_LOGGER, - _debug_log, - _SDAMStatusMessage, -) +from pymongo._telemetry import _SdamTelemetry from pymongo.message import _GetMore, _OpMsg, _Query from pymongo.response import PinnedResponse, Response from pymongo.synchronous.command_runner import run_cursor_command @@ -74,6 +69,7 @@ def __init__( self._events = None if self._publish: self._events = events() # type: ignore[misc] + self._sdam = _SdamTelemetry(topology_id, listeners, self._events) # type: ignore[arg-type] def open(self) -> None: """Start monitoring, or restart after a fork. @@ -92,23 +88,7 @@ def close(self) -> None: Reconnect with open(). """ - if self._publish: - assert self._listener is not None - assert self._events is not None - self._events.put( - ( - self._listener.publish_server_closed, - (self._description.address, self._topology_id), - ) - ) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.STOP_SERVER, - topologyId=self._topology_id, - serverHost=self._description.address[0], - serverPort=self._description.address[1], - ) + self._sdam.server_closed(self._description.address) self._monitor.close() self._pool.close() diff --git a/pymongo/synchronous/topology.py b/pymongo/synchronous/topology.py index b419833256..4f273f60f0 100644 --- a/pymongo/synchronous/topology.py +++ b/pymongo/synchronous/topology.py @@ -30,6 +30,7 @@ from typing import TYPE_CHECKING, Any, Callable, Optional, cast from pymongo import _csot, common, helpers_shared, periodic_executor +from pymongo._telemetry import _SdamTelemetry from pymongo.errors import ( ConnectionFailure, InvalidOperation, @@ -48,10 +49,8 @@ _create_lock, ) from pymongo.logger import ( - _SDAM_LOGGER, _SERVER_SELECTION_LOGGER, _debug_log, - _SDAMStatusMessage, _ServerSelectionStatusMessage, ) from pymongo.pool_options import PoolOptions @@ -118,17 +117,9 @@ def __init__(self, topology_settings: TopologySettings): if self._publish_server or self._publish_tp: self._events = queue.Queue(maxsize=100) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.START_TOPOLOGY, - topologyId=self._topology_id, - ) + self._sdam = _SdamTelemetry(self._topology_id, self._listeners, self._events) + self._sdam.topology_opened() - if self._publish_tp: - assert self._events is not None - assert self._listeners is not None - self._events.put((self._listeners.publish_topology_opened, (self._topology_id,))) self._settings = topology_settings topology_description = TopologyDescription( topology_settings.get_topology_type(), @@ -143,37 +134,10 @@ def __init__(self, topology_settings: TopologySettings): initial_td = TopologyDescription( TOPOLOGY_TYPE.Unknown, {}, None, None, None, self._settings ) - if self._publish_tp: - assert self._events is not None - assert self._listeners is not None - self._events.put( - ( - self._listeners.publish_topology_description_changed, - (initial_td, self._description, self._topology_id), - ) - ) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.TOPOLOGY_CHANGE, - topologyId=self._topology_id, - previousDescription=repr(initial_td), - newDescription=repr(self._description), - ) + self._sdam.topology_description_changed(initial_td, self._description) for seed in topology_settings.seeds: - if self._publish_server: - assert self._events is not None - assert self._listeners is not None - self._events.put((self._listeners.publish_server_opened, (seed, self._topology_id))) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.START_SERVER, - topologyId=self._topology_id, - serverHost=seed[0], - serverPort=seed[1], - ) + self._sdam.server_opened(seed) # Store the seed list to help diagnose errors in _error_message(). self._seed_addresses = list(topology_description.server_descriptions()) @@ -508,36 +472,16 @@ def _process_change( server.pool.ready() suppress_event = sd_old == server_description - if self._publish_server and not suppress_event: - assert self._events is not None - assert self._listeners is not None - self._events.put( - ( - self._listeners.publish_server_description_changed, - (sd_old, server_description, server_description.address, self._topology_id), - ) + if not suppress_event: + self._sdam.server_description_changed( + sd_old, server_description, server_description.address ) self._description = new_td self._update_servers() - if self._publish_tp and not suppress_event: - assert self._events is not None - assert self._listeners is not None - self._events.put( - ( - self._listeners.publish_topology_description_changed, - (td_old, self._description, self._topology_id), - ) - ) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG) and not suppress_event: - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.TOPOLOGY_CHANGE, - topologyId=self._topology_id, - previousDescription=repr(td_old), - newDescription=repr(self._description), - ) + if not suppress_event: + self._sdam.topology_description_changed(td_old, self._description) # Shutdown SRV polling for unsupported cluster types. # This is only applicable if the old topology was Unknown, and the @@ -588,24 +532,7 @@ def _process_srv_update(self, seedlist: list[tuple[str, Any]]) -> None: self._description = _updated_topology_description_srv_polling(self._description, seedlist) self._update_servers() - - if self._publish_tp: - assert self._events is not None - assert self._listeners is not None - self._events.put( - ( - self._listeners.publish_topology_description_changed, - (td_old, self._description, self._topology_id), - ) - ) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.TOPOLOGY_CHANGE, - topologyId=self._topology_id, - previousDescription=repr(td_old), - newDescription=repr(self._description), - ) + self._sdam.topology_description_changed(td_old, self._description) def on_srv_update(self, seedlist: list[tuple[str, Any]]) -> None: """Process a new list of nodes obtained from scanning SRV records.""" @@ -742,8 +669,6 @@ def close(self) -> None: # Publish only after releasing the lock. if self._publish_tp: - assert self._events is not None - assert self._listeners is not None self._description = TopologyDescription( TOPOLOGY_TYPE.Unknown, {}, @@ -752,28 +677,7 @@ def close(self) -> None: self._description.max_election_id, self._description._topology_settings, ) - self._events.put( - ( - self._listeners.publish_topology_description_changed, - ( - old_td, - self._description, - self._topology_id, - ), - ) - ) - self._events.put((self._listeners.publish_topology_closed, (self._topology_id,))) - if _SDAM_LOGGER.isEnabledFor(logging.DEBUG): - _debug_log( - _SDAM_LOGGER, - message=_SDAMStatusMessage.TOPOLOGY_CHANGE, - topologyId=self._topology_id, - previousDescription=repr(old_td), - newDescription=repr(self._description), - ) - _debug_log( - _SDAM_LOGGER, message=_SDAMStatusMessage.STOP_TOPOLOGY, topologyId=self._topology_id - ) + self._sdam.topology_closed(old_td, self._description) if self._publish_server or self._publish_tp: # Make sure the events executor thread is fully closed before publishing the remaining events