Python logging filter being applied to all handlers when only added to one

52 Views Asked by At

I am adding logging to a Python project, and I wish to log to both terminal and file. To do this I am using a streamHandler and a fileHandler.

To make it easier to quickly differentiate between log levels, I wish to add colour to the levelname for the logs that are output to the terminal, and to achieve this I have added a filter.

However, despite the filter only being applied to the streamHandler, messages in the log file are seeing the colour code applied. How can this be, given the filter is not added to the fileHandler?

Example Code

Note that the filter in this example only includes a format for logging.ERROR, as this will log to both terminal and file. But in reality I have a format for all log levels.

import logging


class ColourLevelNameFilter(logging.Filter):

    FORMATS = {
        logging.ERROR: '\x1b[031m' + '{0}' + '\x1b[0m',
    }

    def filter(self, record):
        
        levelname_format = self.FORMATS.get(record.levelno)
        record.levelname = levelname_format.format(record.levelname)

        return True
    
def main():

    time_format = '%Y-%m-%d %H:%M:%S'
    text_format = '%(asctime)s %(levelname)s => %(message)s'
    formatter = logging.Formatter(text_format, time_format)

    stream_handler = logging.StreamHandler()
    stream_handler.setFormatter(formatter)
    stream_handler.setLevel(logging.INFO)
    stream_handler.addFilter(ColourLevelNameFilter())

    log_file = 'test-error.log'
    file_handler = logging.FileHandler(log_file, 'w')
    file_handler.setFormatter(formatter)
    file_handler.setLevel(logging.WARNING)
        
    logger = logging.getLogger('my-app')
    logger.setLevel(logging.INFO)
    logger.addHandler(stream_handler)
    logger.addHandler(file_handler)

    logger.error('Testing logging of error.')

if __name__ == '__main__':
    main()

1

There are 1 best solutions below

2
David Gard On BEST ANSWER

As mentioned in the comments to my question, a Filter is the wrong thing to use in this instance, so I ended up using a customer formatter and rather than editing the record, I amended the text that is returned by the formatter.

Update: Update msg.replace to find and replace f'{record.asctime} {record.levelname}', minimising the risk of spurious coloured words appearing in the log output (see comments).

import logging

class ColourFormatter(logging.Formatter):

    FORMATS = {
        logging.ERROR: '\x1b[031m' + '{0}' + '\x1b[0m',
    }
    
    def format(self, record: logging.LogRecord) -> str:

        levelname_format = self.FORMATS.get(record.levelno)
        colour_levelname = levelname_format.format(record.levelname)
        msg = super().format(record)
        msg = msg.replace(record.levelname, colour_levelname)

        levelname_format = self.FORMATS.get(record.levelno)
        colour_levelname = levelname_format.format(record.levelname)
        msg = msg.replace(f'{record.asctime} {record.levelname}', f'{record.asctime} {colour_levelname}')
    
        return msg

    
def main():

    time_format = '%Y-%m-%d %H:%M:%S'
    text_format = '%(asctime)s %(levelname)s => %(message)s'
    formatter_stream = ColourFormatter(text_format, time_format)
    formatter_file = logging.Formatter(text_format, time_format)

    stream_handler = logging.StreamHandler()
    stream_handler.setFormatter(formatter_stream)
    stream_handler.setLevel(logging.INFO)

    log_file = 'test-error.log'
    file_handler = logging.FileHandler(log_file, 'w')
    file_handler.setFormatter(formatter_file)
    file_handler.setLevel(logging.WARNING)
        
    logger = logging.getLogger('my-app')
    logger.setLevel(logging.INFO)
    logger.addHandler(stream_handler)
    logger.addHandler(file_handler)

    logger.error('Testing logging of error.')

if __name__ == '__main__':
    main()