PYTHON-4557 - Fix write log messages for retried commands (#2260)

Author: NoahStapp

pymongo/asynchronous/mongo_client.py

@@ -2840,7 +2840,7 @@ async def _write(self) -> T:
                     _debug_log(
                         _COMMAND_LOGGER,
                         message=f"Retrying write attempt number {self._attempt_number}",
-                        clientId=self._client.client_id,
+                        clientId=self._client._topology_settings._topology_id,
                         commandName=self._operation,
                         operationId=self._operation_id,
                     )

pymongo/synchronous/mongo_client.py

@@ -2826,7 +2826,7 @@ def _write(self) -> T:
                     _debug_log(
                         _COMMAND_LOGGER,
                         message=f"Retrying write attempt number {self._attempt_number}",
-                        clientId=self._client.client_id,
+                        clientId=self._client._topology_settings._topology_id,
                         commandName=self._operation,
                         operationId=self._operation_id,
                     )

test/asynchronous/test_logger.py

@@ -102,15 +102,42 @@ 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}}
+            {
+                "mode": {"times": 1},
+                "data": {
+                    "failCommands": ["find"],
+                    "errorCode": 10107,
+                    "errorLabels": ["RetryableWriteError"],
+                },
+            }
         ):
             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)
+
+    @async_client_context.require_failCommand_fail_point
+    @async_client_context.require_retryable_writes
+    async def test_logging_retry_write_attempts(self):
+        async with self.fail_point(
+            {
+                "mode": {"times": 1},
+                "data": {
+                    "errorCode": 10107,
+                    "errorLabels": ["RetryableWriteError"],
+                    "failCommands": ["insert"],
+                },
+            }
+        ):
+            with self.assertLogs("pymongo.command", level="DEBUG") as cm:
+                await self.db.test.insert_one({"x": "1"})
+
+        retry_messages = [
+            r.getMessage() for r in cm.records if "Retrying write attempt" in r.getMessage()
+        ]
         self.assertEqual(len(retry_messages), 1)
 
 

test/test_logger.py

@@ -101,15 +101,42 @@ 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}}
+            {
+                "mode": {"times": 1},
+                "data": {
+                    "failCommands": ["find"],
+                    "errorCode": 10107,
+                    "errorLabels": ["RetryableWriteError"],
+                },
+            }
         ):
             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)
+
+    @client_context.require_failCommand_fail_point
+    @client_context.require_retryable_writes
+    def test_logging_retry_write_attempts(self):
+        with self.fail_point(
+            {
+                "mode": {"times": 1},
+                "data": {
+                    "errorCode": 10107,
+                    "errorLabels": ["RetryableWriteError"],
+                    "failCommands": ["insert"],
+                },
+            }
+        ):
+            with self.assertLogs("pymongo.command", level="DEBUG") as cm:
+                self.db.test.insert_one({"x": "1"})
+
+        retry_messages = [
+            r.getMessage() for r in cm.records if "Retrying write attempt" in r.getMessage()
+        ]
         self.assertEqual(len(retry_messages), 1)