Skip to content

Commit 395cae9

Browse files
serhiy-storchakadiegorusso
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.
1 parent ea2ece0 commit 395cae9

File tree

1 file changed

+17
-38
lines changed

1 file changed

+17
-38
lines changed

Lib/test/test_logging.py

+17-38
Original file line numberDiff line numberDiff line change
@@ -6080,46 +6080,22 @@ def test_rollover(self):
60806080
print(tf.read())
60816081
self.assertTrue(found, msg=msg)
60826082

6083-
def test_rollover_at_midnight(self):
6084-
atTime = datetime.datetime.now().time()
6085-
fmt = logging.Formatter('%(asctime)s %(message)s')
6086-
for i in range(3):
6087-
fh = logging.handlers.TimedRotatingFileHandler(
6088-
self.fn, encoding="utf-8", when='MIDNIGHT', atTime=atTime)
6089-
fh.setFormatter(fmt)
6090-
r2 = logging.makeLogRecord({'msg': f'testing1 {i}'})
6091-
fh.emit(r2)
6092-
fh.close()
6093-
self.assertLogFile(self.fn)
6094-
with open(self.fn, encoding="utf-8") as f:
6095-
for i, line in enumerate(f):
6096-
self.assertIn(f'testing1 {i}', line)
6097-
6098-
os.utime(self.fn, (time.time() - 1,)*2)
6099-
for i in range(2):
6100-
fh = logging.handlers.TimedRotatingFileHandler(
6101-
self.fn, encoding="utf-8", when='MIDNIGHT', atTime=atTime)
6102-
fh.setFormatter(fmt)
6103-
r2 = logging.makeLogRecord({'msg': f'testing2 {i}'})
6104-
fh.emit(r2)
6105-
fh.close()
6106-
rolloverDate = datetime.datetime.now() - datetime.timedelta(days=1)
6107-
otherfn = f'{self.fn}.{rolloverDate:%Y-%m-%d}'
6108-
self.assertLogFile(otherfn)
6109-
with open(self.fn, encoding="utf-8") as f:
6110-
for i, line in enumerate(f):
6111-
self.assertIn(f'testing2 {i}', line)
6112-
with open(otherfn, encoding="utf-8") as f:
6113-
for i, line in enumerate(f):
6114-
self.assertIn(f'testing1 {i}', line)
6115-
6116-
def test_rollover_at_weekday(self):
6083+
def test_rollover_at_midnight(self, weekly=False):
6084+
os_helper.unlink(self.fn)
61176085
now = datetime.datetime.now()
61186086
atTime = now.time()
6087+
if not 0.1 < atTime.microsecond/1e6 < 0.9:
6088+
# The test requires all records to be emitted within
6089+
# the range of the same whole second.
6090+
time.sleep((0.1 - atTime.microsecond/1e6) % 1.0)
6091+
now = datetime.datetime.now()
6092+
atTime = now.time()
6093+
atTime = atTime.replace(microsecond=0)
61196094
fmt = logging.Formatter('%(asctime)s %(message)s')
6095+
when = f'W{now.weekday()}' if weekly else 'MIDNIGHT'
61206096
for i in range(3):
61216097
fh = logging.handlers.TimedRotatingFileHandler(
6122-
self.fn, encoding="utf-8", when=f'W{now.weekday()}', atTime=atTime)
6098+
self.fn, encoding="utf-8", when=when, atTime=atTime)
61236099
fh.setFormatter(fmt)
61246100
r2 = logging.makeLogRecord({'msg': f'testing1 {i}'})
61256101
fh.emit(r2)
@@ -6129,15 +6105,15 @@ def test_rollover_at_weekday(self):
61296105
for i, line in enumerate(f):
61306106
self.assertIn(f'testing1 {i}', line)
61316107

6132-
os.utime(self.fn, (time.time() - 1,)*2)
6108+
os.utime(self.fn, (now.timestamp() - 1,)*2)
61336109
for i in range(2):
61346110
fh = logging.handlers.TimedRotatingFileHandler(
6135-
self.fn, encoding="utf-8", when=f'W{now.weekday()}', atTime=atTime)
6111+
self.fn, encoding="utf-8", when=when, atTime=atTime)
61366112
fh.setFormatter(fmt)
61376113
r2 = logging.makeLogRecord({'msg': f'testing2 {i}'})
61386114
fh.emit(r2)
61396115
fh.close()
6140-
rolloverDate = datetime.datetime.now() - datetime.timedelta(days=7)
6116+
rolloverDate = now - datetime.timedelta(days=7 if weekly else 1)
61416117
otherfn = f'{self.fn}.{rolloverDate:%Y-%m-%d}'
61426118
self.assertLogFile(otherfn)
61436119
with open(self.fn, encoding="utf-8") as f:
@@ -6147,6 +6123,9 @@ def test_rollover_at_weekday(self):
61476123
for i, line in enumerate(f):
61486124
self.assertIn(f'testing1 {i}', line)
61496125

6126+
def test_rollover_at_weekday(self):
6127+
self.test_rollover_at_midnight(weekly=True)
6128+
61506129
def test_invalid(self):
61516130
assertRaises = self.assertRaises
61526131
assertRaises(ValueError, logging.handlers.TimedRotatingFileHandler,

0 commit comments

Comments
 (0)