[Python-checkins] gh-92592: Allow logging filters to return a LogRecord. (GH-92591)
vsajip
webhook-mailer at python.org
Tue Jun 7 11:54:07 EDT 2022
https://github.com/python/cpython/commit/296081a7cedc032232efc823b7b238710677a9df
commit: 296081a7cedc032232efc823b7b238710677a9df
branch: main
author: Adrian Garcia Badaracco <1755071+adriangb at users.noreply.github.com>
committer: vsajip <vinay_sajip at yahoo.co.uk>
date: 2022-06-07T16:53:57+01:00
summary:
gh-92592: Allow logging filters to return a LogRecord. (GH-92591)
files:
A Misc/NEWS.d/next/Library/2022-05-09-22-27-11.gh-issue-92591.V7RCk2.rst
M Doc/howto/logging-cookbook.rst
M Doc/library/logging.rst
M Lib/logging/__init__.py
M Lib/test/test_logging.py
diff --git a/Doc/howto/logging-cookbook.rst b/Doc/howto/logging-cookbook.rst
index 2b5eb8ff320dd..8b42383e2eb55 100644
--- a/Doc/howto/logging-cookbook.rst
+++ b/Doc/howto/logging-cookbook.rst
@@ -714,6 +714,32 @@ which, when run, produces something like:
2010-09-06 22:38:15,301 d.e.f DEBUG IP: 123.231.231.123 User: fred A message at DEBUG level with 2 parameters
2010-09-06 22:38:15,301 d.e.f INFO IP: 123.231.231.123 User: fred A message at INFO level with 2 parameters
+Imparting contextual information in handlers
+--------------------------------------------
+
+Each :class:`~Handler` has its own chain of filters.
+If you want to add contextual information to a :class:`LogRecord` without leaking
+it to other handlers, you can use a filter that returns
+a new :class:`~LogRecord` instead of modifying it in-place, as shown in the following script::
+
+ import copy
+ import logging
+
+ def filter(record: logging.LogRecord):
+ record = copy.copy(record)
+ record.user = 'jim'
+ return record
+
+ if __name__ == '__main__':
+ logger = logging.getLogger()
+ logger.setLevel(logging.INFO)
+ handler = logging.StreamHandler()
+ formatter = logging.Formatter('%(message)s from %(user)-8s')
+ handler.setFormatter(formatter)
+ handler.addFilter(filter)
+ logger.addHandler(handler)
+
+ logger.info('A log message')
.. _multiple-processes:
diff --git a/Doc/library/logging.rst b/Doc/library/logging.rst
index cc83193c86393..fda8e64c23bc5 100644
--- a/Doc/library/logging.rst
+++ b/Doc/library/logging.rst
@@ -666,9 +666,10 @@ empty string, all events are passed.
.. method:: filter(record)
- Is the specified record to be logged? Returns zero for no, nonzero for
- yes. If deemed appropriate, the record may be modified in-place by this
- method.
+ Is the specified record to be logged? Returns falsy for no, truthy for
+ yes. Filters can either modify log records in-place or return a completely
+ different record instance which will replace the original
+ log record in any future processing of the event.
Note that filters attached to handlers are consulted before an event is
emitted by the handler, whereas filters attached to loggers are consulted
@@ -690,6 +691,12 @@ which has a ``filter`` method with the same semantics.
parameter. The returned value should conform to that returned by
:meth:`~Filter.filter`.
+.. versionchanged:: 3.12
+ You can now return a :class:`LogRecord` instance from filters to replace
+ the log record rather than modifying it in place. This allows filters attached to
+ a :class:`Handler` to modify the log record before it is emitted, without
+ having side effects on other handlers.
+
Although filters are used primarily to filter records based on more
sophisticated criteria than levels, they get to see every record which is
processed by the handler or logger they're attached to: this can be useful if
diff --git a/Lib/logging/__init__.py b/Lib/logging/__init__.py
index 276845a9b62da..88953fefb7447 100644
--- a/Lib/logging/__init__.py
+++ b/Lib/logging/__init__.py
@@ -833,23 +833,36 @@ def filter(self, record):
Determine if a record is loggable by consulting all the filters.
The default is to allow the record to be logged; any filter can veto
- this and the record is then dropped. Returns a zero value if a record
- is to be dropped, else non-zero.
+ this by returning a falsy value.
+ If a filter attached to a handler returns a log record instance,
+ then that instance is used in place of the original log record in
+ any further processing of the event by that handler.
+ If a filter returns any other truthy value, the original log record
+ is used in any further processing of the event by that handler.
+
+ If none of the filters return falsy values, this method returns
+ a log record.
+ If any of the filters return a falsy value, this method returns
+ a falsy value.
.. versionchanged:: 3.2
Allow filters to be just callables.
+
+ .. versionchanged:: 3.12
+ Allow filters to return a LogRecord instead of
+ modifying it in place.
"""
- rv = True
for f in self.filters:
if hasattr(f, 'filter'):
result = f.filter(record)
else:
result = f(record) # assume callable - will raise if not
if not result:
- rv = False
- break
- return rv
+ return False
+ if isinstance(result, LogRecord):
+ record = result
+ return record
#---------------------------------------------------------------------------
# Handler classes and functions
@@ -1001,10 +1014,14 @@ def handle(self, record):
Emission depends on filters which may have been added to the handler.
Wrap the actual emission of the record with acquisition/release of
- the I/O thread lock. Returns whether the filter passed the record for
- emission.
+ the I/O thread lock.
+
+ Returns an instance of the log record that was emitted
+ if it passed all filters, otherwise a falsy value is returned.
"""
rv = self.filter(record)
+ if isinstance(rv, LogRecord):
+ record = rv
if rv:
self.acquire()
try:
@@ -1673,8 +1690,14 @@ def handle(self, record):
This method is used for unpickled records received from a socket, as
well as those created locally. Logger-level filtering is applied.
"""
- if (not self.disabled) and self.filter(record):
- self.callHandlers(record)
+ if self.disabled:
+ return
+ maybe_record = self.filter(record)
+ if not maybe_record:
+ return
+ if isinstance(maybe_record, LogRecord):
+ record = maybe_record
+ self.callHandlers(record)
def addHandler(self, hdlr):
"""
diff --git a/Lib/test/test_logging.py b/Lib/test/test_logging.py
index 3edb52d6c87bb..87b3efa406572 100644
--- a/Lib/test/test_logging.py
+++ b/Lib/test/test_logging.py
@@ -468,6 +468,51 @@ def log_at_all_levels(self, logger):
for lvl in LEVEL_RANGE:
logger.log(lvl, self.next_message())
+ def test_handler_filter_replaces_record(self):
+ def replace_message(record: logging.LogRecord):
+ record = copy.copy(record)
+ record.msg = "new message!"
+ return record
+
+ # Set up a logging hierarchy such that "child" and it's handler
+ # (and thus `replace_message()`) always get called before
+ # propagating up to "parent".
+ # Then we can confirm that `replace_message()` was able to
+ # replace the log record without having a side effect on
+ # other loggers or handlers.
+ parent = logging.getLogger("parent")
+ child = logging.getLogger("parent.child")
+ stream_1 = io.StringIO()
+ stream_2 = io.StringIO()
+ handler_1 = logging.StreamHandler(stream_1)
+ handler_2 = logging.StreamHandler(stream_2)
+ handler_2.addFilter(replace_message)
+ parent.addHandler(handler_1)
+ child.addHandler(handler_2)
+
+ child.info("original message")
+ handler_1.flush()
+ handler_2.flush()
+ self.assertEqual(stream_1.getvalue(), "original message\n")
+ self.assertEqual(stream_2.getvalue(), "new message!\n")
+
+ def test_logging_filter_replaces_record(self):
+ records = set()
+
+ class RecordingFilter(logging.Filter):
+ def filter(self, record: logging.LogRecord):
+ records.add(id(record))
+ return copy.copy(record)
+
+ logger = logging.getLogger("logger")
+ logger.setLevel(logging.INFO)
+ logger.addFilter(RecordingFilter())
+ logger.addFilter(RecordingFilter())
+
+ logger.info("msg")
+
+ self.assertEqual(2, len(records))
+
def test_logger_filter(self):
# Filter at logger level.
self.root_logger.setLevel(VERBOSE)
diff --git a/Misc/NEWS.d/next/Library/2022-05-09-22-27-11.gh-issue-92591.V7RCk2.rst b/Misc/NEWS.d/next/Library/2022-05-09-22-27-11.gh-issue-92591.V7RCk2.rst
new file mode 100644
index 0000000000000..cd9b598d1dbca
--- /dev/null
+++ b/Misc/NEWS.d/next/Library/2022-05-09-22-27-11.gh-issue-92591.V7RCk2.rst
@@ -0,0 +1,3 @@
+Allow :mod:`logging` filters to return a :class:`logging.LogRecord` instance
+so that filters attached to :class:`logging.Handler`\ s can enrich records without
+side effects on other handlers.
More information about the Python-checkins
mailing list