From 517ee4d09f8a4d0e3cc1eb546a4f701ca2fb3662 Mon Sep 17 00:00:00 2001 From: Mephisto Fox Date: Tue, 24 Mar 2026 17:20:56 +0300 Subject: [PATCH] fix: handle PythonFinalizationError in LoggerManager shutdown Python 3.13+ raises PythonFinalizationError when calling thread.join() during interpreter shutdown. LoggerManager.__del__ calls shutdown() which calls QueueListener.stop(), triggering this error. Fix: check sys.is_finalizing() before calling listener.stop(). During finalization, close handlers directly without joining the thread. Reproduces on Python 3.13+ with USE_ASYNC=True (default). Co-authored-by: Mephisto --- src/ozonapi/infrastructure/logging/manager.py | 19 +++- tests/test_infrastructure/test_logging.py | 105 ++++++++++++------ 2 files changed, 86 insertions(+), 38 deletions(-) diff --git a/src/ozonapi/infrastructure/logging/manager.py b/src/ozonapi/infrastructure/logging/manager.py index 25064b4..ec464cf 100644 --- a/src/ozonapi/infrastructure/logging/manager.py +++ b/src/ozonapi/infrastructure/logging/manager.py @@ -5,6 +5,7 @@ and proper resource cleanup. """ +import sys import logging import weakref from logging.handlers import QueueHandler @@ -178,7 +179,12 @@ def _copy_logger(self, source: logging.Logger, target: logging.Logger) -> None: target.setLevel(source.level) def shutdown(self) -> None: - """Clean up all logging resources for this domain.""" + """Clean up all logging resources for this domain. + + During interpreter finalization (Python 3.13+), QueueListener.stop() + calls thread.join() which raises PythonFinalizationError. In that case + we close handlers directly without joining the listener thread. + """ if not self._is_configured: return @@ -187,7 +193,16 @@ def shutdown(self) -> None: self._managed_loggers.clear() if self._listener: - self._listener.stop() + if sys.is_finalizing(): + # During interpreter shutdown, threads cannot be joined. + # Close handlers directly to release resources. + for handler in getattr(self._listener, 'handlers', ()): + try: + handler.close() + except Exception: + pass + else: + self._listener.stop() self._listener = None self._is_configured = False diff --git a/tests/test_infrastructure/test_logging.py b/tests/test_infrastructure/test_logging.py index 40aacb5..869351f 100644 --- a/tests/test_infrastructure/test_logging.py +++ b/tests/test_infrastructure/test_logging.py @@ -32,7 +32,9 @@ def env_vars(self, monkeypatch: pytest.MonkeyPatch) -> None: def default_manager(self) -> Generator[LoggerManager, None, None]: """Fixture providing configured LoggerManager with default settings.""" manager = LoggerManager("test") - settings = LoggingSettings(LEVEL="DEBUG", JSON=False, USE_ASYNC=False) + settings = LoggingSettings( + LEVEL="DEBUG", JSON=False, USE_ASYNC=False, MAX_QUEUE_SIZE=1000 + ) manager.configure(settings) yield manager manager.shutdown() @@ -59,12 +61,16 @@ def test_manager_configuration(self, default_manager: LoggerManager) -> None: assert logging.getLogger("test").level == logging.DEBUG assert len(logging.getLogger("test").handlers) > 0 - def test_reconfiguration_raises_exception(self, default_manager: LoggerManager) -> None: + def test_reconfiguration_raises_exception( + self, default_manager: LoggerManager + ) -> None: """Test that reconfiguring a manager raises RuntimeError.""" with pytest.raises(RuntimeError, match="already configured"): default_manager.configure(LoggingSettings()) - def test_duplicate_domain_raises_exception(self, default_manager: LoggerManager) -> None: + def test_duplicate_domain_raises_exception( + self, default_manager: LoggerManager + ) -> None: """Test that creating another manager for same domain raises RuntimeError.""" with pytest.raises(RuntimeError, match="already configured by another manager"): manager2 = LoggerManager("test") @@ -114,7 +120,7 @@ def test_console_logger_output(self, capsys: pytest.CaptureFixture) -> None: settings = LoggingSettings( USE_ASYNC=False, # Disable async to test console output directly JSON=False, # Ensure we're using text format - FORMAT='%(message)s' # Simple format for easier testing + FORMAT="%(message)s", # Simple format for easier testing ) manager.configure(settings) @@ -145,7 +151,7 @@ def test_json_logging(self) -> None: lineno=1, msg="Test JSON output", args=None, - exc_info=None + exc_info=None, ) formatted = handler.formatter.format(record) @@ -161,12 +167,14 @@ def test_file_logging_parameters(self, temp_log_dir: Path) -> None: FILE="test.log", MAX_BYTES=1024, BACKUP_FILES_COUNT=3, - USE_ASYNC=False + USE_ASYNC=False, ) manager.configure(settings) logger = manager.get_logger() - file_handlers = [h for h in logger.handlers if isinstance(h, RotatingFileHandler)] + file_handlers = [ + h for h in logger.handlers if isinstance(h, RotatingFileHandler) + ] assert len(file_handlers) == 1 handler = file_handlers[0] @@ -181,7 +189,9 @@ def test_file_logging_output(self, temp_log_dir: Path) -> None: file_name = "output_test.log" log_file = os.path.join(temp_log_dir, file_name) manager = LoggerManager("file_output_test") - settings = LoggingSettings(DIR=str(temp_log_dir), FILE=file_name, USE_ASYNC=False) + settings = LoggingSettings( + DIR=str(temp_log_dir), FILE=file_name, USE_ASYNC=False + ) manager.configure(settings) logger = manager.get_logger() @@ -217,16 +227,20 @@ def test_queue_size_parameter(self) -> None: assert manager._listener.queue.maxsize == 10 manager.shutdown() - def test_custom_handler_factory(self, temp_log_dir: Path, capsys: pytest.CaptureFixture): + def test_custom_handler_factory( + self, temp_log_dir: Path, capsys: pytest.CaptureFixture + ): """Test that custom_handler_factory properly integrates custom handlers.""" # Setup temp_log_dir.mkdir(parents=True, exist_ok=True) - test_log_file = 'test.log' + test_log_file = "test.log" # Track created handlers for cleanup verification test_handlers = [] - def create_custom_handlers(settings: LoggingSettings, formatter: logging.Formatter): + def create_custom_handlers( + settings: LoggingSettings, formatter: logging.Formatter + ): """Test custom handler factory that creates multiple handler types.""" nonlocal test_handlers @@ -238,21 +252,21 @@ def create_custom_handlers(settings: LoggingSettings, formatter: logging.Formatt # Create a SysLogHandler (mocked to stdout for testing) syslog = logging.StreamHandler() - syslog.setFormatter(logging.Formatter('SYSLOG: %(message)s')) + syslog.setFormatter(logging.Formatter("SYSLOG: %(message)s")) syslog.setLevel(settings.LEVEL) # Explicitly set level from settings test_handlers.append(syslog) return [memory_handler, syslog] # Test configuration with custom factory - manager = LoggerManager('custom_test') + manager = LoggerManager("custom_test") settings = LoggingSettings( - LEVEL='WARNING', + LEVEL="WARNING", JSON=False, USE_ASYNC=False, DIR=str(temp_log_dir), FILE=test_log_file, - FORMAT='%(levelname)s - %(message)s' + FORMAT="%(levelname)s - %(message)s", ) manager.configure(settings, custom_handler_factory=create_custom_handlers) @@ -283,19 +297,17 @@ def create_custom_handlers(settings: LoggingSettings, formatter: logging.Formatt # Verify shutdown cleanup manager.shutdown() for handler in test_handlers: - if hasattr(handler, 'closed'): # Only MemoryHandler has closed attribute + if hasattr(handler, "closed"): # Only MemoryHandler has closed attribute assert handler.closed is True else: # For StreamHandler, verify it's not in logger anymore - assert handler not in logging.getLogger('custom_test').handlers + assert handler not in logging.getLogger("custom_test").handlers - def test_custom_handler_factory_not_callable_raises_exception(self, temp_log_dir: Path) -> None: + def test_custom_handler_factory_not_callable_raises_exception( + self, temp_log_dir: Path + ) -> None: """Test that non-callable custom_handler_factory raises TypeError.""" manager = LoggerManager("not_callable_test") - settings = LoggingSettings( - LEVEL="INFO", - DIR=None, - USE_ASYNC=False - ) + settings = LoggingSettings(LEVEL="INFO", DIR=None, USE_ASYNC=False) # Test with non-callable factory (using a string as example) with pytest.raises(TypeError, match="is not callable"): @@ -303,14 +315,12 @@ def test_custom_handler_factory_not_callable_raises_exception(self, temp_log_dir manager.shutdown() - def test_custom_handler_factory_non_iterable_return_raises_exception(self, temp_log_dir: Path) -> None: + def test_custom_handler_factory_non_iterable_return_raises_exception( + self, temp_log_dir: Path + ) -> None: """Test that custom_handler_factory returning non-iterable raises TypeError.""" manager = LoggerManager("non_iterable_test") - settings = LoggingSettings( - LEVEL="INFO", - DIR=None, - USE_ASYNC=False - ) + settings = LoggingSettings(LEVEL="INFO", DIR=None, USE_ASYNC=False) # Factory that returns a non-iterable (using int as example) def bad_factory(*args, **kwargs): @@ -321,14 +331,12 @@ def bad_factory(*args, **kwargs): manager.shutdown() - def test_custom_handler_factory_non_handler_objects_raises_exception(self, temp_log_dir: Path) -> None: + def test_custom_handler_factory_non_handler_objects_raises_exception( + self, temp_log_dir: Path + ) -> None: """Test that custom_handler_factory returning non-handler objects raises TypeError.""" manager = LoggerManager("non_handler_test") - settings = LoggingSettings( - LEVEL="INFO", - DIR=None, - USE_ASYNC=False - ) + settings = LoggingSettings(LEVEL="INFO", DIR=None, USE_ASYNC=False) # Factory that returns a mix of valid and invalid objects def bad_factory(_, formatter): @@ -349,4 +357,29 @@ def test_shutdown_cleanup(self, default_manager: LoggerManager) -> None: default_manager.shutdown() assert len(logger.handlers) == 0 assert not default_manager._is_configured - assert len(default_manager._managed_loggers) == 0 \ No newline at end of file + assert len(default_manager._managed_loggers) == 0 + + def test_shutdown_during_finalization(self) -> None: + """Test that shutdown handles interpreter finalization gracefully. + + Python 3.13+ raises PythonFinalizationError when calling thread.join() + during interpreter shutdown. The shutdown method should handle this by + closing handlers directly without joining the listener thread. + """ + import sys + from unittest.mock import patch + + manager = LoggerManager("finalization_test") + settings = LoggingSettings(USE_ASYNC=True) + manager.configure(settings) + + assert manager._listener is not None + + # Simulate interpreter finalization — shutdown must not raise + with patch.object(sys, "is_finalizing", return_value=True): + manager.shutdown() + + # Verify cleanup happened without errors + assert not manager._is_configured + assert manager._listener is None + assert len(manager._managed_loggers) == 0