Skip to content

Commit 296081a

Browse files
authored
gh-92592: Allow logging filters to return a LogRecord. (GH-92591)
1 parent 70690c7 commit 296081a

File tree

5 files changed

+117
-13
lines changed

5 files changed

+117
-13
lines changed

Doc/howto/logging-cookbook.rst

+26
Original file line numberDiff line numberDiff line change
@@ -714,6 +714,32 @@ which, when run, produces something like:
714714
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
715715
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
716716
717+
Imparting contextual information in handlers
718+
--------------------------------------------
719+
720+
Each :class:`~Handler` has its own chain of filters.
721+
If you want to add contextual information to a :class:`LogRecord` without leaking
722+
it to other handlers, you can use a filter that returns
723+
a new :class:`~LogRecord` instead of modifying it in-place, as shown in the following script::
724+
725+
import copy
726+
import logging
727+
728+
def filter(record: logging.LogRecord):
729+
record = copy.copy(record)
730+
record.user = 'jim'
731+
return record
732+
733+
if __name__ == '__main__':
734+
logger = logging.getLogger()
735+
logger.setLevel(logging.INFO)
736+
handler = logging.StreamHandler()
737+
formatter = logging.Formatter('%(message)s from %(user)-8s')
738+
handler.setFormatter(formatter)
739+
handler.addFilter(filter)
740+
logger.addHandler(handler)
741+
742+
logger.info('A log message')
717743

718744
.. _multiple-processes:
719745

Doc/library/logging.rst

+10-3
Original file line numberDiff line numberDiff line change
@@ -666,9 +666,10 @@ empty string, all events are passed.
666666

667667
.. method:: filter(record)
668668

669-
Is the specified record to be logged? Returns zero for no, nonzero for
670-
yes. If deemed appropriate, the record may be modified in-place by this
671-
method.
669+
Is the specified record to be logged? Returns falsy for no, truthy for
670+
yes. Filters can either modify log records in-place or return a completely
671+
different record instance which will replace the original
672+
log record in any future processing of the event.
672673

673674
Note that filters attached to handlers are consulted before an event is
674675
emitted by the handler, whereas filters attached to loggers are consulted
@@ -690,6 +691,12 @@ which has a ``filter`` method with the same semantics.
690691
parameter. The returned value should conform to that returned by
691692
:meth:`~Filter.filter`.
692693

694+
.. versionchanged:: 3.12
695+
You can now return a :class:`LogRecord` instance from filters to replace
696+
the log record rather than modifying it in place. This allows filters attached to
697+
a :class:`Handler` to modify the log record before it is emitted, without
698+
having side effects on other handlers.
699+
693700
Although filters are used primarily to filter records based on more
694701
sophisticated criteria than levels, they get to see every record which is
695702
processed by the handler or logger they're attached to: this can be useful if

Lib/logging/__init__.py

+33-10
Original file line numberDiff line numberDiff line change
@@ -833,23 +833,36 @@ def filter(self, record):
833833
Determine if a record is loggable by consulting all the filters.
834834
835835
The default is to allow the record to be logged; any filter can veto
836-
this and the record is then dropped. Returns a zero value if a record
837-
is to be dropped, else non-zero.
836+
this by returning a falsy value.
837+
If a filter attached to a handler returns a log record instance,
838+
then that instance is used in place of the original log record in
839+
any further processing of the event by that handler.
840+
If a filter returns any other truthy value, the original log record
841+
is used in any further processing of the event by that handler.
842+
843+
If none of the filters return falsy values, this method returns
844+
a log record.
845+
If any of the filters return a falsy value, this method returns
846+
a falsy value.
838847
839848
.. versionchanged:: 3.2
840849
841850
Allow filters to be just callables.
851+
852+
.. versionchanged:: 3.12
853+
Allow filters to return a LogRecord instead of
854+
modifying it in place.
842855
"""
843-
rv = True
844856
for f in self.filters:
845857
if hasattr(f, 'filter'):
846858
result = f.filter(record)
847859
else:
848860
result = f(record) # assume callable - will raise if not
849861
if not result:
850-
rv = False
851-
break
852-
return rv
862+
return False
863+
if isinstance(result, LogRecord):
864+
record = result
865+
return record
853866

854867
#---------------------------------------------------------------------------
855868
# Handler classes and functions
@@ -1001,10 +1014,14 @@ def handle(self, record):
10011014
10021015
Emission depends on filters which may have been added to the handler.
10031016
Wrap the actual emission of the record with acquisition/release of
1004-
the I/O thread lock. Returns whether the filter passed the record for
1005-
emission.
1017+
the I/O thread lock.
1018+
1019+
Returns an instance of the log record that was emitted
1020+
if it passed all filters, otherwise a falsy value is returned.
10061021
"""
10071022
rv = self.filter(record)
1023+
if isinstance(rv, LogRecord):
1024+
record = rv
10081025
if rv:
10091026
self.acquire()
10101027
try:
@@ -1673,8 +1690,14 @@ def handle(self, record):
16731690
This method is used for unpickled records received from a socket, as
16741691
well as those created locally. Logger-level filtering is applied.
16751692
"""
1676-
if (not self.disabled) and self.filter(record):
1677-
self.callHandlers(record)
1693+
if self.disabled:
1694+
return
1695+
maybe_record = self.filter(record)
1696+
if not maybe_record:
1697+
return
1698+
if isinstance(maybe_record, LogRecord):
1699+
record = maybe_record
1700+
self.callHandlers(record)
16781701

16791702
def addHandler(self, hdlr):
16801703
"""

Lib/test/test_logging.py

+45
Original file line numberDiff line numberDiff line change
@@ -468,6 +468,51 @@ def log_at_all_levels(self, logger):
468468
for lvl in LEVEL_RANGE:
469469
logger.log(lvl, self.next_message())
470470

471+
def test_handler_filter_replaces_record(self):
472+
def replace_message(record: logging.LogRecord):
473+
record = copy.copy(record)
474+
record.msg = "new message!"
475+
return record
476+
477+
# Set up a logging hierarchy such that "child" and it's handler
478+
# (and thus `replace_message()`) always get called before
479+
# propagating up to "parent".
480+
# Then we can confirm that `replace_message()` was able to
481+
# replace the log record without having a side effect on
482+
# other loggers or handlers.
483+
parent = logging.getLogger("parent")
484+
child = logging.getLogger("parent.child")
485+
stream_1 = io.StringIO()
486+
stream_2 = io.StringIO()
487+
handler_1 = logging.StreamHandler(stream_1)
488+
handler_2 = logging.StreamHandler(stream_2)
489+
handler_2.addFilter(replace_message)
490+
parent.addHandler(handler_1)
491+
child.addHandler(handler_2)
492+
493+
child.info("original message")
494+
handler_1.flush()
495+
handler_2.flush()
496+
self.assertEqual(stream_1.getvalue(), "original message\n")
497+
self.assertEqual(stream_2.getvalue(), "new message!\n")
498+
499+
def test_logging_filter_replaces_record(self):
500+
records = set()
501+
502+
class RecordingFilter(logging.Filter):
503+
def filter(self, record: logging.LogRecord):
504+
records.add(id(record))
505+
return copy.copy(record)
506+
507+
logger = logging.getLogger("logger")
508+
logger.setLevel(logging.INFO)
509+
logger.addFilter(RecordingFilter())
510+
logger.addFilter(RecordingFilter())
511+
512+
logger.info("msg")
513+
514+
self.assertEqual(2, len(records))
515+
471516
def test_logger_filter(self):
472517
# Filter at logger level.
473518
self.root_logger.setLevel(VERBOSE)
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,3 @@
1+
Allow :mod:`logging` filters to return a :class:`logging.LogRecord` instance
2+
so that filters attached to :class:`logging.Handler`\ s can enrich records without
3+
side effects on other handlers.

0 commit comments

Comments
 (0)