diff options
| -rw-r--r-- | Doc/library/logging.handlers.rst | 3 | ||||
| -rw-r--r-- | Lib/logging/__init__.py | 13 | ||||
| -rw-r--r-- | Lib/test/test_logging.py | 18 | ||||
| -rw-r--r-- | Misc/NEWS.d/next/Library/2021-07-25-08-17-55.bpo-42378.WIhUZK.rst | 4 |
4 files changed, 32 insertions, 6 deletions
diff --git a/Doc/library/logging.handlers.rst b/Doc/library/logging.handlers.rst index 7fe9a98df82..51bcf599e08 100644 --- a/Doc/library/logging.handlers.rst +++ b/Doc/library/logging.handlers.rst @@ -117,6 +117,9 @@ sends logging output to a disk file. It inherits the output functionality from Outputs the record to the file. + Note that if the file was closed due to logging shutdown at exit and the file + mode is 'w', the record will not be emitted (see :issue:`42378`). + .. _null-handler: diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py index 3538f0670aa..e49e0d02a80 100644 --- a/Lib/logging/__init__.py +++ b/Lib/logging/__init__.py @@ -882,6 +882,7 @@ class Handler(Filterer): self._name = None self.level = _checkLevel(level) self.formatter = None + self._closed = False # Add the handler to the global _handlerList (for cleanup on shutdown) _addHandlerRef(self) self.createLock() @@ -1000,6 +1001,7 @@ class Handler(Filterer): #get the module data lock, as we're updating a shared structure. _acquireLock() try: #unlikely to raise an exception, but you never know... + self._closed = True if self._name and self._name in _handlers: del _handlers[self._name] finally: @@ -1188,6 +1190,8 @@ class FileHandler(StreamHandler): finally: # Issue #19523: call unconditionally to # prevent a handler leak when delay is set + # Also see Issue #42378: we also rely on + # self._closed being set to True there StreamHandler.close(self) finally: self.release() @@ -1207,10 +1211,15 @@ class FileHandler(StreamHandler): If the stream was not opened because 'delay' was specified in the constructor, open it before calling the superclass's emit. + + If stream is not open, current mode is 'w' and `_closed=True`, record + will not be emitted (see Issue #42378). """ if self.stream is None: - self.stream = self._open() - StreamHandler.emit(self, record) + if self.mode != 'w' or not self._closed: + self.stream = self._open() + if self.stream: + StreamHandler.emit(self, record) def __repr__(self): level = getLevelName(self.level) diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index 48ed2eb2fc6..94c3fd9f28b 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -5174,6 +5174,9 @@ class BaseFileTest(BaseTest): msg="Log file %r does not exist" % filename) self.rmfiles.append(filename) + def next_rec(self): + return logging.LogRecord('n', logging.DEBUG, 'p', 1, + self.next_message(), None, None, None) class FileHandlerTest(BaseFileTest): def test_delay(self): @@ -5186,11 +5189,18 @@ class FileHandlerTest(BaseFileTest): self.assertTrue(os.path.exists(self.fn)) fh.close() -class RotatingFileHandlerTest(BaseFileTest): - def next_rec(self): - return logging.LogRecord('n', logging.DEBUG, 'p', 1, - self.next_message(), None, None, None) + def test_emit_after_closing_in_write_mode(self): + # Issue #42378 + os.unlink(self.fn) + fh = logging.FileHandler(self.fn, encoding='utf-8', mode='w') + fh.setFormatter(logging.Formatter('%(message)s')) + fh.emit(self.next_rec()) # '1' + fh.close() + fh.emit(self.next_rec()) # '2' + with open(self.fn) as fp: + self.assertEqual(fp.read().strip(), '1') +class RotatingFileHandlerTest(BaseFileTest): def test_should_not_rollover(self): # If maxbytes is zero rollover never occurs rh = logging.handlers.RotatingFileHandler( diff --git a/Misc/NEWS.d/next/Library/2021-07-25-08-17-55.bpo-42378.WIhUZK.rst b/Misc/NEWS.d/next/Library/2021-07-25-08-17-55.bpo-42378.WIhUZK.rst new file mode 100644 index 00000000000..90c3961dc87 --- /dev/null +++ b/Misc/NEWS.d/next/Library/2021-07-25-08-17-55.bpo-42378.WIhUZK.rst @@ -0,0 +1,4 @@ +Fixes the issue with log file being overwritten when +:class:`logging.FileHandler` is used in :mod:`atexit` with *filemode* set to +``'w'``. Note this will cause the message in *atexit* not being logged if +the log stream is already closed due to shutdown of logging. |