From 39d9f1f0588c9fed7763e0b076acf33dd8f44b8b Mon Sep 17 00:00:00 2001 From: Ivan Marton Date: Fri, 1 Mar 2024 21:12:14 +0100 Subject: [PATCH 1/3] Add missing NEWS item about the change --- .../next/Library/2021-02-26-13-17-57.bpo-40469.yJHeQg.rst | 6 ++++++ 1 file changed, 6 insertions(+) create mode 100644 Misc/NEWS.d/next/Library/2021-02-26-13-17-57.bpo-40469.yJHeQg.rst diff --git a/Misc/NEWS.d/next/Library/2021-02-26-13-17-57.bpo-40469.yJHeQg.rst b/Misc/NEWS.d/next/Library/2021-02-26-13-17-57.bpo-40469.yJHeQg.rst new file mode 100644 index 000000000000000..eab474dfd2ea82a --- /dev/null +++ b/Misc/NEWS.d/next/Library/2021-02-26-13-17-57.bpo-40469.yJHeQg.rst @@ -0,0 +1,6 @@ +A bug has been fixed that made the ``TimedRotatingFileHandler`` use the +MTIME attribute of the configured log file to to detect whether it has to be +rotated yet or not. In cases when the file was changed within the rotation +period the value of the MTIME was also updated to the current time and as a +result the rotation never happened. The file creation time (CTIME) is used +instead that makes the rotation file modification independent. From 67313093f1c16b0db72f48e2733ad3d2326bfe49 Mon Sep 17 00:00:00 2001 From: Ivan Marton Date: Fri, 1 Mar 2024 21:11:00 +0100 Subject: [PATCH 2/3] gh-84649: Make TimedRotatingFileHandler use CTIME instead of MTIME The TimedRotatingFileHandler previously only used st_mtime attribute of the log file to detect whether it has to be rotate yet or not. In cases when the file is changed within the rotatation period the st_mtime is also updated to the current time and the rotation never happens. It's more appropriate to check the file creation time (st_ctime) instead. Whenever available, the more appropriate st_birthtime will be in use. (This feature is available on FreeBSD, MacOS and Windows at the moment.) If the st_mtime would be newer than st_ctime (e.g.: because the inode related to the file has been changed without any file content modification), then the earliest attribute will be used. --- Lib/logging/handlers.py | 12 +++++++-- Lib/test/support/__init__.py | 4 +++ Lib/test/test_logging.py | 47 ++++++++++++++++++++++++++++++++++++ Misc/ACKS | 1 + 4 files changed, 62 insertions(+), 2 deletions(-) diff --git a/Lib/logging/handlers.py b/Lib/logging/handlers.py index cdb014bca04b6e0..6ea86173a390118 100644 --- a/Lib/logging/handlers.py +++ b/Lib/logging/handlers.py @@ -24,7 +24,7 @@ """ import io, logging, socket, os, pickle, struct, time, re -from stat import ST_DEV, ST_INO, ST_MTIME +from stat import ST_DEV, ST_INO import queue import threading import copy @@ -269,7 +269,15 @@ def __init__(self, filename, when='h', interval=1, backupCount=0, # path object (see Issue #27493), but self.baseFilename will be a string filename = self.baseFilename if os.path.exists(filename): - t = os.stat(filename)[ST_MTIME] + # Use the minimum of file creation and modification time as the base of the + # rollover calculation + stat_result = os.stat(filename) + # Use st_birthtime whenever it is available or use st_ctime instead otherwise + try: + creation_time = stat_result.st_birthtime + except AttributeError: + creation_time = stat_result.st_ctime + t = int(min(creation_time, stat_result.st_mtime)) else: t = int(time.time()) self.rolloverAt = self.computeRollover(t) diff --git a/Lib/test/support/__init__.py b/Lib/test/support/__init__.py index 505d4bea83fe8d5..d0f0058be9802c1 100644 --- a/Lib/test/support/__init__.py +++ b/Lib/test/support/__init__.py @@ -37,6 +37,7 @@ "has_fork_support", "requires_fork", "has_subprocess_support", "requires_subprocess", "has_socket_support", "requires_working_socket", + "has_st_birthtime", "anticipate_failure", "load_package_tests", "detect_api_mismatch", "check__all__", "skip_if_buggy_ucrt_strfptime", "check_disallow_instantiation", "check_sanitizer", "skip_if_sanitizer", @@ -546,6 +547,9 @@ def requires_debug_ranges(reason='requires co_positions / debug_ranges'): or is_android ) +# At the moment, st_birthtime attribute is only supported on Windows, MacOS and FreeBSD +has_st_birthtime = sys.platform.startswith(("win", "freebsd", "darwin")) + def requires_fork(): return unittest.skipUnless(has_fork_support, "requires working os.fork()") diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index d71385bf2c78d7e..e14b1aa4f68bbe6 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -6080,6 +6080,53 @@ def test_rollover(self): print(tf.read()) self.assertTrue(found, msg=msg) + @unittest.skipUnless(support.has_st_birthtime, "st_birthtime not available or supported by Python on this OS") + def test_rollover_based_on_st_birthtime_only(self): + def add_record(message: str) -> None: + fh = logging.handlers.TimedRotatingFileHandler( + self.fn, when='S', interval=4, encoding="utf-8", backupCount=1) + fmt = logging.Formatter('%(asctime)s %(message)s') + fh.setFormatter(fmt) + record = logging.makeLogRecord({'msg': message}) + fh.emit(record) + fh.close() + + add_record('testing - initial') + self.assertLogFile(self.fn) + # Sleep a little over the half of rollover time - and this value must be over + # 2 seconds, since this is the mtime resolution on FAT32 filesystems. + time.sleep(2.1) + add_record('testing - update before rollover to renew the st_mtime') + time.sleep(2.1) # a little over the half of rollover time + add_record('testing - new record supposedly in the new file after rollover') + + # At this point, the log file should be rotated if the rotation is based + # on creation time but should be not if it's based on creation time + found = False + now = datetime.datetime.now() + GO_BACK = 5 # seconds + for secs in range(GO_BACK): + prev = now - datetime.timedelta(seconds=secs) + fn = self.fn + prev.strftime(".%Y-%m-%d_%H-%M-%S") + found = os.path.exists(fn) + if found: + self.rmfiles.append(fn) + break + msg = 'No rotated files found, went back %d seconds' % GO_BACK + if not found: + # print additional diagnostics + dn, fn = os.path.split(self.fn) + files = [f for f in os.listdir(dn) if f.startswith(fn)] + print('Test time: %s' % now.strftime("%Y-%m-%d %H-%M-%S"), file=sys.stderr) + print('The only matching files are: %s' % files, file=sys.stderr) + for f in files: + print('Contents of %s:' % f) + path = os.path.join(dn, f) + print(os.stat(path)) + with open(path, 'r') as tf: + print(tf.read()) + self.assertTrue(found, msg=msg) + def test_rollover_at_midnight(self): atTime = datetime.datetime.now().time() fmt = logging.Formatter('%(asctime)s %(message)s') diff --git a/Misc/ACKS b/Misc/ACKS index f01c7a70a65dc52..187f832c13f15e2 100644 --- a/Misc/ACKS +++ b/Misc/ACKS @@ -1170,6 +1170,7 @@ Owen Martin Sidney San Martín Westley Martínez Sébastien Martini +Iván Márton Roger Masse Nick Mathewson Simon Mathieu From 6e588d4b75c5934b7b4903afef990c5d9e4ee3d4 Mon Sep 17 00:00:00 2001 From: Serhiy Storchaka Date: Thu, 4 Jun 2026 14:11:15 +0300 Subject: [PATCH 3/3] Re-wrap long lines. --- Lib/logging/handlers.py | 7 ++++--- Lib/test/support/__init__.py | 3 ++- Lib/test/test_logging.py | 13 ++++++++----- 3 files changed, 14 insertions(+), 9 deletions(-) diff --git a/Lib/logging/handlers.py b/Lib/logging/handlers.py index 3256936a615ebbf..73782f53041008c 100644 --- a/Lib/logging/handlers.py +++ b/Lib/logging/handlers.py @@ -282,10 +282,11 @@ def __init__(self, filename, when='h', interval=1, backupCount=0, # path object (see Issue #27493), but self.baseFilename will be a string filename = self.baseFilename if os.path.exists(filename): - # Use the minimum of file creation and modification time as the base of the - # rollover calculation + # Use the minimum of file creation and modification time as + # the base of the rollover calculation stat_result = os.stat(filename) - # Use st_birthtime whenever it is available or use st_ctime instead otherwise + # Use st_birthtime whenever it is available or use st_ctime + # instead otherwise try: creation_time = stat_result.st_birthtime except AttributeError: diff --git a/Lib/test/support/__init__.py b/Lib/test/support/__init__.py index 70d52dc641473b1..84f735c1537efa7 100644 --- a/Lib/test/support/__init__.py +++ b/Lib/test/support/__init__.py @@ -621,7 +621,8 @@ def skip_wasi_stack_overflow(): or is_android ) -# At the moment, st_birthtime attribute is only supported on Windows, MacOS and FreeBSD +# At the moment, st_birthtime attribute is only supported on Windows, +# MacOS and FreeBSD. has_st_birthtime = sys.platform.startswith(("win", "freebsd", "darwin")) def requires_fork(): diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py index 4ed626d4d764685..31c052bfb56cd7a 100644 --- a/Lib/test/test_logging.py +++ b/Lib/test/test_logging.py @@ -6615,7 +6615,8 @@ def test_rollover(self): print(tf.read()) self.assertTrue(found, msg=msg) - @unittest.skipUnless(support.has_st_birthtime, "st_birthtime not available or supported by Python on this OS") + @unittest.skipUnless(support.has_st_birthtime, + "st_birthtime not available or supported by Python on this OS") def test_rollover_based_on_st_birthtime_only(self): def add_record(message: str) -> None: fh = logging.handlers.TimedRotatingFileHandler( @@ -6628,15 +6629,17 @@ def add_record(message: str) -> None: add_record('testing - initial') self.assertLogFile(self.fn) - # Sleep a little over the half of rollover time - and this value must be over - # 2 seconds, since this is the mtime resolution on FAT32 filesystems. + # Sleep a little over the half of rollover time - and this value + # must be over 2 seconds, since this is the mtime resolution on + # FAT32 filesystems. time.sleep(2.1) add_record('testing - update before rollover to renew the st_mtime') time.sleep(2.1) # a little over the half of rollover time add_record('testing - new record supposedly in the new file after rollover') - # At this point, the log file should be rotated if the rotation is based - # on creation time but should be not if it's based on creation time + # At this point, the log file should be rotated if the rotation + # is based on creation time but should be not if it's based on + # creation time. found = False now = datetime.datetime.now() GO_BACK = 5 # seconds