Skip to content

Commit e75c1ec

Browse files
serhiy-storchakamiss-islington
authored andcommitted
pythongh-88352: Make TimedRotatingFileHandler tests more stable (pythonGH-116409)
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 de239be commit e75c1ec

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
@@ -6025,46 +6025,22 @@ def test_rollover(self):
60256025
print(tf.read())
60266026
self.assertTrue(found, msg=msg)
60276027

6028-
def test_rollover_at_midnight(self):
6029-
atTime = datetime.datetime.now().time()
6030-
fmt = logging.Formatter('%(asctime)s %(message)s')
6031-
for i in range(3):
6032-
fh = logging.handlers.TimedRotatingFileHandler(
6033-
self.fn, encoding="utf-8", when='MIDNIGHT', atTime=atTime)
6034-
fh.setFormatter(fmt)
6035-
r2 = logging.makeLogRecord({'msg': f'testing1 {i}'})
6036-
fh.emit(r2)
6037-
fh.close()
6038-
self.assertLogFile(self.fn)
6039-
with open(self.fn, encoding="utf-8") as f:
6040-
for i, line in enumerate(f):
6041-
self.assertIn(f'testing1 {i}', line)
6042-
6043-
os.utime(self.fn, (time.time() - 1,)*2)
6044-
for i in range(2):
6045-
fh = logging.handlers.TimedRotatingFileHandler(
6046-
self.fn, encoding="utf-8", when='MIDNIGHT', atTime=atTime)
6047-
fh.setFormatter(fmt)
6048-
r2 = logging.makeLogRecord({'msg': f'testing2 {i}'})
6049-
fh.emit(r2)
6050-
fh.close()
6051-
rolloverDate = datetime.datetime.now() - datetime.timedelta(days=1)
6052-
otherfn = f'{self.fn}.{rolloverDate:%Y-%m-%d}'
6053-
self.assertLogFile(otherfn)
6054-
with open(self.fn, encoding="utf-8") as f:
6055-
for i, line in enumerate(f):
6056-
self.assertIn(f'testing2 {i}', line)
6057-
with open(otherfn, encoding="utf-8") as f:
6058-
for i, line in enumerate(f):
6059-
self.assertIn(f'testing1 {i}', line)
6060-
6061-
def test_rollover_at_weekday(self):
6028+
def test_rollover_at_midnight(self, weekly=False):
6029+
os_helper.unlink(self.fn)
60626030
now = datetime.datetime.now()
60636031
atTime = now.time()
6032+
if not 0.1 < atTime.microsecond/1e6 < 0.9:
6033+
# The test requires all records to be emitted within
6034+
# the range of the same whole second.
6035+
time.sleep((0.1 - atTime.microsecond/1e6) % 1.0)
6036+
now = datetime.datetime.now()
6037+
atTime = now.time()
6038+
atTime = atTime.replace(microsecond=0)
60646039
fmt = logging.Formatter('%(asctime)s %(message)s')
6040+
when = f'W{now.weekday()}' if weekly else 'MIDNIGHT'
60656041
for i in range(3):
60666042
fh = logging.handlers.TimedRotatingFileHandler(
6067-
self.fn, encoding="utf-8", when=f'W{now.weekday()}', atTime=atTime)
6043+
self.fn, encoding="utf-8", when=when, atTime=atTime)
60686044
fh.setFormatter(fmt)
60696045
r2 = logging.makeLogRecord({'msg': f'testing1 {i}'})
60706046
fh.emit(r2)
@@ -6074,15 +6050,15 @@ def test_rollover_at_weekday(self):
60746050
for i, line in enumerate(f):
60756051
self.assertIn(f'testing1 {i}', line)
60766052

6077-
os.utime(self.fn, (time.time() - 1,)*2)
6053+
os.utime(self.fn, (now.timestamp() - 1,)*2)
60786054
for i in range(2):
60796055
fh = logging.handlers.TimedRotatingFileHandler(
6080-
self.fn, encoding="utf-8", when=f'W{now.weekday()}', atTime=atTime)
6056+
self.fn, encoding="utf-8", when=when, atTime=atTime)
60816057
fh.setFormatter(fmt)
60826058
r2 = logging.makeLogRecord({'msg': f'testing2 {i}'})
60836059
fh.emit(r2)
60846060
fh.close()
6085-
rolloverDate = datetime.datetime.now() - datetime.timedelta(days=7)
6061+
rolloverDate = now - datetime.timedelta(days=7 if weekly else 1)
60866062
otherfn = f'{self.fn}.{rolloverDate:%Y-%m-%d}'
60876063
self.assertLogFile(otherfn)
60886064
with open(self.fn, encoding="utf-8") as f:
@@ -6092,6 +6068,9 @@ def test_rollover_at_weekday(self):
60926068
for i, line in enumerate(f):
60936069
self.assertIn(f'testing1 {i}', line)
60946070

6071+
def test_rollover_at_weekday(self):
6072+
self.test_rollover_at_midnight(weekly=True)
6073+
60956074
def test_invalid(self):
60966075
assertRaises = self.assertRaises
60976076
assertRaises(ValueError, logging.handlers.TimedRotatingFileHandler,

0 commit comments

Comments
 (0)