Skip to content

Commit 707ce1f

Browse files
[3.11] gh-88352: Make TimedRotatingFileHandler tests more stable (GH-116409) (GH-116586)
The tests failed (with less than 1% probability) if for example the file was created at 11:46:03.999, but the record was emitted at 11:46:04.001, with atTime=11:46:04, which caused an unexpected rollover. Ensure that the tests are always run within the range of the same whole second. Also share code between test_rollover_at_midnight and test_rollover_at_weekday. (cherry picked from commit d8712fa) Co-authored-by: Serhiy Storchaka <[email protected]>
1 parent 34e808e commit 707ce1f

File tree

1 file changed

+17
-38
lines changed

1 file changed

+17
-38
lines changed

Lib/test/test_logging.py

Lines changed: 17 additions & 38 deletions
Original file line numberDiff line numberDiff line change
@@ -5654,46 +5654,22 @@ def test_rollover(self):
56545654
print(tf.read())
56555655
self.assertTrue(found, msg=msg)
56565656

5657-
def test_rollover_at_midnight(self):
5658-
atTime = datetime.datetime.now().time()
5659-
fmt = logging.Formatter('%(asctime)s %(message)s')
5660-
for i in range(3):
5661-
fh = logging.handlers.TimedRotatingFileHandler(
5662-
self.fn, encoding="utf-8", when='MIDNIGHT', atTime=atTime)
5663-
fh.setFormatter(fmt)
5664-
r2 = logging.makeLogRecord({'msg': f'testing1 {i}'})
5665-
fh.emit(r2)
5666-
fh.close()
5667-
self.assertLogFile(self.fn)
5668-
with open(self.fn, encoding="utf-8") as f:
5669-
for i, line in enumerate(f):
5670-
self.assertIn(f'testing1 {i}', line)
5671-
5672-
os.utime(self.fn, (time.time() - 1,)*2)
5673-
for i in range(2):
5674-
fh = logging.handlers.TimedRotatingFileHandler(
5675-
self.fn, encoding="utf-8", when='MIDNIGHT', atTime=atTime)
5676-
fh.setFormatter(fmt)
5677-
r2 = logging.makeLogRecord({'msg': f'testing2 {i}'})
5678-
fh.emit(r2)
5679-
fh.close()
5680-
rolloverDate = datetime.datetime.now() - datetime.timedelta(days=1)
5681-
otherfn = f'{self.fn}.{rolloverDate:%Y-%m-%d}'
5682-
self.assertLogFile(otherfn)
5683-
with open(self.fn, encoding="utf-8") as f:
5684-
for i, line in enumerate(f):
5685-
self.assertIn(f'testing2 {i}', line)
5686-
with open(otherfn, encoding="utf-8") as f:
5687-
for i, line in enumerate(f):
5688-
self.assertIn(f'testing1 {i}', line)
5689-
5690-
def test_rollover_at_weekday(self):
5657+
def test_rollover_at_midnight(self, weekly=False):
5658+
os_helper.unlink(self.fn)
56915659
now = datetime.datetime.now()
56925660
atTime = now.time()
5661+
if not 0.1 < atTime.microsecond/1e6 < 0.9:
5662+
# The test requires all records to be emitted within
5663+
# the range of the same whole second.
5664+
time.sleep((0.1 - atTime.microsecond/1e6) % 1.0)
5665+
now = datetime.datetime.now()
5666+
atTime = now.time()
5667+
atTime = atTime.replace(microsecond=0)
56935668
fmt = logging.Formatter('%(asctime)s %(message)s')
5669+
when = f'W{now.weekday()}' if weekly else 'MIDNIGHT'
56945670
for i in range(3):
56955671
fh = logging.handlers.TimedRotatingFileHandler(
5696-
self.fn, encoding="utf-8", when=f'W{now.weekday()}', atTime=atTime)
5672+
self.fn, encoding="utf-8", when=when, atTime=atTime)
56975673
fh.setFormatter(fmt)
56985674
r2 = logging.makeLogRecord({'msg': f'testing1 {i}'})
56995675
fh.emit(r2)
@@ -5703,15 +5679,15 @@ def test_rollover_at_weekday(self):
57035679
for i, line in enumerate(f):
57045680
self.assertIn(f'testing1 {i}', line)
57055681

5706-
os.utime(self.fn, (time.time() - 1,)*2)
5682+
os.utime(self.fn, (now.timestamp() - 1,)*2)
57075683
for i in range(2):
57085684
fh = logging.handlers.TimedRotatingFileHandler(
5709-
self.fn, encoding="utf-8", when=f'W{now.weekday()}', atTime=atTime)
5685+
self.fn, encoding="utf-8", when=when, atTime=atTime)
57105686
fh.setFormatter(fmt)
57115687
r2 = logging.makeLogRecord({'msg': f'testing2 {i}'})
57125688
fh.emit(r2)
57135689
fh.close()
5714-
rolloverDate = datetime.datetime.now() - datetime.timedelta(days=7)
5690+
rolloverDate = now - datetime.timedelta(days=7 if weekly else 1)
57155691
otherfn = f'{self.fn}.{rolloverDate:%Y-%m-%d}'
57165692
self.assertLogFile(otherfn)
57175693
with open(self.fn, encoding="utf-8") as f:
@@ -5721,6 +5697,9 @@ def test_rollover_at_weekday(self):
57215697
for i, line in enumerate(f):
57225698
self.assertIn(f'testing1 {i}', line)
57235699

5700+
def test_rollover_at_weekday(self):
5701+
self.test_rollover_at_midnight(weekly=True)
5702+
57245703
def test_invalid(self):
57255704
assertRaises = self.assertRaises
57265705
assertRaises(ValueError, logging.handlers.TimedRotatingFileHandler,

0 commit comments

Comments
 (0)