From 02c1d587083d04eec6a3a032e884d527f6bf19f2 Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Fri, 15 Sep 2023 18:07:13 +0100 Subject: [PATCH 01/26] Updated logging __init__.py to acquire its module lock using a context manager so that it is safer and easier to use. --- Lib/logging/__init__.py | 104 +++++++++++------------------------- Lib/logging/config.py | 30 ++++------- Lib/multiprocessing/util.py | 6 +-- Lib/test/test_logging.py | 15 ++---- 4 files changed, 45 insertions(+), 110 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 2d228e563094c8..521e0ac2b0869f 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -28,6 +28,7 @@ from types import GenericAlias from string import Template from string import Formatter as StrFormatter +from contextlib import contextmanager __all__ = ['BASIC_FORMAT', 'BufferingFormatter', 'CRITICAL', 'DEBUG', 'ERROR', @@ -159,12 +160,9 @@ def addLevelName(level, levelName): This is used when converting levels to text during message formatting. """ - _acquireLock() - try: #unlikely to cause an exception, but you never know... + with _acquireLock(): _levelToName[level] = levelName _nameToLevel[levelName] = level - finally: - _releaseLock() if hasattr(sys, "_getframe"): currentframe = lambda: sys._getframe(1) @@ -231,25 +229,20 @@ def _checkLevel(level): # _lock = threading.RLock() + +@contextmanager def _acquireLock(): """ Acquire the module-level lock for serializing access to shared data. - - This should be released with _releaseLock(). """ if _lock: try: _lock.acquire() + yield except BaseException: - _lock.release() raise - -def _releaseLock(): - """ - Release the module-level lock acquired by calling _acquireLock(). - """ - if _lock: - _lock.release() + finally: + _lock.release() # Prevent a held logging lock from blocking a child from logging. @@ -264,23 +257,20 @@ def _register_at_fork_reinit_lock(instance): _at_fork_reinit_lock_weakset = weakref.WeakSet() def _register_at_fork_reinit_lock(instance): - _acquireLock() - try: + with _acquireLock(): _at_fork_reinit_lock_weakset.add(instance) - finally: - _releaseLock() def _after_at_fork_child_reinit_locks(): for handler in _at_fork_reinit_lock_weakset: handler._at_fork_reinit() - # _acquireLock() was called in the parent before forking. + # _lock.acquire() was called in the parent before forking. # The lock is reinitialized to unlocked state. _lock._at_fork_reinit() - os.register_at_fork(before=_acquireLock, + os.register_at_fork(before=_lock.acquire, after_in_child=_after_at_fork_child_reinit_locks, - after_in_parent=_releaseLock) + after_in_parent=_lock.release) #--------------------------------------------------------------------------- @@ -883,25 +873,20 @@ def _removeHandlerRef(wr): # set to None. It can also be called from another thread. So we need to # pre-emptively grab the necessary globals and check if they're None, # to prevent race conditions and failures during interpreter shutdown. - acquire, release, handlers = _acquireLock, _releaseLock, _handlerList - if acquire and release and handlers: - acquire() - try: - handlers.remove(wr) - except ValueError: - pass - finally: - release() + acquire, handlers = _acquireLock, _handlerList + if acquire and handlers: + with acquire(): + try: + handlers.remove(wr) + except ValueError: + pass def _addHandlerRef(handler): """ Add a handler to the internal cleanup list using a weak reference. """ - _acquireLock() - try: + with _acquireLock(): _handlerList.append(weakref.ref(handler, _removeHandlerRef)) - finally: - _releaseLock() def getHandlerByName(name): @@ -946,15 +931,12 @@ def get_name(self): return self._name def set_name(self, name): - _acquireLock() - try: + with _acquireLock(): if self._name in _handlers: del _handlers[self._name] self._name = name if name: _handlers[name] = self - finally: - _releaseLock() name = property(get_name, set_name) @@ -1058,13 +1040,10 @@ def close(self): methods. """ #get the module data lock, as we're updating a shared structure. - _acquireLock() - try: #unlikely to raise an exception, but you never know... + with _acquireLock(): self._closed = True if self._name and self._name in _handlers: del _handlers[self._name] - finally: - _releaseLock() def handleError(self, record): """ @@ -1391,8 +1370,7 @@ def getLogger(self, name): rv = None if not isinstance(name, str): raise TypeError('A logger name must be a string') - _acquireLock() - try: + with _acquireLock(): if name in self.loggerDict: rv = self.loggerDict[name] if isinstance(rv, PlaceHolder): @@ -1407,8 +1385,6 @@ def getLogger(self, name): rv.manager = self self.loggerDict[name] = rv self._fixupParents(rv) - finally: - _releaseLock() return rv def setLoggerClass(self, klass): @@ -1471,12 +1447,11 @@ def _clear_cache(self): Called when level changes are made """ - _acquireLock() - for logger in self.loggerDict.values(): - if isinstance(logger, Logger): - logger._cache.clear() - self.root._cache.clear() - _releaseLock() + with _acquireLock(): + for logger in self.loggerDict.values(): + if isinstance(logger, Logger): + logger._cache.clear() + self.root._cache.clear() #--------------------------------------------------------------------------- # Logger classes and functions @@ -1701,23 +1676,17 @@ def addHandler(self, hdlr): """ Add the specified handler to this logger. """ - _acquireLock() - try: + with _acquireLock(): if not (hdlr in self.handlers): self.handlers.append(hdlr) - finally: - _releaseLock() def removeHandler(self, hdlr): """ Remove the specified handler from this logger. """ - _acquireLock() - try: + with _acquireLock(): if hdlr in self.handlers: self.handlers.remove(hdlr) - finally: - _releaseLock() def hasHandlers(self): """ @@ -1795,16 +1764,13 @@ def isEnabledFor(self, level): try: return self._cache[level] except KeyError: - _acquireLock() - try: + with _acquireLock(): if self.manager.disable >= level: is_enabled = self._cache[level] = False else: is_enabled = self._cache[level] = ( level >= self.getEffectiveLevel() ) - finally: - _releaseLock() return is_enabled def getChild(self, suffix): @@ -1834,16 +1800,13 @@ def _hierlevel(logger): return 1 + logger.name.count('.') d = self.manager.loggerDict - _acquireLock() - try: + with _acquireLock(): # exclude PlaceHolders - the last check is to ensure that lower-level # descendants aren't returned - if there are placeholders, a logger's # parent field might point to a grandparent or ancestor thereof. return set(item for item in d.values() if isinstance(item, Logger) and item.parent is self and _hierlevel(item) == 1 + _hierlevel(item.parent)) - finally: - _releaseLock() def __repr__(self): level = getLevelName(self.getEffectiveLevel()) @@ -2102,8 +2065,7 @@ def basicConfig(**kwargs): """ # Add thread safety in case someone mistakenly calls # basicConfig() from multiple threads - _acquireLock() - try: + with _acquireLock(): force = kwargs.pop('force', False) encoding = kwargs.pop('encoding', None) errors = kwargs.pop('errors', 'backslashreplace') @@ -2152,8 +2114,6 @@ def basicConfig(**kwargs): if kwargs: keys = ', '.join(kwargs.keys()) raise ValueError('Unrecognised argument(s): %s' % keys) - finally: - _releaseLock() #--------------------------------------------------------------------------- # Utility functions at module level. diff --git a/Lib/logging/config.py b/Lib/logging/config.py index 41283f4d627267..bf10580c45e262 100644 --- a/Lib/logging/config.py +++ b/Lib/logging/config.py @@ -83,15 +83,12 @@ def fileConfig(fname, defaults=None, disable_existing_loggers=True, encoding=Non formatters = _create_formatters(cp) # critical section - logging._acquireLock() - try: + with logging._acquireLock(): _clearExistingHandlers() # Handlers add themselves to logging._handlers handlers = _install_handlers(cp, formatters) _install_loggers(cp, handlers, disable_existing_loggers) - finally: - logging._releaseLock() def _resolve(name): @@ -516,8 +513,7 @@ def configure(self): raise ValueError("Unsupported version: %s" % config['version']) incremental = config.pop('incremental', False) EMPTY_DICT = {} - logging._acquireLock() - try: + with logging._acquireLock(): if incremental: handlers = config.get('handlers', EMPTY_DICT) for name in handlers: @@ -661,8 +657,6 @@ def configure(self): except Exception as e: raise ValueError('Unable to configure root ' 'logger') from e - finally: - logging._releaseLock() def configure_formatter(self, config): """Configure a formatter from a dictionary.""" @@ -988,9 +982,8 @@ class ConfigSocketReceiver(ThreadingTCPServer): def __init__(self, host='localhost', port=DEFAULT_LOGGING_CONFIG_PORT, handler=None, ready=None, verify=None): ThreadingTCPServer.__init__(self, (host, port), handler) - logging._acquireLock() - self.abort = 0 - logging._releaseLock() + with logging._acquireLock(): + self.abort = 0 self.timeout = 1 self.ready = ready self.verify = verify @@ -1004,9 +997,8 @@ def serve_until_stopped(self): self.timeout) if rd: self.handle_request() - logging._acquireLock() - abort = self.abort - logging._releaseLock() + with logging._acquireLock(): + abort = self.abort self.server_close() class Server(threading.Thread): @@ -1027,9 +1019,8 @@ def run(self): self.port = server.server_address[1] self.ready.set() global _listener - logging._acquireLock() - _listener = server - logging._releaseLock() + with logging._acquireLock(): + _listener = server server.serve_until_stopped() return Server(ConfigSocketReceiver, ConfigStreamHandler, port, verify) @@ -1039,10 +1030,7 @@ def stopListening(): Stop the listening server which was created with a call to listen(). """ global _listener - logging._acquireLock() - try: + with logging._acquireLock(): if _listener: _listener.abort = 1 _listener = None - finally: - logging._releaseLock() diff --git a/Lib/multiprocessing/util.py b/Lib/multiprocessing/util.py index 6ee0d33e88a060..cedb1580e163e2 100644 --- a/Lib/multiprocessing/util.py +++ b/Lib/multiprocessing/util.py @@ -64,8 +64,7 @@ def get_logger(): global _logger import logging - logging._acquireLock() - try: + with logging._acquireLock(): if not _logger: _logger = logging.getLogger(LOGGER_NAME) @@ -79,9 +78,6 @@ def get_logger(): atexit._exithandlers.remove((_exit_function, (), {})) atexit._exithandlers.append((_exit_function, (), {})) - finally: - logging._releaseLock() - return _logger def log_to_stderr(level=None): diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index 2305e5162f901e..a08ae5dfd3f02a 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -90,8 +90,7 @@ def setUp(self): self._threading_key = threading_helper.threading_setup() logger_dict = logging.getLogger().manager.loggerDict - logging._acquireLock() - try: + with logging._acquireLock(): self.saved_handlers = logging._handlers.copy() self.saved_handler_list = logging._handlerList[:] self.saved_loggers = saved_loggers = logger_dict.copy() @@ -101,8 +100,6 @@ def setUp(self): for name in saved_loggers: logger_states[name] = getattr(saved_loggers[name], 'disabled', None) - finally: - logging._releaseLock() # Set two unused loggers self.logger1 = logging.getLogger("\xab\xd7\xbb") @@ -136,8 +133,7 @@ def tearDown(self): self.root_logger.removeHandler(h) h.close() self.root_logger.setLevel(self.original_logging_level) - logging._acquireLock() - try: + with logging._acquireLock(): logging._levelToName.clear() logging._levelToName.update(self.saved_level_to_name) logging._nameToLevel.clear() @@ -154,8 +150,6 @@ def tearDown(self): for name in self.logger_states: if logger_states[name] is not None: self.saved_loggers[name].disabled = logger_states[name] - finally: - logging._releaseLock() self.doCleanups() threading_helper.threading_cleanup(*self._threading_key) @@ -759,8 +753,7 @@ def emit(self, record): fork_happened__release_locks_and_end_thread = threading.Event() def lock_holder_thread_fn(): - logging._acquireLock() - try: + with logging._acquireLock(): refed_h.acquire() try: # Tell the main thread to do the fork. @@ -780,8 +773,6 @@ def lock_holder_thread_fn(): fork_happened__release_locks_and_end_thread.wait(0.5) finally: refed_h.release() - finally: - logging._releaseLock() lock_holder_thread = threading.Thread( target=lock_holder_thread_fn, From f319ab0a92cd98f35d215d4dfde236ba6f312a06 Mon Sep 17 00:00:00 2001 From: "blurb-it[bot]" <43283697+blurb-it[bot]@users.noreply.github.com> Date: Fri, 15 Sep 2023 17:12:54 +0000 Subject: [PATCH 02/26] =?UTF-8?q?=F0=9F=93=9C=F0=9F=A4=96=20Added=20by=20b?= =?UTF-8?q?lurb=5Fit.?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst | 1 + 1 file changed, 1 insertion(+) create mode 100644 Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst diff --git a/Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst b/Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst new file mode 100644 index 00000000000000..aa9512590a9154 --- /dev/null +++ b/Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst @@ -0,0 +1 @@ +Updated logging library to acquire its module lock using a context manager so that it is safer and easier to use. From fd635b2840042c90bac375156a4b05a07181bc9e Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Fri, 15 Sep 2023 18:59:44 +0100 Subject: [PATCH 03/26] Updated to leave the existing API alone and added a new method _acquireModuleLock --- Lib/logging/__init__.py | 57 ++++++++++++++++++++++++------------- Lib/logging/config.py | 12 ++++---- Lib/multiprocessing/util.py | 2 +- Lib/test/test_logging.py | 6 ++-- 4 files changed, 48 insertions(+), 29 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 521e0ac2b0869f..eead3c58dd4d35 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -160,7 +160,7 @@ def addLevelName(level, levelName): This is used when converting levels to text during message formatting. """ - with _acquireLock(): + with _acquireModuleLock(): _levelToName[level] = levelName _nameToLevel[levelName] = level @@ -230,19 +230,38 @@ def _checkLevel(level): _lock = threading.RLock() -@contextmanager def _acquireLock(): """ Acquire the module-level lock for serializing access to shared data. + + This should be released with _releaseLock(). """ if _lock: try: _lock.acquire() - yield except BaseException: - raise - finally: _lock.release() + raise + + +def _releaseLock(): + """ + Release the module-level lock acquired by calling _acquireLock(). + """ + if _lock: + _lock.release() + + +@contextmanager +def _acquireModuleLock(): + """ + Acquire the module-level lock using a context manager for serializing access to shared data. + """ + try: + _acquireLock() + yield + finally: + _releaseLock() # Prevent a held logging lock from blocking a child from logging. @@ -257,20 +276,20 @@ def _register_at_fork_reinit_lock(instance): _at_fork_reinit_lock_weakset = weakref.WeakSet() def _register_at_fork_reinit_lock(instance): - with _acquireLock(): + with _acquireModuleLock(): _at_fork_reinit_lock_weakset.add(instance) def _after_at_fork_child_reinit_locks(): for handler in _at_fork_reinit_lock_weakset: handler._at_fork_reinit() - # _lock.acquire() was called in the parent before forking. + # _acquireLock() was called in the parent before forking. # The lock is reinitialized to unlocked state. _lock._at_fork_reinit() - os.register_at_fork(before=_lock.acquire, + os.register_at_fork(before=_acquireLock, after_in_child=_after_at_fork_child_reinit_locks, - after_in_parent=_lock.release) + after_in_parent=_releaseLock) #--------------------------------------------------------------------------- @@ -885,7 +904,7 @@ def _addHandlerRef(handler): """ Add a handler to the internal cleanup list using a weak reference. """ - with _acquireLock(): + with _acquireModuleLock(): _handlerList.append(weakref.ref(handler, _removeHandlerRef)) @@ -931,7 +950,7 @@ def get_name(self): return self._name def set_name(self, name): - with _acquireLock(): + with _acquireModuleLock(): if self._name in _handlers: del _handlers[self._name] self._name = name @@ -1040,7 +1059,7 @@ def close(self): methods. """ #get the module data lock, as we're updating a shared structure. - with _acquireLock(): + with _acquireModuleLock(): self._closed = True if self._name and self._name in _handlers: del _handlers[self._name] @@ -1370,7 +1389,7 @@ def getLogger(self, name): rv = None if not isinstance(name, str): raise TypeError('A logger name must be a string') - with _acquireLock(): + with _acquireModuleLock(): if name in self.loggerDict: rv = self.loggerDict[name] if isinstance(rv, PlaceHolder): @@ -1447,7 +1466,7 @@ def _clear_cache(self): Called when level changes are made """ - with _acquireLock(): + with _acquireModuleLock(): for logger in self.loggerDict.values(): if isinstance(logger, Logger): logger._cache.clear() @@ -1676,7 +1695,7 @@ def addHandler(self, hdlr): """ Add the specified handler to this logger. """ - with _acquireLock(): + with _acquireModuleLock(): if not (hdlr in self.handlers): self.handlers.append(hdlr) @@ -1684,7 +1703,7 @@ def removeHandler(self, hdlr): """ Remove the specified handler from this logger. """ - with _acquireLock(): + with _acquireModuleLock(): if hdlr in self.handlers: self.handlers.remove(hdlr) @@ -1764,7 +1783,7 @@ def isEnabledFor(self, level): try: return self._cache[level] except KeyError: - with _acquireLock(): + with _acquireModuleLock(): if self.manager.disable >= level: is_enabled = self._cache[level] = False else: @@ -1800,7 +1819,7 @@ def _hierlevel(logger): return 1 + logger.name.count('.') d = self.manager.loggerDict - with _acquireLock(): + with _acquireModuleLock(): # exclude PlaceHolders - the last check is to ensure that lower-level # descendants aren't returned - if there are placeholders, a logger's # parent field might point to a grandparent or ancestor thereof. @@ -2065,7 +2084,7 @@ def basicConfig(**kwargs): """ # Add thread safety in case someone mistakenly calls # basicConfig() from multiple threads - with _acquireLock(): + with _acquireModuleLock(): force = kwargs.pop('force', False) encoding = kwargs.pop('encoding', None) errors = kwargs.pop('errors', 'backslashreplace') diff --git a/Lib/logging/config.py b/Lib/logging/config.py index bf10580c45e262..75b027d84904a2 100644 --- a/Lib/logging/config.py +++ b/Lib/logging/config.py @@ -83,7 +83,7 @@ def fileConfig(fname, defaults=None, disable_existing_loggers=True, encoding=Non formatters = _create_formatters(cp) # critical section - with logging._acquireLock(): + with logging._acquireModuleLock(): _clearExistingHandlers() # Handlers add themselves to logging._handlers @@ -513,7 +513,7 @@ def configure(self): raise ValueError("Unsupported version: %s" % config['version']) incremental = config.pop('incremental', False) EMPTY_DICT = {} - with logging._acquireLock(): + with logging._acquireModuleLock(): if incremental: handlers = config.get('handlers', EMPTY_DICT) for name in handlers: @@ -982,7 +982,7 @@ class ConfigSocketReceiver(ThreadingTCPServer): def __init__(self, host='localhost', port=DEFAULT_LOGGING_CONFIG_PORT, handler=None, ready=None, verify=None): ThreadingTCPServer.__init__(self, (host, port), handler) - with logging._acquireLock(): + with logging._acquireModuleLock(): self.abort = 0 self.timeout = 1 self.ready = ready @@ -997,7 +997,7 @@ def serve_until_stopped(self): self.timeout) if rd: self.handle_request() - with logging._acquireLock(): + with logging._acquireModuleLock(): abort = self.abort self.server_close() @@ -1019,7 +1019,7 @@ def run(self): self.port = server.server_address[1] self.ready.set() global _listener - with logging._acquireLock(): + with logging._acquireModuleLock(): _listener = server server.serve_until_stopped() @@ -1030,7 +1030,7 @@ def stopListening(): Stop the listening server which was created with a call to listen(). """ global _listener - with logging._acquireLock(): + with logging._acquireModuleLock(): if _listener: _listener.abort = 1 _listener = None diff --git a/Lib/multiprocessing/util.py b/Lib/multiprocessing/util.py index cedb1580e163e2..487997c840b8f1 100644 --- a/Lib/multiprocessing/util.py +++ b/Lib/multiprocessing/util.py @@ -64,7 +64,7 @@ def get_logger(): global _logger import logging - with logging._acquireLock(): + with logging._acquireModuleLock(): if not _logger: _logger = logging.getLogger(LOGGER_NAME) diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index a08ae5dfd3f02a..9a06f789ee0e71 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -90,7 +90,7 @@ def setUp(self): self._threading_key = threading_helper.threading_setup() logger_dict = logging.getLogger().manager.loggerDict - with logging._acquireLock(): + with logging._acquireModuleLock(): self.saved_handlers = logging._handlers.copy() self.saved_handler_list = logging._handlerList[:] self.saved_loggers = saved_loggers = logger_dict.copy() @@ -133,7 +133,7 @@ def tearDown(self): self.root_logger.removeHandler(h) h.close() self.root_logger.setLevel(self.original_logging_level) - with logging._acquireLock(): + with logging._acquireModuleLock(): logging._levelToName.clear() logging._levelToName.update(self.saved_level_to_name) logging._nameToLevel.clear() @@ -753,7 +753,7 @@ def emit(self, record): fork_happened__release_locks_and_end_thread = threading.Event() def lock_holder_thread_fn(): - with logging._acquireLock(): + with logging._acquireModuleLock(): refed_h.acquire() try: # Tell the main thread to do the fork. From e5ad43b7fee87a0b1136dd6925d07aade55f7151 Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Fri, 15 Sep 2023 19:03:27 +0100 Subject: [PATCH 04/26] Updated acquireLock usages to acquireModuleLock --- Lib/logging/__init__.py | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index eead3c58dd4d35..116102f3f49bfe 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -260,6 +260,8 @@ def _acquireModuleLock(): try: _acquireLock() yield + except BaseException: + raise finally: _releaseLock() @@ -892,7 +894,7 @@ def _removeHandlerRef(wr): # set to None. It can also be called from another thread. So we need to # pre-emptively grab the necessary globals and check if they're None, # to prevent race conditions and failures during interpreter shutdown. - acquire, handlers = _acquireLock, _handlerList + acquire, handlers = _acquireModuleLock, _handlerList if acquire and handlers: with acquire(): try: From 0a2bb5f509423641f8815fa1db94354fee0fdfce Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Fri, 15 Sep 2023 19:05:19 +0100 Subject: [PATCH 05/26] Removed unnecessary changes --- Lib/logging/__init__.py | 2 -- 1 file changed, 2 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 116102f3f49bfe..d579c125ae4124 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -229,7 +229,6 @@ def _checkLevel(level): # _lock = threading.RLock() - def _acquireLock(): """ Acquire the module-level lock for serializing access to shared data. @@ -243,7 +242,6 @@ def _acquireLock(): _lock.release() raise - def _releaseLock(): """ Release the module-level lock acquired by calling _acquireLock(). From 4f2d1c156529663e7d87a9320c393a9dcc1bd6c9 Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Sat, 16 Sep 2023 08:10:18 +0100 Subject: [PATCH 06/26] Updated _acquireModuleLock() to _get_lock() which gets the lock's context manager, or a null context. --- Lib/logging/__init__.py | 46 ++++++++++++++++++------------------- Lib/logging/config.py | 12 +++++----- Lib/multiprocessing/util.py | 2 +- Lib/test/test_logging.py | 6 ++--- 4 files changed, 32 insertions(+), 34 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index d579c125ae4124..2ba49d0921c65f 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -25,10 +25,12 @@ import sys, os, time, io, re, traceback, warnings, weakref, collections.abc +import contextlib from types import GenericAlias from string import Template from string import Formatter as StrFormatter -from contextlib import contextmanager +from contextlib import nullcontext +from typing import ContextManager __all__ = ['BASIC_FORMAT', 'BufferingFormatter', 'CRITICAL', 'DEBUG', 'ERROR', @@ -160,7 +162,7 @@ def addLevelName(level, levelName): This is used when converting levels to text during message formatting. """ - with _acquireModuleLock(): + with _get_lock(): _levelToName[level] = levelName _nameToLevel[levelName] = level @@ -250,18 +252,14 @@ def _releaseLock(): _lock.release() -@contextmanager -def _acquireModuleLock(): +def _get_lock() -> ContextManager: """ - Acquire the module-level lock using a context manager for serializing access to shared data. + Get the module-level lock using a context manager for serializing access to shared data and safely releasing the + lock once finished. """ - try: - _acquireLock() - yield - except BaseException: - raise - finally: - _releaseLock() + if _lock: + return _lock + return nullcontext(enter_result=False) # threading.RLock returns True from __enter__, so return False here # Prevent a held logging lock from blocking a child from logging. @@ -276,7 +274,7 @@ def _register_at_fork_reinit_lock(instance): _at_fork_reinit_lock_weakset = weakref.WeakSet() def _register_at_fork_reinit_lock(instance): - with _acquireModuleLock(): + with _get_lock(): _at_fork_reinit_lock_weakset.add(instance) def _after_at_fork_child_reinit_locks(): @@ -892,7 +890,7 @@ def _removeHandlerRef(wr): # set to None. It can also be called from another thread. So we need to # pre-emptively grab the necessary globals and check if they're None, # to prevent race conditions and failures during interpreter shutdown. - acquire, handlers = _acquireModuleLock, _handlerList + acquire, handlers = _get_lock, _handlerList if acquire and handlers: with acquire(): try: @@ -904,7 +902,7 @@ def _addHandlerRef(handler): """ Add a handler to the internal cleanup list using a weak reference. """ - with _acquireModuleLock(): + with _get_lock(): _handlerList.append(weakref.ref(handler, _removeHandlerRef)) @@ -950,7 +948,7 @@ def get_name(self): return self._name def set_name(self, name): - with _acquireModuleLock(): + with _get_lock(): if self._name in _handlers: del _handlers[self._name] self._name = name @@ -1059,7 +1057,7 @@ def close(self): methods. """ #get the module data lock, as we're updating a shared structure. - with _acquireModuleLock(): + with _get_lock(): self._closed = True if self._name and self._name in _handlers: del _handlers[self._name] @@ -1389,7 +1387,7 @@ def getLogger(self, name): rv = None if not isinstance(name, str): raise TypeError('A logger name must be a string') - with _acquireModuleLock(): + with _get_lock(): if name in self.loggerDict: rv = self.loggerDict[name] if isinstance(rv, PlaceHolder): @@ -1466,7 +1464,7 @@ def _clear_cache(self): Called when level changes are made """ - with _acquireModuleLock(): + with _get_lock(): for logger in self.loggerDict.values(): if isinstance(logger, Logger): logger._cache.clear() @@ -1695,7 +1693,7 @@ def addHandler(self, hdlr): """ Add the specified handler to this logger. """ - with _acquireModuleLock(): + with _get_lock(): if not (hdlr in self.handlers): self.handlers.append(hdlr) @@ -1703,7 +1701,7 @@ def removeHandler(self, hdlr): """ Remove the specified handler from this logger. """ - with _acquireModuleLock(): + with _get_lock(): if hdlr in self.handlers: self.handlers.remove(hdlr) @@ -1783,7 +1781,7 @@ def isEnabledFor(self, level): try: return self._cache[level] except KeyError: - with _acquireModuleLock(): + with _get_lock(): if self.manager.disable >= level: is_enabled = self._cache[level] = False else: @@ -1819,7 +1817,7 @@ def _hierlevel(logger): return 1 + logger.name.count('.') d = self.manager.loggerDict - with _acquireModuleLock(): + with _get_lock(): # exclude PlaceHolders - the last check is to ensure that lower-level # descendants aren't returned - if there are placeholders, a logger's # parent field might point to a grandparent or ancestor thereof. @@ -2084,7 +2082,7 @@ def basicConfig(**kwargs): """ # Add thread safety in case someone mistakenly calls # basicConfig() from multiple threads - with _acquireModuleLock(): + with _get_lock(): force = kwargs.pop('force', False) encoding = kwargs.pop('encoding', None) errors = kwargs.pop('errors', 'backslashreplace') diff --git a/Lib/logging/config.py b/Lib/logging/config.py index 75b027d84904a2..78216a608044c4 100644 --- a/Lib/logging/config.py +++ b/Lib/logging/config.py @@ -83,7 +83,7 @@ def fileConfig(fname, defaults=None, disable_existing_loggers=True, encoding=Non formatters = _create_formatters(cp) # critical section - with logging._acquireModuleLock(): + with logging._get_lock(): _clearExistingHandlers() # Handlers add themselves to logging._handlers @@ -513,7 +513,7 @@ def configure(self): raise ValueError("Unsupported version: %s" % config['version']) incremental = config.pop('incremental', False) EMPTY_DICT = {} - with logging._acquireModuleLock(): + with logging._get_lock(): if incremental: handlers = config.get('handlers', EMPTY_DICT) for name in handlers: @@ -982,7 +982,7 @@ class ConfigSocketReceiver(ThreadingTCPServer): def __init__(self, host='localhost', port=DEFAULT_LOGGING_CONFIG_PORT, handler=None, ready=None, verify=None): ThreadingTCPServer.__init__(self, (host, port), handler) - with logging._acquireModuleLock(): + with logging._get_lock(): self.abort = 0 self.timeout = 1 self.ready = ready @@ -997,7 +997,7 @@ def serve_until_stopped(self): self.timeout) if rd: self.handle_request() - with logging._acquireModuleLock(): + with logging._get_lock(): abort = self.abort self.server_close() @@ -1019,7 +1019,7 @@ def run(self): self.port = server.server_address[1] self.ready.set() global _listener - with logging._acquireModuleLock(): + with logging._get_lock(): _listener = server server.serve_until_stopped() @@ -1030,7 +1030,7 @@ def stopListening(): Stop the listening server which was created with a call to listen(). """ global _listener - with logging._acquireModuleLock(): + with logging._get_lock(): if _listener: _listener.abort = 1 _listener = None diff --git a/Lib/multiprocessing/util.py b/Lib/multiprocessing/util.py index 487997c840b8f1..947d5da71149e2 100644 --- a/Lib/multiprocessing/util.py +++ b/Lib/multiprocessing/util.py @@ -64,7 +64,7 @@ def get_logger(): global _logger import logging - with logging._acquireModuleLock(): + with logging._get_lock(): if not _logger: _logger = logging.getLogger(LOGGER_NAME) diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index 9a06f789ee0e71..2bac4c72d399bd 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -90,7 +90,7 @@ def setUp(self): self._threading_key = threading_helper.threading_setup() logger_dict = logging.getLogger().manager.loggerDict - with logging._acquireModuleLock(): + with logging._get_lock(): self.saved_handlers = logging._handlers.copy() self.saved_handler_list = logging._handlerList[:] self.saved_loggers = saved_loggers = logger_dict.copy() @@ -133,7 +133,7 @@ def tearDown(self): self.root_logger.removeHandler(h) h.close() self.root_logger.setLevel(self.original_logging_level) - with logging._acquireModuleLock(): + with logging._get_lock(): logging._levelToName.clear() logging._levelToName.update(self.saved_level_to_name) logging._nameToLevel.clear() @@ -753,7 +753,7 @@ def emit(self, record): fork_happened__release_locks_and_end_thread = threading.Event() def lock_holder_thread_fn(): - with logging._acquireModuleLock(): + with logging._get_lock(): refed_h.acquire() try: # Tell the main thread to do the fork. From 892a5cb4f8d76a4d8080841b95b8849c9ffe2c4c Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Sat, 16 Sep 2023 08:13:22 +0100 Subject: [PATCH 07/26] Updated comments --- Lib/logging/__init__.py | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 2ba49d0921c65f..16de1d551fdf98 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -254,12 +254,14 @@ def _releaseLock(): def _get_lock() -> ContextManager: """ - Get the module-level lock using a context manager for serializing access to shared data and safely releasing the - lock once finished. + Get the module-level lock using a context manager for serializing access to + shared data and safely releasing the lock once finished. """ if _lock: return _lock - return nullcontext(enter_result=False) # threading.RLock returns True from __enter__, so return False here + + # _lock returns True from __enter__, so return False from nullcontext. + return nullcontext(enter_result=False) # Prevent a held logging lock from blocking a child from logging. From cf7a2e6d11306d482619d463db92268e384e00b2 Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Sat, 16 Sep 2023 08:15:11 +0100 Subject: [PATCH 08/26] Updated blurb --- .../next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst b/Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst index aa9512590a9154..fcdf7cb267d500 100644 --- a/Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst +++ b/Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst @@ -1 +1 @@ -Updated logging library to acquire its module lock using a context manager so that it is safer and easier to use. +Updated logging library with function "_get_lock" to acquire its module lock using a context manager so that it is safer and easier to use. From 2760cc518f3d3df1aaf62f4ddb8f5ea7d89e4d38 Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Sat, 16 Sep 2023 08:15:56 +0100 Subject: [PATCH 09/26] Removed unused import --- Lib/logging/__init__.py | 1 - 1 file changed, 1 deletion(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 16de1d551fdf98..5f397aaa18332a 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -25,7 +25,6 @@ import sys, os, time, io, re, traceback, warnings, weakref, collections.abc -import contextlib from types import GenericAlias from string import Template from string import Formatter as StrFormatter From 7f3b28aa510669a2e695cd0cfeebb1c421d87c65 Mon Sep 17 00:00:00 2001 From: Dale Collison <92315623+dcollison@users.noreply.github.com> Date: Thu, 21 Sep 2023 09:11:31 +0100 Subject: [PATCH 10/26] Updated __init__.py to remove _get_lock() and "if _lock" checks since bool(_lock) always returns true --- Lib/logging/__init__.py | 52 ++++++++++++++--------------------------- 1 file changed, 18 insertions(+), 34 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 5f397aaa18332a..01b6bded000370 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -28,8 +28,6 @@ from types import GenericAlias from string import Template from string import Formatter as StrFormatter -from contextlib import nullcontext -from typing import ContextManager __all__ = ['BASIC_FORMAT', 'BufferingFormatter', 'CRITICAL', 'DEBUG', 'ERROR', @@ -161,7 +159,7 @@ def addLevelName(level, levelName): This is used when converting levels to text during message formatting. """ - with _get_lock(): + with _lock: _levelToName[level] = levelName _nameToLevel[levelName] = level @@ -236,31 +234,17 @@ def _acquireLock(): This should be released with _releaseLock(). """ - if _lock: - try: - _lock.acquire() - except BaseException: - _lock.release() - raise + try: + _lock.acquire() + except BaseException: + _lock.release() + raise def _releaseLock(): """ Release the module-level lock acquired by calling _acquireLock(). """ - if _lock: - _lock.release() - - -def _get_lock() -> ContextManager: - """ - Get the module-level lock using a context manager for serializing access to - shared data and safely releasing the lock once finished. - """ - if _lock: - return _lock - - # _lock returns True from __enter__, so return False from nullcontext. - return nullcontext(enter_result=False) + _lock.release() # Prevent a held logging lock from blocking a child from logging. @@ -275,7 +259,7 @@ def _register_at_fork_reinit_lock(instance): _at_fork_reinit_lock_weakset = weakref.WeakSet() def _register_at_fork_reinit_lock(instance): - with _get_lock(): + with _lock: _at_fork_reinit_lock_weakset.add(instance) def _after_at_fork_child_reinit_locks(): @@ -903,7 +887,7 @@ def _addHandlerRef(handler): """ Add a handler to the internal cleanup list using a weak reference. """ - with _get_lock(): + with _lock: _handlerList.append(weakref.ref(handler, _removeHandlerRef)) @@ -949,7 +933,7 @@ def get_name(self): return self._name def set_name(self, name): - with _get_lock(): + with _lock: if self._name in _handlers: del _handlers[self._name] self._name = name @@ -1058,7 +1042,7 @@ def close(self): methods. """ #get the module data lock, as we're updating a shared structure. - with _get_lock(): + with _lock: self._closed = True if self._name and self._name in _handlers: del _handlers[self._name] @@ -1388,7 +1372,7 @@ def getLogger(self, name): rv = None if not isinstance(name, str): raise TypeError('A logger name must be a string') - with _get_lock(): + with _lock: if name in self.loggerDict: rv = self.loggerDict[name] if isinstance(rv, PlaceHolder): @@ -1465,7 +1449,7 @@ def _clear_cache(self): Called when level changes are made """ - with _get_lock(): + with _lock: for logger in self.loggerDict.values(): if isinstance(logger, Logger): logger._cache.clear() @@ -1694,7 +1678,7 @@ def addHandler(self, hdlr): """ Add the specified handler to this logger. """ - with _get_lock(): + with _lock: if not (hdlr in self.handlers): self.handlers.append(hdlr) @@ -1702,7 +1686,7 @@ def removeHandler(self, hdlr): """ Remove the specified handler from this logger. """ - with _get_lock(): + with _lock: if hdlr in self.handlers: self.handlers.remove(hdlr) @@ -1782,7 +1766,7 @@ def isEnabledFor(self, level): try: return self._cache[level] except KeyError: - with _get_lock(): + with _lock: if self.manager.disable >= level: is_enabled = self._cache[level] = False else: @@ -1818,7 +1802,7 @@ def _hierlevel(logger): return 1 + logger.name.count('.') d = self.manager.loggerDict - with _get_lock(): + with _lock: # exclude PlaceHolders - the last check is to ensure that lower-level # descendants aren't returned - if there are placeholders, a logger's # parent field might point to a grandparent or ancestor thereof. @@ -2083,7 +2067,7 @@ def basicConfig(**kwargs): """ # Add thread safety in case someone mistakenly calls # basicConfig() from multiple threads - with _get_lock(): + with _lock: force = kwargs.pop('force', False) encoding = kwargs.pop('encoding', None) errors = kwargs.pop('errors', 'backslashreplace') From 09c9133f1bedfccee2c97456f52663c26653fb9b Mon Sep 17 00:00:00 2001 From: Dale Collison <92315623+dcollison@users.noreply.github.com> Date: Thu, 21 Sep 2023 09:14:05 +0100 Subject: [PATCH 11/26] Changed "with logging._get_lock():" to "with logging._lock:" --- Lib/logging/config.py | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/Lib/logging/config.py b/Lib/logging/config.py index 78216a608044c4..951bba73913cb3 100644 --- a/Lib/logging/config.py +++ b/Lib/logging/config.py @@ -83,7 +83,7 @@ def fileConfig(fname, defaults=None, disable_existing_loggers=True, encoding=Non formatters = _create_formatters(cp) # critical section - with logging._get_lock(): + with logging._lock: _clearExistingHandlers() # Handlers add themselves to logging._handlers @@ -513,7 +513,7 @@ def configure(self): raise ValueError("Unsupported version: %s" % config['version']) incremental = config.pop('incremental', False) EMPTY_DICT = {} - with logging._get_lock(): + with logging._lock: if incremental: handlers = config.get('handlers', EMPTY_DICT) for name in handlers: @@ -982,7 +982,7 @@ class ConfigSocketReceiver(ThreadingTCPServer): def __init__(self, host='localhost', port=DEFAULT_LOGGING_CONFIG_PORT, handler=None, ready=None, verify=None): ThreadingTCPServer.__init__(self, (host, port), handler) - with logging._get_lock(): + with logging._lock: self.abort = 0 self.timeout = 1 self.ready = ready @@ -997,7 +997,7 @@ def serve_until_stopped(self): self.timeout) if rd: self.handle_request() - with logging._get_lock(): + with logging._lock: abort = self.abort self.server_close() @@ -1019,7 +1019,7 @@ def run(self): self.port = server.server_address[1] self.ready.set() global _listener - with logging._get_lock(): + with logging._lock: _listener = server server.serve_until_stopped() @@ -1030,7 +1030,7 @@ def stopListening(): Stop the listening server which was created with a call to listen(). """ global _listener - with logging._get_lock(): + with logging._lock: if _listener: _listener.abort = 1 _listener = None From 9f3607e25fd77c13764abb12892a2dd303b3b2c8 Mon Sep 17 00:00:00 2001 From: Dale Collison <92315623+dcollison@users.noreply.github.com> Date: Thu, 21 Sep 2023 09:15:02 +0100 Subject: [PATCH 12/26] Changed "with logging._get_lock()" to "with logging._lock:" --- Lib/multiprocessing/util.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Lib/multiprocessing/util.py b/Lib/multiprocessing/util.py index 947d5da71149e2..28c77df1c32ea8 100644 --- a/Lib/multiprocessing/util.py +++ b/Lib/multiprocessing/util.py @@ -64,7 +64,7 @@ def get_logger(): global _logger import logging - with logging._get_lock(): + with logging._lock: if not _logger: _logger = logging.getLogger(LOGGER_NAME) From b15e4bf9409dfd0d9f363b9e6f301cbac2cbbb72 Mon Sep 17 00:00:00 2001 From: Dale Collison <92315623+dcollison@users.noreply.github.com> Date: Thu, 21 Sep 2023 09:16:19 +0100 Subject: [PATCH 13/26] Changed "with logging._get_lock():" to "with logging._lock:" --- Lib/test/test_logging.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index e33e91c8ea12bc..94a40555695921 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -90,7 +90,7 @@ def setUp(self): self._threading_key = threading_helper.threading_setup() logger_dict = logging.getLogger().manager.loggerDict - with logging._get_lock(): + with logging._lock: self.saved_handlers = logging._handlers.copy() self.saved_handler_list = logging._handlerList[:] self.saved_loggers = saved_loggers = logger_dict.copy() @@ -133,7 +133,7 @@ def tearDown(self): self.root_logger.removeHandler(h) h.close() self.root_logger.setLevel(self.original_logging_level) - with logging._get_lock(): + with logging._lock: logging._levelToName.clear() logging._levelToName.update(self.saved_level_to_name) logging._nameToLevel.clear() @@ -753,7 +753,7 @@ def emit(self, record): fork_happened__release_locks_and_end_thread = threading.Event() def lock_holder_thread_fn(): - with logging._get_lock(): + with logging._lock: refed_h.acquire() try: # Tell the main thread to do the fork. From a0c50bfe675e990e222a0ae498edb79da2c8b039 Mon Sep 17 00:00:00 2001 From: Dale Collison <92315623+dcollison@users.noreply.github.com> Date: Thu, 21 Sep 2023 09:18:09 +0100 Subject: [PATCH 14/26] Update __init__.py --- Lib/logging/__init__.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 01b6bded000370..98f52bccc2408d 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -875,9 +875,9 @@ def _removeHandlerRef(wr): # set to None. It can also be called from another thread. So we need to # pre-emptively grab the necessary globals and check if they're None, # to prevent race conditions and failures during interpreter shutdown. - acquire, handlers = _get_lock, _handlerList - if acquire and handlers: - with acquire(): + handlers = _handlerList + if handlers: + with _lock: try: handlers.remove(wr) except ValueError: From 9d0675bcc734597ee21a132a133b814f2932965a Mon Sep 17 00:00:00 2001 From: Dale Collison <92315623+dcollison@users.noreply.github.com> Date: Thu, 21 Sep 2023 09:18:56 +0100 Subject: [PATCH 15/26] Update Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst Co-authored-by: Adam Turner <9087854+AA-Turner@users.noreply.github.com> --- .../next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst b/Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst index fcdf7cb267d500..640f6b7f17b359 100644 --- a/Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst +++ b/Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst @@ -1 +1 @@ -Updated logging library with function "_get_lock" to acquire its module lock using a context manager so that it is safer and easier to use. +logging: Use a context manager for lock acquisition. From a298a7bce977141d9fa51abdd45139531d9f8f92 Mon Sep 17 00:00:00 2001 From: Dale Collison <92315623+dcollison@users.noreply.github.com> Date: Thu, 21 Sep 2023 09:23:22 +0100 Subject: [PATCH 16/26] Update __init__.py --- Lib/logging/__init__.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 98f52bccc2408d..617b3faf45f1cc 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -876,7 +876,7 @@ def _removeHandlerRef(wr): # pre-emptively grab the necessary globals and check if they're None, # to prevent race conditions and failures during interpreter shutdown. handlers = _handlerList - if handlers: + if _lock and handlers: with _lock: try: handlers.remove(wr) From 1979a75e185259994812d6ea79e00669e4195e66 Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Thu, 21 Sep 2023 18:09:02 +0100 Subject: [PATCH 17/26] Updated handlers to use a context manager for lock acquisition --- Lib/logging/__init__.py | 26 ++++++-------------------- 1 file changed, 6 insertions(+), 20 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 617b3faf45f1cc..d35dbcbcb68cea 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -956,15 +956,13 @@ def acquire(self): """ Acquire the I/O thread lock. """ - if self.lock: - self.lock.acquire() + self.lock.acquire() def release(self): """ Release the I/O thread lock. """ - if self.lock: - self.lock.release() + self.lock.release() def setLevel(self, level): """ @@ -1010,11 +1008,8 @@ def handle(self, record): if isinstance(rv, LogRecord): record = rv if rv: - self.acquire() - try: + with self.lock: self.emit(record) - finally: - self.release() return rv def setFormatter(self, fmt): @@ -1122,12 +1117,9 @@ def flush(self): """ Flushes the stream. """ - self.acquire() - try: + with self.lock: if self.stream and hasattr(self.stream, "flush"): self.stream.flush() - finally: - self.release() def emit(self, record): """ @@ -1163,12 +1155,9 @@ def setStream(self, stream): result = None else: result = self.stream - self.acquire() - try: + with self.lock: self.flush() self.stream = stream - finally: - self.release() return result def __repr__(self): @@ -1218,8 +1207,7 @@ def close(self): """ Closes the stream. """ - self.acquire() - try: + with self.lock: try: if self.stream: try: @@ -1235,8 +1223,6 @@ def close(self): # Also see Issue #42378: we also rely on # self._closed being set to True there StreamHandler.close(self) - finally: - self.release() def _open(self): """ From 3fd33efd596d8b9529771b25056b9ab54b164934 Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Thu, 21 Sep 2023 18:13:04 +0100 Subject: [PATCH 18/26] Updated handlers to use a context manager for lock acquisition --- Lib/logging/handlers.py | 30 ++++++----------------------- Lib/test/test_logging.py | 41 +++++++++++++++++----------------------- 2 files changed, 23 insertions(+), 48 deletions(-) diff --git a/Lib/logging/handlers.py b/Lib/logging/handlers.py index 671cc9596b02dd..e75da9b7b1de64 100644 --- a/Lib/logging/handlers.py +++ b/Lib/logging/handlers.py @@ -683,15 +683,12 @@ def close(self): """ Closes the socket. """ - self.acquire() - try: + with self.lock: sock = self.sock if sock: self.sock = None sock.close() logging.Handler.close(self) - finally: - self.release() class DatagramHandler(SocketHandler): """ @@ -953,15 +950,12 @@ def close(self): """ Closes the socket. """ - self.acquire() - try: + with self.lock: sock = self.socket if sock: self.socket = None sock.close() logging.Handler.close(self) - finally: - self.release() def mapPriority(self, levelName): """ @@ -1333,11 +1327,8 @@ def flush(self): This version just zaps the buffer to empty. """ - self.acquire() - try: + with self.lock: self.buffer.clear() - finally: - self.release() def close(self): """ @@ -1387,11 +1378,8 @@ def setTarget(self, target): """ Set the target handler for this handler. """ - self.acquire() - try: + with self.lock: self.target = target - finally: - self.release() def flush(self): """ @@ -1401,14 +1389,11 @@ def flush(self): The record buffer is only cleared if a target has been set. """ - self.acquire() - try: + with self.lock: if self.target: for record in self.buffer: self.target.handle(record) self.buffer.clear() - finally: - self.release() def close(self): """ @@ -1419,12 +1404,9 @@ def close(self): if self.flushOnClose: self.flush() finally: - self.acquire() - try: + with self.lock: self.target = None BufferingHandler.close(self) - finally: - self.release() class QueueHandler(logging.Handler): diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index 94a40555695921..cca02a010b80f4 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -733,11 +733,8 @@ def __init__(self): stream=open('/dev/null', 'wt', encoding='utf-8')) def emit(self, record): - self.sub_handler.acquire() - try: + with self.sub_handler.lock: self.sub_handler.emit(record) - finally: - self.sub_handler.release() self.assertEqual(len(logging._handlers), 0) refed_h = _OurHandler() @@ -753,26 +750,22 @@ def emit(self, record): fork_happened__release_locks_and_end_thread = threading.Event() def lock_holder_thread_fn(): - with logging._lock: - refed_h.acquire() - try: - # Tell the main thread to do the fork. - locks_held__ready_to_fork.set() - - # If the deadlock bug exists, the fork will happen - # without dealing with the locks we hold, deadlocking - # the child. - - # Wait for a successful fork or an unreasonable amount of - # time before releasing our locks. To avoid a timing based - # test we'd need communication from os.fork() as to when it - # has actually happened. Given this is a regression test - # for a fixed issue, potentially less reliably detecting - # regression via timing is acceptable for simplicity. - # The test will always take at least this long. :( - fork_happened__release_locks_and_end_thread.wait(0.5) - finally: - refed_h.release() + with logging._lock, refed_h.lock: + # Tell the main thread to do the fork. + locks_held__ready_to_fork.set() + + # If the deadlock bug exists, the fork will happen + # without dealing with the locks we hold, deadlocking + # the child. + + # Wait for a successful fork or an unreasonable amount of + # time before releasing our locks. To avoid a timing based + # test we'd need communication from os.fork() as to when it + # has actually happened. Given this is a regression test + # for a fixed issue, potentially less reliably detecting + # regression via timing is acceptable for simplicity. + # The test will always take at least this long. :( + fork_happened__release_locks_and_end_thread.wait(0.5) lock_holder_thread = threading.Thread( target=lock_holder_thread_fn, From 22c868e39d8248aeb65ea1109d11bcbb02c223dc Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Thu, 21 Sep 2023 18:17:20 +0100 Subject: [PATCH 19/26] Copying _lock to local variable --- Lib/logging/__init__.py | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index d35dbcbcb68cea..560200d80bd794 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -232,6 +232,7 @@ def _acquireLock(): """ Acquire the module-level lock for serializing access to shared data. + This should be released with _releaseLock(). This should be released with _releaseLock(). """ try: @@ -875,9 +876,9 @@ def _removeHandlerRef(wr): # set to None. It can also be called from another thread. So we need to # pre-emptively grab the necessary globals and check if they're None, # to prevent race conditions and failures during interpreter shutdown. - handlers = _handlerList - if _lock and handlers: - with _lock: + handlers, lock = _handlerList, _lock + if lock and handlers: + with lock: try: handlers.remove(wr) except ValueError: From 335f814017ec7ab4dd0ccafc0903bfc018952a35 Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Thu, 21 Sep 2023 18:22:17 +0100 Subject: [PATCH 20/26] Updated another lock acquisition --- Lib/logging/__init__.py | 30 ++++++++++++++---------------- 1 file changed, 14 insertions(+), 16 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 560200d80bd794..b1a76ba69ea96d 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -2213,22 +2213,20 @@ def shutdown(handlerList=_handlerList): try: h = wr() if h: - try: - h.acquire() - # MemoryHandlers might not want to be flushed on close, - # but circular imports prevent us scoping this to just - # those handlers. hence the default to True. - if getattr(h, 'flushOnClose', True): - h.flush() - h.close() - except (OSError, ValueError): - # Ignore errors which might be caused - # because handlers have been closed but - # references to them are still around at - # application exit. - pass - finally: - h.release() + with h.lock: + try: + # MemoryHandlers might not want to be flushed on close, + # but circular imports prevent us scoping this to just + # those handlers. hence the default to True. + if getattr(h, 'flushOnClose', True): + h.flush() + h.close() + except (OSError, ValueError): + # Ignore errors which might be caused + # because handlers have been closed but + # references to them are still around at + # application exit. + pass except: # ignore everything, as we're shutting down if raiseExceptions: raise From afa79efe9d4256a16c1e52b8f98c4c93a0157daf Mon Sep 17 00:00:00 2001 From: Dale Collison <92315623+dcollison@users.noreply.github.com> Date: Thu, 21 Sep 2023 18:22:28 +0100 Subject: [PATCH 21/26] Update Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst Co-authored-by: Victor Stinner --- .../next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst b/Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst index 640f6b7f17b359..28f0c16e620146 100644 --- a/Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst +++ b/Misc/NEWS.d/next/Library/2023-09-15-17-12-53.gh-issue-109461.VNFPTK.rst @@ -1 +1 @@ -logging: Use a context manager for lock acquisition. +:mod:`logging`: Use a context manager for lock acquisition. From 5e92580d9e09935adaeea4219d15d99d2fd3df8a Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Thu, 21 Sep 2023 18:23:52 +0100 Subject: [PATCH 22/26] Someone managed to duplicate a line in the docstring --- Lib/logging/__init__.py | 1 - 1 file changed, 1 deletion(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index b1a76ba69ea96d..828bed149d6738 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -232,7 +232,6 @@ def _acquireLock(): """ Acquire the module-level lock for serializing access to shared data. - This should be released with _releaseLock(). This should be released with _releaseLock(). """ try: From c73e2b714a69d38833aee8aaeda0877814ee400d Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Thu, 21 Sep 2023 18:26:19 +0100 Subject: [PATCH 23/26] Someone managed to duplicate a line in the docstring --- Lib/logging/__init__.py | 30 ++++++++++++++++-------------- 1 file changed, 16 insertions(+), 14 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 828bed149d6738..89e32270a70f11 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -2212,20 +2212,22 @@ def shutdown(handlerList=_handlerList): try: h = wr() if h: - with h.lock: - try: - # MemoryHandlers might not want to be flushed on close, - # but circular imports prevent us scoping this to just - # those handlers. hence the default to True. - if getattr(h, 'flushOnClose', True): - h.flush() - h.close() - except (OSError, ValueError): - # Ignore errors which might be caused - # because handlers have been closed but - # references to them are still around at - # application exit. - pass + try: + h.acquire() + # MemoryHandlers might not want to be flushed on close, + # but circular imports prevent us scoping this to just + # those handlers. hence the default to True. + if getattr(h, 'flushOnClose', True): + h.flush() + h.close() + except (OSError, ValueError): + # Ignore errors which might be caused + # because handlers have been closed but + # references to them are still around at + # application exit. + pass + finally: + h.release() except: # ignore everything, as we're shutting down if raiseExceptions: raise From a9472c725af15b0caf729c240298df16521630a4 Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Thu, 21 Sep 2023 18:34:46 +0100 Subject: [PATCH 24/26] Reverted Handler acquire() and release() as it actually needs the None check --- Lib/logging/__init__.py | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 89e32270a70f11..4fa366fabf34e2 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -956,13 +956,15 @@ def acquire(self): """ Acquire the I/O thread lock. """ - self.lock.acquire() + if self.lock: + self.lock.acquire() def release(self): """ Release the I/O thread lock. """ - self.lock.release() + if self.lock: + self.lock.release() def setLevel(self, level): """ From bca5ae894c3a7ea40d490f914f12fd940c750680 Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Fri, 22 Sep 2023 09:13:21 +0100 Subject: [PATCH 25/26] Added comment to _acquireLock() to justify the try-except block around lock acquisition --- Lib/logging/__init__.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 4fa366fabf34e2..f6df5ef0220adf 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -234,6 +234,8 @@ def _acquireLock(): This should be released with _releaseLock(). """ + # Wrap the lock acquisition in a try-except to prevent the lock from being + # abandoned in the event of an asynchronous exception. See gh-106238. try: _lock.acquire() except BaseException: From 1ba5979a695e605cdd8677e7318e5de507976c9d Mon Sep 17 00:00:00 2001 From: Dale Collison Date: Fri, 22 Sep 2023 09:27:12 +0100 Subject: [PATCH 26/26] Renamed "_acquireLock" to "_prepareFork" and "_releaseLock" to "_afterFork" and updated docstrings --- Lib/logging/__init__.py | 18 ++++++++++-------- 1 file changed, 10 insertions(+), 8 deletions(-) diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index f6df5ef0220adf..eb7e020d1edfc0 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -228,11 +228,11 @@ def _checkLevel(level): # _lock = threading.RLock() -def _acquireLock(): +def _prepareFork(): """ - Acquire the module-level lock for serializing access to shared data. + Prepare to fork a new child process by acquiring the module-level lock. - This should be released with _releaseLock(). + This should be used in conjunction with _afterFork(). """ # Wrap the lock acquisition in a try-except to prevent the lock from being # abandoned in the event of an asynchronous exception. See gh-106238. @@ -242,9 +242,11 @@ def _acquireLock(): _lock.release() raise -def _releaseLock(): +def _afterFork(): """ - Release the module-level lock acquired by calling _acquireLock(). + After a new child process has been forked, release the module-level lock. + + This should be used in conjunction with _prepareFork(). """ _lock.release() @@ -268,13 +270,13 @@ def _after_at_fork_child_reinit_locks(): for handler in _at_fork_reinit_lock_weakset: handler._at_fork_reinit() - # _acquireLock() was called in the parent before forking. + # _prepareFork() was called in the parent before forking. # The lock is reinitialized to unlocked state. _lock._at_fork_reinit() - os.register_at_fork(before=_acquireLock, + os.register_at_fork(before=_prepareFork, after_in_child=_after_at_fork_child_reinit_locks, - after_in_parent=_releaseLock) + after_in_parent=_afterFork) #---------------------------------------------------------------------------