[2024/11/05 23:37:48.728] FAILURE: pymongo.errors.OperationFailure: Unable to acquire lock '{7211588314512027680: Database, 294059286870945824}' within a max lock request timeout of '25ms' milliseconds., full error: {'errorLabels': ['TransientTransactionError'], 'operationTime': Timestamp(1730871391, 3), 'ok': 0.0, 'errmsg': "Unable to acquire lock '{7211588314512027680: Database, 294059286870945824}' within a max lock request timeout of '25ms' milliseconds.", 'code': 24, 'codeName': 'LockTimeout', '$clusterTime': {'clusterTime': Timestamp(1730871391, 3), 'signature': {'hash': b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00', 'keyId': 0}}} ()
 [2024/11/05 23:37:48.728] self = <test.asynchronous.test_transactions.TestTransactions testMethod=test_transaction_direct_connection>
 [2024/11/05 23:37:48.728]     @async_client_context.require_transactions
 [2024/11/05 23:37:48.728]     async def test_transaction_direct_connection(self):
 [2024/11/05 23:37:48.728]         client = await self.async_single_client()
 [2024/11/05 23:37:48.728]         coll = client.pymongo_test.test
 [2024/11/05 23:37:48.728]     
 [2024/11/05 23:37:48.728]         # Make sure the collection exists.
 [2024/11/05 23:37:48.728]         await coll.insert_one({})
 [2024/11/05 23:37:48.728]         self.assertEqual(client.topology_description.topology_type_name, "Single")
 [2024/11/05 23:37:48.728]     
 [2024/11/05 23:37:48.728]         async def find(*args, **kwargs):
 [2024/11/05 23:37:48.728]             return coll.find(*args, **kwargs)
 [2024/11/05 23:37:48.728]     
 [2024/11/05 23:37:48.728]         async def find_raw_batches(*args, **kwargs):
 [2024/11/05 23:37:48.728]             return coll.find_raw_batches(*args, **kwargs)
 [2024/11/05 23:37:48.728]     
 [2024/11/05 23:37:48.728]         ops = [
 [2024/11/05 23:37:48.728]             (coll.bulk_write, [[InsertOne[dict]({})]]),
 [2024/11/05 23:37:48.728]             (coll.insert_one, [{}]),
 [2024/11/05 23:37:48.728]             (coll.insert_many, [[{}, {}]]),
 [2024/11/05 23:37:48.728]             (coll.replace_one, [{}, {}]),
 [2024/11/05 23:37:48.728]             (coll.update_one, [{}, {"$set": {"a": 1}}]),
 [2024/11/05 23:37:48.728]             (coll.update_many, [{}, {"$set": {"a": 1}}]),
 [2024/11/05 23:37:48.728]             (coll.delete_one, [{}]),
 [2024/11/05 23:37:48.728]             (coll.delete_many, [{}]),
 [2024/11/05 23:37:48.728]             (coll.find_one_and_replace, [{}, {}]),
 [2024/11/05 23:37:48.728]             (coll.find_one_and_update, [{}, {"$set": {"a": 1}}]),
 [2024/11/05 23:37:48.728]             (coll.find_one_and_delete, [{}, {}]),
 [2024/11/05 23:37:48.728]             (coll.find_one, [{}]),
 [2024/11/05 23:37:48.728]             (coll.count_documents, [{}]),
 [2024/11/05 23:37:48.728]             (coll.distinct, ["foo"]),
 [2024/11/05 23:37:48.728]             (coll.aggregate, [[]]),
 [2024/11/05 23:37:48.728]             (find, [{}]),
 [2024/11/05 23:37:48.728]             (coll.aggregate_raw_batches, [[]]),
 [2024/11/05 23:37:48.728]             (find_raw_batches, [{}]),
 [2024/11/05 23:37:48.728]             (coll.database.command, ["find", coll.name]),
 [2024/11/05 23:37:48.728]         ]
 [2024/11/05 23:37:48.728]         for f, args in ops:
 [2024/11/05 23:37:48.728]             async with client.start_session() as s, await s.start_transaction():
 [2024/11/05 23:37:48.728] >               res = await f(*args, session=s)  # type:ignore[operator]
 [2024/11/05 23:37:48.728] test/asynchronous/test_transactions.py:385: 
 [2024/11/05 23:37:48.728] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
 [2024/11/05 23:37:48.728] pymongo/_csot.py:109: in csot_wrapper
 [2024/11/05 23:37:48.728]     return await func(self, *args, **kwargs)
 [2024/11/05 23:37:48.728] pymongo/asynchronous/collection.py:976: in insert_many
 [2024/11/05 23:37:48.728]     await blk.execute(write_concern, session, _Op.INSERT)
 [2024/11/05 23:37:48.728] pymongo/asynchronous/bulk.py:753: in execute
 [2024/11/05 23:37:48.728]     return await self.execute_command(generator, write_concern, session, operation)
 [2024/11/05 23:37:48.728] pymongo/asynchronous/bulk.py:604: in execute_command
 [2024/11/05 23:37:48.728]     _ = await client._retryable_write(
 [2024/11/05 23:37:48.728] pymongo/asynchronous/mongo_client.py:1896: in _retryable_write
 [2024/11/05 23:37:48.728]     return await self._retry_with_session(retryable, func, s, bulk, operation, operation_id)
 [2024/11/05 23:37:48.728] pymongo/asynchronous/mongo_client.py:1782: in _retry_with_session
 [2024/11/05 23:37:48.728]     return await self._retry_internal(
 [2024/11/05 23:37:48.728] pymongo/_csot.py:109: in csot_wrapper
 [2024/11/05 23:37:48.728]     return await func(self, *args, **kwargs)
 [2024/11/05 23:37:48.728] pymongo/asynchronous/mongo_client.py:1817: in _retry_internal
 [2024/11/05 23:37:48.728]     return await _ClientConnectionRetryable(
 [2024/11/05 23:37:48.728] pymongo/asynchronous/mongo_client.py:2567: in run
 [2024/11/05 23:37:48.728]     return await self._read() if self._is_read else await self._write()
 [2024/11/05 23:37:48.728] pymongo/asynchronous/mongo_client.py:2689: in _write
 [2024/11/05 23:37:48.728]     return await self._func(self._session, conn, self._retryable)  # type: ignore
 [2024/11/05 23:37:48.728] pymongo/asynchronous/bulk.py:593: in retryable_bulk
 [2024/11/05 23:37:48.728]     await self._execute_command(
 [2024/11/05 23:37:48.728] pymongo/asynchronous/bulk.py:538: in _execute_command
 [2024/11/05 23:37:48.728]     result, to_send = await self._execute_batch(bwc, cmd, ops, client)
 [2024/11/05 23:37:48.728] pymongo/asynchronous/bulk.py:462: in _execute_batch
 [2024/11/05 23:37:48.728]     result = await self.write_command(bwc, cmd, request_id, msg, to_send, client)  # type: ignore[arg-type]
 [2024/11/05 23:37:48.728] pymongo/asynchronous/helpers.py:45: in inner
 [2024/11/05 23:37:48.728]     return await func(*args, **kwargs)
 [2024/11/05 23:37:48.728] pymongo/asynchronous/bulk.py:274: in write_command
 [2024/11/05 23:37:48.728]     reply = await bwc.conn.write_command(request_id, msg, bwc.codec)  # type: ignore[misc]
 [2024/11/05 23:37:48.728] pymongo/asynchronous/pool.py:628: in write_command
 [2024/11/05 23:37:48.728]     helpers_shared._check_command_response(result, self.max_wire_version)
 [2024/11/05 23:37:48.728] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
 [2024/11/05 23:37:48.728] response = {'$clusterTime': {'clusterTime': Timestamp(1730871391, 3), 'signature': {'hash': b'\x00\x00\x00\x00\x00\x00\x00\x00\x0... '{7211588314512027680: Database, 294059286870945824}' within a max lock request timeout of '25ms' milliseconds.", ...}
 [2024/11/05 23:37:48.728] max_wire_version = 7, allowable_errors = None, parse_write_concern_error = False
 [2024/11/05 23:37:48.728]     def _check_command_response(
 [2024/11/05 23:37:48.728]         response: _DocumentOut,
 [2024/11/05 23:37:48.728]         max_wire_version: Optional[int],
 [2024/11/05 23:37:48.728]         allowable_errors: Optional[Container[Union[int, str]]] = None,
 [2024/11/05 23:37:48.728]         parse_write_concern_error: bool = False,
 [2024/11/05 23:37:48.728]     ) -> None:
 [2024/11/05 23:37:48.728]         """Check the response to a command for errors."""
 [2024/11/05 23:37:48.728]         if "ok" not in response:
 [2024/11/05 23:37:48.728]             # Server didn't recognize our message as a command.
 [2024/11/05 23:37:48.728]             raise OperationFailure(
 [2024/11/05 23:37:48.728]                 response.get("$err"),  # type: ignore[arg-type]
 [2024/11/05 23:37:48.728]                 response.get("code"),
 [2024/11/05 23:37:48.728]                 response,
 [2024/11/05 23:37:48.728]                 max_wire_version,
 [2024/11/05 23:37:48.728]             )
 [2024/11/05 23:37:48.728]     
 [2024/11/05 23:37:48.728]         if parse_write_concern_error and "writeConcernError" in response:
 [2024/11/05 23:37:48.728]             _error = response["writeConcernError"]
 [2024/11/05 23:37:48.728]             _labels = response.get("errorLabels")
 [2024/11/05 23:37:48.728]             if _labels:
 [2024/11/05 23:37:48.728]                 _error.update({"errorLabels": _labels})
 [2024/11/05 23:37:48.728]             _raise_write_concern_error(_error)
 [2024/11/05 23:37:48.728]     
 [2024/11/05 23:37:48.728]         if response["ok"]:
 [2024/11/05 23:37:48.728]             return
 [2024/11/05 23:37:48.728]     
 [2024/11/05 23:37:48.728]         details = response
 [2024/11/05 23:37:48.728]         # Mongos returns the error details in a 'raw' object
 [2024/11/05 23:37:48.728]         # for some errors.
 [2024/11/05 23:37:48.728]         if "raw" in response:
 [2024/11/05 23:37:48.728]             for shard in response["raw"].values():
 [2024/11/05 23:37:48.728]                 # Grab the first non-empty raw error from a shard.
 [2024/11/05 23:37:48.728]                 if shard.get("errmsg") and not shard.get("ok"):
 [2024/11/05 23:37:48.728]                     details = shard
 [2024/11/05 23:37:48.728]                     break
 [2024/11/05 23:37:48.728]     
 [2024/11/05 23:37:48.728]         errmsg = details["errmsg"]
 [2024/11/05 23:37:48.728]         code = details.get("code")
 [2024/11/05 23:37:48.728]     
 [2024/11/05 23:37:48.728]         # For allowable errors, only check for error messages when the code is not
 [2024/11/05 23:37:48.728]         # included.
 [2024/11/05 23:37:48.728]         if allowable_errors:
 [2024/11/05 23:37:48.728]             if code is not None:
 [2024/11/05 23:37:48.728]                 if code in allowable_errors:
 [2024/11/05 23:37:48.728]                     return
 [2024/11/05 23:37:48.728]             elif errmsg in allowable_errors:
 [2024/11/05 23:37:48.728]                 return
 [2024/11/05 23:37:48.728]     
 [2024/11/05 23:37:48.728]         # Server is "not primary" or "recovering"
 [2024/11/05 23:37:48.728]         if code is not None:
 [2024/11/05 23:37:48.728]             if code in _NOT_PRIMARY_CODES:
 [2024/11/05 23:37:48.728]                 raise NotPrimaryError(errmsg, response)
 [2024/11/05 23:37:48.728]         elif HelloCompat.LEGACY_ERROR in errmsg or "node is recovering" in errmsg:
 [2024/11/05 23:37:48.728]             raise NotPrimaryError(errmsg, response)
 [2024/11/05 23:37:48.728]     
 [2024/11/05 23:37:48.728]         # Other errors
 [2024/11/05 23:37:48.728]         # findAndModify with upsert can raise duplicate key error
 [2024/11/05 23:37:48.728]         if code in (11000, 11001, 12582):
 [2024/11/05 23:37:48.728]             raise DuplicateKeyError(errmsg, code, response, max_wire_version)
 [2024/11/05 23:37:48.728]         elif code == 50:
 [2024/11/05 23:37:48.728]             raise ExecutionTimeout(errmsg, code, response, max_wire_version)
 [2024/11/05 23:37:48.728]         elif code == 43:
 [2024/11/05 23:37:48.728]             raise CursorNotFound(errmsg, code, response, max_wire_version)
 [2024/11/05 23:37:48.728]     
 [2024/11/05 23:37:48.728] >       raise OperationFailure(errmsg, code, response, max_wire_version)
 [2024/11/05 23:37:48.728] E       pymongo.errors.OperationFailure: Unable to acquire lock '{7211588314512027680: Database, 294059286870945824}' within a max lock request timeout of '25ms' milliseconds., full error: {'errorLabels': ['TransientTransactionError'], 'operationTime': Timestamp(1730871391, 3), 'ok': 0.0, 'errmsg': "Unable to acquire lock '{7211588314512027680: Database, 294059286870945824}' within a max lock request timeout of '25ms' milliseconds.", 'code': 24, 'codeName': 'LockTimeout', '$clusterTime': {'clusterTime': Timestamp(1730871391, 3), 'signature': {'hash': b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00', 'keyId': 0}}}
 [2024/11/05 23:37:48.728] pymongo/helpers_shared.py:247: OperationFailure