Skip to content

Commit 7dc920a

Browse files
gh-84649: Fix unstable test_rollover_at_midnight (GH-154463)
Create the log file in a fresh directory under a name which has never been used. On Windows, NTFS file tunneling restored the original creation time of a file recreated with the same name, which made the rollover time earlier than the current time and caused an unwanted rollover. Also check that the rollover does not happen before the specified time. Co-authored-by: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
1 parent d1174a4 commit 7dc920a

1 file changed

Lines changed: 24 additions & 3 deletions

File tree

Lib/test/test_logging.py

Lines changed: 24 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -6704,7 +6704,14 @@ def add_record(message: str) -> None:
67046704
self.assertTrue(found, msg=msg)
67056705

67066706
def test_rollover_at_midnight(self, weekly=False):
6707+
# Create the log file in a fresh directory under a never used name:
6708+
# on Windows, NTFS file tunneling restores the original creation time
6709+
# of a file recreated with the same name.
67076710
os_helper.unlink(self.fn)
6711+
dirname = tempfile.mkdtemp()
6712+
self.addCleanup(os_helper.rmtree, dirname)
6713+
self.fn = os.path.join(dirname, 'test_rollover.log')
6714+
67086715
# Emit the first records a little after the beginning of a whole
67096716
# second, so that their file times fall inside that second and not the
67106717
# previous one, which would cause an unwanted rollover.
@@ -6730,7 +6737,24 @@ def test_rollover_at_midnight(self, weekly=False):
67306737
# changed, so the rollover cannot be forced by back-dating the file.
67316738
# Wait until the clock reaches a rollover time set one second ahead.
67326739
rollover = int(time.time()) + 1
6740+
if rollover - time.time() < 0.1:
6741+
# Leave time to emit a record before the rollover time.
6742+
rollover += 1
67336743
atTime = datetime.datetime.fromtimestamp(rollover).time()
6744+
rolloverDate = (datetime.datetime.fromtimestamp(rollover)
6745+
- datetime.timedelta(days=7 if weekly else 1))
6746+
otherfn = f'{self.fn}.{rolloverDate:%Y-%m-%d}'
6747+
6748+
# A record emitted before the rollover time is not rolled over.
6749+
fh = logging.handlers.TimedRotatingFileHandler(
6750+
self.fn, encoding="utf-8", when=when, atTime=atTime)
6751+
fh.setFormatter(fmt)
6752+
r2 = logging.makeLogRecord({'msg': 'testing1 3'})
6753+
fh.emit(r2)
6754+
fh.close()
6755+
self.assertFalse(os.path.exists(otherfn),
6756+
msg=f'{otherfn} was rolled over too early')
6757+
67346758
while time.time() < rollover:
67356759
time.sleep(rollover - time.time())
67366760
for i in range(2):
@@ -6740,9 +6764,6 @@ def test_rollover_at_midnight(self, weekly=False):
67406764
r2 = logging.makeLogRecord({'msg': f'testing2 {i}'})
67416765
fh.emit(r2)
67426766
fh.close()
6743-
rolloverDate = (datetime.datetime.fromtimestamp(rollover)
6744-
- datetime.timedelta(days=7 if weekly else 1))
6745-
otherfn = f'{self.fn}.{rolloverDate:%Y-%m-%d}'
67466767
self.assertLogFile(otherfn)
67476768
with open(self.fn, encoding="utf-8") as f:
67486769
for i, line in enumerate(f):

0 commit comments

Comments
 (0)