R
R
Ruslan2020-12-22 09:09:26
Python
Ruslan, 2020-12-22 09:09:26

Why are logs duplicated when using the logging library?

It is necessary to organize logging for the simplest mail parsing agent, I wrote the following script:

#!/usr/bin/python3 -u

import logging

from logging import config
from time import sleep

LOGGING_CONFIG = {
    'version': 1,
    'disable_existing_loggers': True,
    'formatters': {
        'standard': {
            'format': '[%(asctime)s] %(levelname)s | %(name)s: %(message)s',
            'datefmt': '%Y-%m-%d %H:%M:%S',
        },
    },
    'handlers': {
        'init': {
            'level': 'INFO',
            'formatter': 'standard',
            'class': 'logging.StreamHandler',
            'stream': 'ext://sys.stdout',
        },
        'getmail': {
            'level': 'INFO',
            'formatter': 'standard',
            'class': 'logging.StreamHandler',
            'stream': 'ext://sys.stdout',
        },
        'parse': {
            'level': 'INFO',
            'formatter': 'standard',
            'class': 'logging.StreamHandler',
            'stream': 'ext://sys.stdout',
        },
    },
    'loggers': {
        '': {
            'level': 'NOTSET',
            'handlers': ['init', 'getmail', 'parse'],
            'propagate': 1,
        }
    },
}

def agent_getmail():
    sleep(1)
    logger = logging.getLogger('getmail')
    logger.debug('getmail - debug')
    logger.info('getmail - info')
    logger.error('getmail - error')
    return True


def agent_parse():
    sleep(1)
    logger = logging.getLogger('parse')
    logger.debug('parse - debug')
    logger.info('parse - info')
    logger.error('parse - error')
    return True

def main():
    logging.config.dictConfig(LOGGING_CONFIG)

    logger = logging.getLogger('init')
    logger.debug('init - debug')
    logger.info('init - info')
    logger.error('init - error')
    agent_getmail()
    agent_parse()

if __name__ == "__main__":
    main()

At startup, I get duplicate messages for the same number of handlers:
[2020-12-22 12:05:33] INFO | init: init - info
[2020-12-22 12:05:33] INFO | init: init - info
[2020-12-22 12:05:33] INFO | init: init - info
[2020-12-22 12:05:33] ERROR | init: init - error
[2020-12-22 12:05:33] ERROR | init: init - error
[2020-12-22 12:05:33] ERROR | init: init - error
[2020-12-22 12:05:34] INFO | getmail: getmail - info
[2020-12-22 12:05:34] INFO | getmail: getmail - info
[2020-12-22 12:05:34] INFO | getmail: getmail - info
[2020-12-22 12:05:34] ERROR | getmail: getmail - error
[2020-12-22 12:05:34] ERROR | getmail: getmail - error
[2020-12-22 12:05:34] ERROR | getmail: getmail - error
[2020-12-22 12:05:35] INFO | parse: parse - info
[2020-12-22 12:05:35] INFO | parse: parse - info
[2020-12-22 12:05:35] INFO | parse: parse - info
[2020-12-22 12:05:35] ERROR | parse: parse - error
[2020-12-22 12:05:35] ERROR | parse: parse - error
[2020-12-22 12:05:35] ERROR | parse: parse - error


What did I incorrectly specify in the config? Did everything like manu.

Answer the question

In order to leave comments, you need to log in

1 answer(s)
S
Sergey Pankov, 2020-12-22
@Tiasar

So you, judging by the config, this is exactly what you want. In fact, you have one logger that eats everything and passes it indiscriminately to three handlers.
You are confused about the names. Handler name does not filter logs. You create named loggers in code, but you don't filter by those names anywhere.
For clarity and transparency, I recommend naming handlers in the config with the "handler_" prefix or something like that. So that it would not be tempting to make a mistake in the names. Explicit is better than implicit
You need to make three loggers in the config, each of which will filter its logs and give it to its own handler.
Yes, it looks like you misunderstood the essence of handlers.
Loggers filter messages, handlers process them.
In your case, one handler was enough. A few are needed in case, in addition to stdout, some logs would need to be sent by mail, some should be formatted in a special way and shoved into a separate file (for example, important errors), some should be suppressed and not displayed anywhere, some should be sent via a telegram bot to a chat.

LOGGING_CONFIG = {
    'version': 1,
    'disable_existing_loggers': True,
    'formatters': {
        'standard': {
            'format': '[%(asctime)s] %(levelname)s | %(name)s: %(message)s',
            'datefmt': '%Y-%m-%d %H:%M:%S',
        },
    },
    'handlers': {
        'std': {
            # 'level': 'INFO',
            'formatter': 'standard',
            'class': 'logging.StreamHandler',
            'stream': 'ext://sys.stdout',
        },
    },
    'loggers': {
        'init': {
            'level': 'DEBUG',
            'handlers': ['std'],
            'propagate': 1,
        },
        'parse': {
            'level': 'DEBUG',
            'handlers': ['std'],
            'propagate': 1,
        },
        'getmail': {
            'level': 'DEBUG',
            'handlers': ['std'],
            'propagate': 1,
        },
    },
}

Didn't find what you were looking for?

Ask your question

Ask a Question

731 491 924 answers to any question