Skip to content

[3.9] bpo-46063: Improve algorithm for computing which rolled-over log file… (GH-30093) (GH-30095) #30095

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Dec 14, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
17 changes: 17 additions & 0 deletions Doc/library/logging.handlers.rst
Original file line number Diff line number Diff line change
Expand Up @@ -231,6 +231,19 @@ need to override.
return the same output every time for a given input, otherwise the
rollover behaviour may not work as expected.

It's also worth noting that care should be taken when using a namer to
preserve certain attributes in the filename which are used during rotation.
For example, :class:`RotatingFileHandler` expects to have a set of log files
whose names contain successive integers, so that rotation works as expected,
and :class:`TimedRotatingFileHandler` deletes old log files (based on the
``backupCount`` parameter passed to the handler's initializer) by determining
the oldest files to delete. For this to happen, the filenames should be
sortable using the date/time portion of the filename, and a namer needs to
respect this. (If a namer is wanted that doesn't respect this scheme, it will
need to be used in a subclass of :class:`TimedRotatingFileHandler` which
overrides the :meth:`~TimedRotatingFileHandler.getFilesToDelete` method to
fit in with the custom naming scheme.)

.. versionadded:: 3.3


Expand Down Expand Up @@ -440,6 +453,10 @@ timed intervals.

Outputs the record to the file, catering for rollover as described above.

.. method:: getFilesToDelete()

Returns a list of filenames which should be deleted as part of rollover. These
are the absolute paths of the oldest backup log files written by the handler.

.. _socket-handler:

Expand Down
19 changes: 16 additions & 3 deletions Lib/logging/handlers.py
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
# Copyright 2001-2016 by Vinay Sajip. All Rights Reserved.
# Copyright 2001-2021 by Vinay Sajip. All Rights Reserved.
#
# Permission to use, copy, modify, and distribute this software and its
# documentation for any purpose and without fee is hereby granted,
Expand All @@ -18,7 +18,7 @@
Additional handlers for the logging package for Python. The core package is
based on PEP 282 and comments thereto in comp.lang.python.
Copyright (C) 2001-2016 Vinay Sajip. All Rights Reserved.
Copyright (C) 2001-2021 Vinay Sajip. All Rights Reserved.
To use, simply 'import logging.handlers' and log away!
"""
Expand Down Expand Up @@ -363,9 +363,22 @@ def getFilesToDelete(self):
fileNames = os.listdir(dirName)
result = []
# See bpo-44753: Don't use the extension when computing the prefix.
prefix = os.path.splitext(baseName)[0] + "."
n, e = os.path.splitext(baseName)
prefix = n + '.'
plen = len(prefix)
for fileName in fileNames:
if self.namer is None:
# Our files will always start with baseName
if not fileName.startswith(baseName):
continue
else:
# Our files could be just about anything after custom naming, but
# likely candidates are of the form
# foo.log.DATETIME_SUFFIX or foo.DATETIME_SUFFIX.log
if (not fileName.startswith(baseName) and fileName.endswith(e) and
len(fileName) > (plen + 1) and not fileName[plen+1].isdigit()):
continue

if fileName[:plen] == prefix:
suffix = fileName[plen:]
# See bpo-45628: The date/time suffix could be anywhere in the
Expand Down
52 changes: 50 additions & 2 deletions Lib/test/test_logging.py
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
# Copyright 2001-2019 by Vinay Sajip. All Rights Reserved.
# Copyright 2001-2021 by Vinay Sajip. All Rights Reserved.
#
# Permission to use, copy, modify, and distribute this software and its
# documentation for any purpose and without fee is hereby granted,
Expand All @@ -16,7 +16,7 @@

"""Test harness for the logging module. Run all tests.
Copyright (C) 2001-2019 Vinay Sajip. All Rights Reserved.
Copyright (C) 2001-2021 Vinay Sajip. All Rights Reserved.
"""

import logging
Expand All @@ -36,6 +36,7 @@
import queue
import random
import re
import shutil
import socket
import struct
import sys
Expand Down Expand Up @@ -5284,6 +5285,53 @@ def test_compute_rollover_weekly_attime(self):
finally:
rh.close()

def test_compute_files_to_delete(self):
# See bpo-46063 for background
wd = tempfile.mkdtemp(prefix='test_logging_')
self.addCleanup(shutil.rmtree, wd)
times = []
dt = datetime.datetime.now()
for i in range(10):
times.append(dt.strftime('%Y-%m-%d_%H-%M-%S'))
dt += datetime.timedelta(seconds=5)
prefixes = ('a.b', 'a.b.c', 'd.e', 'd.e.f')
files = []
rotators = []
for prefix in prefixes:
p = os.path.join(wd, '%s.log' % prefix)
rotator = logging.handlers.TimedRotatingFileHandler(p, when='s',
interval=5,
backupCount=7)
rotators.append(rotator)
if prefix.startswith('a.b'):
for t in times:
files.append('%s.log.%s' % (prefix, t))
else:
rotator.namer = lambda name: name.replace('.log', '') + '.log'
for t in times:
files.append('%s.%s.log' % (prefix, t))
# Create empty files
for fn in files:
p = os.path.join(wd, fn)
with open(p, 'wb') as f:
pass
# Now the checks that only the correct files are offered up for deletion
for i, prefix in enumerate(prefixes):
rotator = rotators[i]
candidates = rotator.getFilesToDelete()
self.assertEqual(len(candidates), 3)
if prefix.startswith('a.b'):
p = '%s.log.' % prefix
for c in candidates:
d, fn = os.path.split(c)
self.assertTrue(fn.startswith(p))
else:
for c in candidates:
d, fn = os.path.split(c)
self.assertTrue(fn.endswith('.log'))
self.assertTrue(fn.startswith(prefix + '.') and
fn[len(prefix) + 2].isdigit())


def secs(**kw):
return datetime.timedelta(**kw) // datetime.timedelta(seconds=1)
Expand Down