Why doesn't filter attached to the root logger

Question

From paragraph 15.7.4 of the python logging documentation:

Note that filters attached to handlers are consulted whenever an event is emitted by the handler, whereas filters attached to loggers are consulted whenever an event is logged to the handler (using debug(), info(), etc.) This means that events which have been generated by descendant loggers will not be filtered by a logger’s filter setting, unless the filter has also been applied to those descendant loggers.

I don't understand this design decision. Would it not make more sense for the root logger's filter to be applied to the descendant loggers as well?

Answer 1

Think about it this way. Loggers are like the drain-pipes out of your home. A filter on a logger prevents you from dumping stuff into the sewer, it doesn't filter the whole sewer. Where you are in the flow (upstream, downstream) doesn't change this behavior.

Handlers are the pipes. Pipes accumulate the upstream flow. The default pipe is "skip, pass to parent". If you want to affect the upstream flow, you need to put a filter no the pipe (handler). If you look at the logging flowchart, it should be possible to add a NullHandler (no formatting or output) that filters then propagates the message.

This is the behavior you desire.

Answer 2

I agree: this is a counter-intuitive design decision, IMHO.

The easiest solution is to attach your filter to every possible handler. For example, say you have a console handler, a mail handler and a database handler, you should attach your "root" filter to each and every one of them. :-/

import logging
import logging.config

class MyRootFilter(logging.Filter):
    def filter(self, record):
        # filter out log messages that include "secret"
        if "secret" in record.msg:
            return False
        else:
            return True

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'filters': {
        'my_root_filter': {
            '()': MyRootFilter,
        },
    },
    'handlers': {
        'stderr': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'filters': ['my_root_filter'],
        },
        'mail_admins': {
            'level': 'ERROR',
            'class': 'some.kind.of.EmailHandler',
            'filters': ['my_root_filter'],
        },
        'database': {
            'level': 'ERROR',
            'class': 'some.kind.of.DatabaseHandler',
            'filters': ['my_root_filter'],
        },
    },
    'loggers': {
        'some.sub.project': {
            'handlers': ['stderr'],
            'level': 'ERROR',
        },
    },
}

logging.config.dictConfig(LOGGING)
logging.getLogger("some.sub.project").error("hello")        # logs 'hello'
logging.getLogger("some.sub.project").error("hello secret") # filtered out!  :-)

If there are a lot of handlers, you may want to attach your root filter to every handler programmatically rather than manually. I recommend you do this directly on your configuration dictionary (or file, depending on how you load your logging configuration), rather than doing this after the configuration has been loaded, because there seems to be no documented way to get the list of all handlers. I found logger.handlers and logging._handlers, but since they are not documented, they may break in the future. Plus, there's no guarantee that they are thread-safe.

The previous solution (attaching your root filter to every handler directly in the configuration, before it gets loaded) assumes that you have control over the logging configuration before it's loaded, and also that no handler will be added dynamically (using Logger#addHandler()). If this is not true, then you may want to monkey-patch the logging module (good luck with that!).

edit

I took a shot at monkey patching Logger#addHandler, just for fun. It actually works fine and simplifies the configuration, but I'm not sure I would recommend doing this (I hate monkey-patching, it makes it very hard to debug when something goes wrong). Use at your own risks...

import logging
import logging.config

class MyRootFilter(logging.Filter):
   [...] # same as above

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'stderr': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            # it's shorter: there's no explicit reference to the root filter
        },
        [...]  # other handlers go here
    },
    'loggers': {
        'some.sub.project': {
            'handlers': ['stderr'],
            'level': 'ERROR',
        },
    },
}

def monkey_patched_addHandler(self, handler):
    result = self.old_addHandler(handler)
    self.addFilter(MyRootFilter())
    return result

logging.Logger.old_addHandler = logging.Logger.addHandler
logging.Logger.addHandler = monkey_patched_addHandler

logging.config.dictConfig(LOGGING)
logging.getLogger("some.sub.project").error("hello")        # logs 'hello'
logging.getLogger("some.sub.project").error("hello secret") # filtered out!  :-)