From f28cc39032b4e707d5bf8a5a243f49486f733b3d Mon Sep 17 00:00:00 2001 From: Vinay Sajip Date: Wed, 25 Jun 2025 06:42:38 +0100 Subject: [PATCH 1/2] gh-91555: Revert disabling of logger while handling log record. (GH-135858) Revert "gh-91555: disable logger while handling log record (GH-131812)" This reverts commit 2561e148ec985755baa3984b91fd0bfc089b283c. (cherry picked from commit 18d32fb646b804b26c80910b2c65938e81e2cced) Co-authored-by: Vinay Sajip --- Lib/logging/__init__.py | 28 ++++---------- Lib/test/test_logging.py | 83 ---------------------------------------- 2 files changed, 8 insertions(+), 103 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 357d127c090482..b95c3aacf7d17a 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -1475,8 +1475,6 @@ class Logger(Filterer): level, and "input.csv", "input.xls" and "input.gnu" for the sub-levels. There is no arbitrary limit to the depth of nesting. """ - _tls = threading.local() - def __init__(self, name, level=NOTSET): """ Initialize the logger with a name and an optional level. @@ -1673,19 +1671,14 @@ def handle(self, record): This method is used for unpickled records received from a socket, as well as those created locally. Logger-level filtering is applied. """ - if self._is_disabled(): + if self.disabled: return - - self._tls.in_progress = True - try: - maybe_record = self.filter(record) - if not maybe_record: - return - if isinstance(maybe_record, LogRecord): - record = maybe_record - self.callHandlers(record) - finally: - self._tls.in_progress = False + maybe_record = self.filter(record) + if not maybe_record: + return + if isinstance(maybe_record, LogRecord): + record = maybe_record + self.callHandlers(record) def addHandler(self, hdlr): """ @@ -1773,7 +1766,7 @@ def isEnabledFor(self, level): """ Is this logger enabled for level 'level'? """ - if self._is_disabled(): + if self.disabled: return False try: @@ -1823,11 +1816,6 @@ def _hierlevel(logger): if isinstance(item, Logger) and item.parent is self and _hierlevel(item) == 1 + _hierlevel(item.parent)) - def _is_disabled(self): - # We need to use getattr as it will only be set the first time a log - # message is recorded on any given thread - return self.disabled or getattr(self._tls, 'in_progress', False) - def __repr__(self): level = getLevelName(self.getEffectiveLevel()) return '<%s %s (%s)>' % (self.__class__.__name__, self.name, level) diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index 84ca91ad4f7331..58e0381c4aa934 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -4163,89 +4163,6 @@ def __init__(self, *args, **kwargs): handler = logging.getHandlerByName('custom') self.assertEqual(handler.custom_kwargs, custom_kwargs) - # See gh-91555 and gh-90321 - @support.requires_subprocess() - def test_deadlock_in_queue(self): - queue = multiprocessing.Queue() - handler = logging.handlers.QueueHandler(queue) - logger = multiprocessing.get_logger() - level = logger.level - try: - logger.setLevel(logging.DEBUG) - logger.addHandler(handler) - logger.debug("deadlock") - finally: - logger.setLevel(level) - logger.removeHandler(handler) - - def test_recursion_in_custom_handler(self): - class BadHandler(logging.Handler): - def __init__(self): - super().__init__() - def emit(self, record): - logger.debug("recurse") - logger = logging.getLogger("test_recursion_in_custom_handler") - logger.addHandler(BadHandler()) - logger.setLevel(logging.DEBUG) - logger.debug("boom") - - @threading_helper.requires_working_threading() - def test_thread_supression_noninterference(self): - lock = threading.Lock() - logger = logging.getLogger("test_thread_supression_noninterference") - - # Block on the first call, allow others through - # - # NOTE: We need to bypass the base class's lock, otherwise that will - # block multiple calls to the same handler itself. - class BlockOnceHandler(TestHandler): - def __init__(self, barrier): - super().__init__(support.Matcher()) - self.barrier = barrier - - def createLock(self): - self.lock = None - - def handle(self, record): - self.emit(record) - - def emit(self, record): - if self.barrier: - barrier = self.barrier - self.barrier = None - barrier.wait() - with lock: - pass - super().emit(record) - logger.info("blow up if not supressed") - - barrier = threading.Barrier(2) - handler = BlockOnceHandler(barrier) - logger.addHandler(handler) - logger.setLevel(logging.DEBUG) - - t1 = threading.Thread(target=logger.debug, args=("1",)) - with lock: - - # Ensure first thread is blocked in the handler, hence supressing logging... - t1.start() - barrier.wait() - - # ...but the second thread should still be able to log... - t2 = threading.Thread(target=logger.debug, args=("2",)) - t2.start() - t2.join(timeout=3) - - self.assertEqual(len(handler.buffer), 1) - self.assertTrue(handler.matches(levelno=logging.DEBUG, message='2')) - - # The first thread should still be blocked here - self.assertTrue(t1.is_alive()) - - # Now the lock has been released the first thread should complete - t1.join() - self.assertEqual(len(handler.buffer), 2) - self.assertTrue(handler.matches(levelno=logging.DEBUG, message='1')) class ManagerTest(BaseTest): def test_manager_loggerclass(self): From 7463d33e17c0c8e79d72c32e67adc126240b267b Mon Sep 17 00:00:00 2001 From: Vinay Sajip Date: Wed, 25 Jun 2025 18:17:46 +0100 Subject: [PATCH 2/2] Revised NEWS aggregation for 3.13.4 and added a new NEWS entry relating to a reversion. --- Misc/NEWS.d/3.13.4.rst | 2 +- .../Library/2025-06-25-18-16-45.gh-issue-91555.3cj4M9.rst | 4 ++++ 2 files changed, 5 insertions(+), 1 deletion(-) create mode 100644 Misc/NEWS.d/next/Library/2025-06-25-18-16-45.gh-issue-91555.3cj4M9.rst diff --git a/Misc/NEWS.d/3.13.4.rst b/Misc/NEWS.d/3.13.4.rst index b947ad6775682e..de62e7f8009c3b 100644 --- a/Misc/NEWS.d/3.13.4.rst +++ b/Misc/NEWS.d/3.13.4.rst @@ -493,7 +493,7 @@ methods when getting the class signature for a class with .. section: Library Ignore log messages generated during handling of log messages, to avoid -deadlock or infinite recursion. +deadlock or infinite recursion. [NOTE: This change has since been reverted.] .. diff --git a/Misc/NEWS.d/next/Library/2025-06-25-18-16-45.gh-issue-91555.3cj4M9.rst b/Misc/NEWS.d/next/Library/2025-06-25-18-16-45.gh-issue-91555.3cj4M9.rst new file mode 100644 index 00000000000000..b0fc414bc790c9 --- /dev/null +++ b/Misc/NEWS.d/next/Library/2025-06-25-18-16-45.gh-issue-91555.3cj4M9.rst @@ -0,0 +1,4 @@ +An earlier change, which was introduced in 3.13.4, has been reverted. It +disabled logging for a logger during handling of log messages for that +logger. Since the reversion, the behaviour should be as it was before +3.13.4.