python · martonivan · Mar 1, 2024 · Mar 1, 2024
@@ -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
@@ -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()")
 

@@ -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
@@ -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

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
@@ -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.