diff --git a/pymongo/asynchronous/mongo_client.py b/pymongo/asynchronous/mongo_client.py index 37be9a194c..eefafd5fda 100644 --- a/pymongo/asynchronous/mongo_client.py +++ b/pymongo/asynchronous/mongo_client.py @@ -88,7 +88,7 @@ _async_create_lock, _release_locks, ) -from pymongo.logger import _CLIENT_LOGGER, _log_or_warn +from pymongo.logger import _CLIENT_LOGGER, _log_client_error, _log_or_warn from pymongo.message import _CursorAddress, _GetMore, _Query from pymongo.monitoring import ConnectionClosedReason from pymongo.operations import ( @@ -2049,7 +2049,7 @@ async def _process_kill_cursors(self) -> None: # can be caught in _process_periodic_tasks raise else: - helpers_shared._handle_exception() + _log_client_error() # Don't re-open topology if it's closed and there's no pending cursors. if address_to_cursor_ids: @@ -2061,7 +2061,7 @@ async def _process_kill_cursors(self) -> None: if isinstance(exc, InvalidOperation) and self._topology._closed: raise else: - helpers_shared._handle_exception() + _log_client_error() # This method is run periodically by a background thread. async def _process_periodic_tasks(self) -> None: @@ -2075,7 +2075,7 @@ async def _process_periodic_tasks(self) -> None: if isinstance(exc, InvalidOperation) and self._topology._closed: return else: - helpers_shared._handle_exception() + _log_client_error() def _return_server_session( self, server_session: Union[_ServerSession, _EmptyServerSession] diff --git a/pymongo/logger.py b/pymongo/logger.py index 2ff35328b4..9079dc3f3d 100644 --- a/pymongo/logger.py +++ b/pymongo/logger.py @@ -96,6 +96,14 @@ class _SDAMStatusMessage(str, enum.Enum): } +def _log_client_error() -> None: + # This is called from a daemon thread so check for None to account for interpreter shutdown. + logger = _CLIENT_LOGGER + if logger: + # logger.exception includes the full traceback. + logger.exception("MongoClient background task encountered an error:") + + def _debug_log(logger: logging.Logger, **fields: Any) -> None: logger.debug(LogMessage(**fields)) diff --git a/pymongo/synchronous/mongo_client.py b/pymongo/synchronous/mongo_client.py index 373deabd4e..b101636066 100644 --- a/pymongo/synchronous/mongo_client.py +++ b/pymongo/synchronous/mongo_client.py @@ -80,7 +80,7 @@ _create_lock, _release_locks, ) -from pymongo.logger import _CLIENT_LOGGER, _log_or_warn +from pymongo.logger import _CLIENT_LOGGER, _log_client_error, _log_or_warn from pymongo.message import _CursorAddress, _GetMore, _Query from pymongo.monitoring import ConnectionClosedReason from pymongo.operations import ( @@ -2043,7 +2043,7 @@ def _process_kill_cursors(self) -> None: # can be caught in _process_periodic_tasks raise else: - helpers_shared._handle_exception() + _log_client_error() # Don't re-open topology if it's closed and there's no pending cursors. if address_to_cursor_ids: @@ -2055,7 +2055,7 @@ def _process_kill_cursors(self) -> None: if isinstance(exc, InvalidOperation) and self._topology._closed: raise else: - helpers_shared._handle_exception() + _log_client_error() # This method is run periodically by a background thread. def _process_periodic_tasks(self) -> None: @@ -2069,7 +2069,7 @@ def _process_periodic_tasks(self) -> None: if isinstance(exc, InvalidOperation) and self._topology._closed: return else: - helpers_shared._handle_exception() + _log_client_error() def _return_server_session( self, server_session: Union[_ServerSession, _EmptyServerSession] diff --git a/test/asynchronous/test_client.py b/test/asynchronous/test_client.py index 4758ce3dda..acc815c8a4 100644 --- a/test/asynchronous/test_client.py +++ b/test/asynchronous/test_client.py @@ -1790,6 +1790,29 @@ async def stall_connect(*args, **kwargs): # Each ping command should not take more than 2 seconds self.assertLess(total, 2) + async def test_background_connections_log_on_error(self): + with self.assertLogs("pymongo.client", level="ERROR") as cm: + client = await self.async_rs_or_single_client(minPoolSize=1) + # Create a single connection in the pool. + await client.admin.command("ping") + + # Cause new connections to fail. + pool = await async_get_pool(client) + + async def fail_connect(*args, **kwargs): + raise Exception("failed to connect") + + pool.connect = fail_connect + # Un-patch Pool.connect to break the cyclic reference. + self.addCleanup(delattr, pool, "connect") + + await pool.reset_without_pause() + + await async_wait_until( + lambda: "failed to connect" in "".join(cm.output), "start creating connections" + ) + self.assertIn("MongoClient background task encountered an error", "".join(cm.output)) + @async_client_context.require_replica_set async def test_direct_connection(self): # direct_connection=True should result in Single topology. diff --git a/test/test_client.py b/test/test_client.py index aa321d2925..8e99866cc8 100644 --- a/test/test_client.py +++ b/test/test_client.py @@ -1747,6 +1747,29 @@ def stall_connect(*args, **kwargs): # Each ping command should not take more than 2 seconds self.assertLess(total, 2) + def test_background_connections_log_on_error(self): + with self.assertLogs("pymongo.client", level="ERROR") as cm: + client = self.rs_or_single_client(minPoolSize=1) + # Create a single connection in the pool. + client.admin.command("ping") + + # Cause new connections to fail. + pool = get_pool(client) + + def fail_connect(*args, **kwargs): + raise Exception("failed to connect") + + pool.connect = fail_connect + # Un-patch Pool.connect to break the cyclic reference. + self.addCleanup(delattr, pool, "connect") + + pool.reset_without_pause() + + wait_until( + lambda: "failed to connect" in "".join(cm.output), "start creating connections" + ) + self.assertIn("MongoClient background task encountered an error", "".join(cm.output)) + @client_context.require_replica_set def test_direct_connection(self): # direct_connection=True should result in Single topology.