mongodb/mongo-python-driver
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

PYTHON-4557 - Add log message for retried commands (#2248)

Browse Source
This commit is contained in:
Noah Stapp 2025-04-02 08:29:23 -04:00 committed by GitHub
parent 04ebbcde87
commit 3210b175dd
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
4 changed files with 86 additions and 4 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

27
pymongo/asynchronous/mongo_client.py
View File

@ -89,7 +89,13 @@ from pymongo.lock import (
_async_create_lock,
_release_locks,
)
from pymongo.logger import _CLIENT_LOGGER, _log_client_error, _log_or_warn
from pymongo.logger import (
_CLIENT_LOGGER,
_COMMAND_LOGGER,
_debug_log,
_log_client_error,
_log_or_warn,
)
from pymongo.message import _CursorAddress, _GetMore, _Query
from pymongo.monitoring import ConnectionClosedReason, _EventListeners
from pymongo.operations import (
@ -2686,6 +2692,7 @@ class _ClientConnectionRetryable(Generic[T]):
self._deprioritized_servers: list[Server] = []
self._operation = operation
self._operation_id = operation_id
self._attempt_number = 0
async def run(self) -> T:
"""Runs the supplied func() and attempts a retry
@ -2728,6 +2735,7 @@ class _ClientConnectionRetryable(Generic[T]):
raise
self._retrying = True
self._last_error = exc
self._attempt_number += 1
else:
raise
@ -2749,6 +2757,7 @@ class _ClientConnectionRetryable(Generic[T]):
raise self._last_error from exc
else:
raise
self._attempt_number += 1
if self._bulk:
self._bulk.retrying = True
else:
@ -2827,6 +2836,14 @@ class _ClientConnectionRetryable(Generic[T]):
# not support sessions raise the last error.
self._check_last_error()
self._retryable = False
if self._retrying:
_debug_log(
_COMMAND_LOGGER,
message=f"Retrying write attempt number {self._attempt_number}",
clientId=self._client.client_id,
commandName=self._operation,
operationId=self._operation_id,
)
return await self._func(self._session, conn, self._retryable) # type: ignore
except PyMongoError as exc:
if not self._retryable:
@ -2848,6 +2865,14 @@ class _ClientConnectionRetryable(Generic[T]):
):
if self._retrying and not self._retryable:
self._check_last_error()
if self._retrying:
_debug_log(
_COMMAND_LOGGER,
message=f"Retrying read attempt number {self._attempt_number}",
clientId=self._client._topology_settings._topology_id,
commandName=self._operation,
operationId=self._operation_id,
)
return await self._func(self._session, self._server, conn, read_pref) # type: ignore

27
pymongo/synchronous/mongo_client.py
View File

@ -81,7 +81,13 @@ from pymongo.lock import (
_create_lock,
_release_locks,
)
from pymongo.logger import _CLIENT_LOGGER, _log_client_error, _log_or_warn
from pymongo.logger import (
_CLIENT_LOGGER,
_COMMAND_LOGGER,
_debug_log,
_log_client_error,
_log_or_warn,
)
from pymongo.message import _CursorAddress, _GetMore, _Query
from pymongo.monitoring import ConnectionClosedReason, _EventListeners
from pymongo.operations import (
@ -2672,6 +2678,7 @@ class _ClientConnectionRetryable(Generic[T]):
self._deprioritized_servers: list[Server] = []
self._operation = operation
self._operation_id = operation_id
self._attempt_number = 0
def run(self) -> T:
"""Runs the supplied func() and attempts a retry
@ -2714,6 +2721,7 @@ class _ClientConnectionRetryable(Generic[T]):
raise
self._retrying = True
self._last_error = exc
self._attempt_number += 1
else:
raise
@ -2735,6 +2743,7 @@ class _ClientConnectionRetryable(Generic[T]):
raise self._last_error from exc
else:
raise
self._attempt_number += 1
if self._bulk:
self._bulk.retrying = True
else:
@ -2813,6 +2822,14 @@ class _ClientConnectionRetryable(Generic[T]):
# not support sessions raise the last error.
self._check_last_error()
self._retryable = False
if self._retrying:
_debug_log(
_COMMAND_LOGGER,
message=f"Retrying write attempt number {self._attempt_number}",
clientId=self._client.client_id,
commandName=self._operation,
operationId=self._operation_id,
)
return self._func(self._session, conn, self._retryable) # type: ignore
except PyMongoError as exc:
if not self._retryable:
@ -2834,6 +2851,14 @@ class _ClientConnectionRetryable(Generic[T]):
):
if self._retrying and not self._retryable:
self._check_last_error()
if self._retrying:
_debug_log(
_COMMAND_LOGGER,
message=f"Retrying read attempt number {self._attempt_number}",
clientId=self._client._topology_settings._topology_id,
commandName=self._operation,
operationId=self._operation_id,
)
return self._func(self._session, self._server, conn, read_pref) # type: ignore

18
test/asynchronous/test_logger.py
View File

@ -15,7 +15,7 @@ from __future__ import annotations
import os
from test import unittest
from test.asynchronous import AsyncIntegrationTest
from test.asynchronous import AsyncIntegrationTest, async_client_context
from unittest.mock import patch
from bson import json_util
@ -97,6 +97,22 @@ class TestLogger(AsyncIntegrationTest):
await c.db.test.insert_one({"x": "1"})
self.assertGreater(len(cm.records), 0)
@async_client_context.require_failCommand_fail_point
async def test_logging_retry_read_attempts(self):
await self.db.test.insert_one({"x": "1"})
async with self.fail_point(
{"mode": {"times": 1}, "data": {"failCommands": ["find"], "closeConnection": True}}
):
with self.assertLogs("pymongo.command", level="DEBUG") as cm:
await self.db.test.find_one({"x": "1"})
retry_messages = [
r.getMessage() for r in cm.records if "Retrying read attempt" in r.getMessage()
]
print(retry_messages)
self.assertEqual(len(retry_messages), 1)
if __name__ == "__main__":
unittest.main()

18
test/test_logger.py
View File

@ -14,7 +14,7 @@
from __future__ import annotations
import os
from test import IntegrationTest, unittest
from test import IntegrationTest, client_context, unittest
from unittest.mock import patch
from bson import json_util
@ -96,6 +96,22 @@ class TestLogger(IntegrationTest):
c.db.test.insert_one({"x": "1"})
self.assertGreater(len(cm.records), 0)
@client_context.require_failCommand_fail_point
def test_logging_retry_read_attempts(self):
self.db.test.insert_one({"x": "1"})
with self.fail_point(
{"mode": {"times": 1}, "data": {"failCommands": ["find"], "closeConnection": True}}
):
with self.assertLogs("pymongo.command", level="DEBUG") as cm:
self.db.test.find_one({"x": "1"})
retry_messages = [
r.getMessage() for r in cm.records if "Retrying read attempt" in r.getMessage()
]
print(retry_messages)
self.assertEqual(len(retry_messages), 1)
if __name__ == "__main__":
unittest.main()