Logování

Logování se hodí se k debugingu problémů v pokročilých programech, kde si nechceme vystačit jen s print() proměnných. Navíc jeho nastavení není vůbec složité. Můžeme si zvolit, jestli budeme logovat do stderr nebo do některého ze systémových logů, třeba do syslogu.

Základní

Pro logování používám dvě nastavení, jedno jednodužší a druhé pokročilejší. Začnu tím jednodušším. Asi nemá cenu vysvětlovat všechny volby, stačí ho rovnou použít. Na začátku programu vložime direktivy pro logování. Pomocí log.setLevel si navolíme výchozí threshold, od kterého se boudou logy sbírat.

import logging
import logging.handlers

log = logging.getLogger('spam_application')  # zvolime nejake jmeno
formatter = logging.Formatter('%(asctime)s [%(levelname)s] %(funcName)s: %(message)s')
handler = logging.StreamHandler(sys.stdout)  # Default is stderr, takto: logging.StreamHandler()
handler.setFormatter(formatter)
log.addHandler(handler)
log.setLevel(logging.INFO)

Pokud bychom chtěli logovat navíc do souboru, můžeme přidat:

file_handler = logging.FileHandler(filename='tmp.log')
stdout_handler = logging.StreamHandler(sys.stdout)
handlers = [file_handler, stdout_handler]

V samotném programu 'printíme' logy podle severity události, které chceme psát do stdout. Severita logovaní může nabývat hodnot (DEBUG, INFO, WARNING, ERROR, CRITICAL).

log.critical(print('%s' % variable))
log.error(print('%s' % variable))
log.warning(print('%s' % variable))
log.info(print('%s' % variable))
log.debug(print('%s' % variable))

Pokročilejší

Při pokročilejším logování používam konfigurace přímo v programu. Zde je zápis:

def start_log(loglevel = 'INFO'):
    import logging
    import logging.config

    LOGGING_CONFIG = {
        'version': 1,
        'disable_existing_loggers': True,
        'formatters': {
            'standard': {
                'format': '%(asctime)s [%(levelname)s] %(funcName)s: %(message)s'
            },
        },
        'handlers': {
            'default': {
                'level': loglevel,
                'formatter': 'standard',
                'class': 'logging.StreamHandler',
                'stream': 'ext://sys.stdout',  # Default is stderr
            },
        },
        'loggers': {
            '': {  # root logger
                'handlers': ['default'],
                'level': 'WARNING',
                'propagate': False
            },
            'my.packg': {
                'handlers': ['default'],
                'level': 'INFO',
                'propagate': False
            },
            '__main__': {  # if __name__ == '__main__'
                'handlers': ['default'],
                'level': 'DEBUG',
                'propagate': False
            },
        }
    }

    # Run once at startup:
    log = logging.config.dictConfig(LOGGING_CONFIG)

    # Include in each module:
    log = logging.getLogger(__name__)
    log.debug("Logging is configured. Start logging!")

    return(log)

if __name__ == '__main__':
    loglevel = "DEBUG"
    log = start_log(loglevel)

    log.critical(print('%s' % variable))
    log.error(print('%s' % variable))
    log.warning(print('%s' % variable))
    log.info(print('%s' % variable))
    log.debug(print('%s' % variable))

Můžeme nastavit logování jinam než do stdout, dejme tomu, že chceme logovat také do souboru:

def start_log(loglevel = 'DEBUG'):
    import logging               
    import logging.config

    class _ExcludeErrorsFilter(logging.Filter):
        def filter(self, record):
            return record.levelno < 40

    LOGGING_CONFIG = { 
        'version': 1,
        'filters': {
            'exclude_errors': {
                '()': _ExcludeErrorsFilter
            }
        },
        'disable_existing_loggers': True,
        'formatters': { 
            'standard': { 
                'format': '%(asctime)s (%(process)d) [:%(lineno)s]\t| [%(levelname)s] %(message)s'
            },
        },
        'handlers': { 
             'console_stderr': {
                 # Sends log messages with log level ERROR or higher to stderr
                 'class': 'logging.StreamHandler',
                 'level': 'ERROR',
                 'formatter': 'standard',
                 'stream': 'ext://sys.stderr',  # Default is stderr
             },
             'console_stdout': {
                 # Sends log messages with log level lower than ERROR to stdout
                 'class': 'logging.StreamHandler',
                 'level': loglevel,
                 'formatter': 'standard',
                 'filters': ['exclude_errors'],
                 'stream': 'ext://sys.stdout',  # Default is stderr
             },
             'file': {
                 # Sends all log messages to a file
                 'class': 'logging.FileHandler',
                 'level': 'DEBUG',
                 'formatter': 'standard',
                 'filename': 'my.log',
                 'encoding': 'utf8',
             },
        },
        'loggers': { 
            '': {  # root logger
                'handlers': ['console_stderr', 'console_stdout', 'file' ],
                # In general, this should be kept at 'NOTSET'.
                # Otherwise it would interfere with the log levels set for each handler.
                'level': 'NOTSET',
                'propagate': False
            },
        } 
    }

    log = logging.config.dictConfig(LOGGING_CONFIG)
    log = logging.getLogger(__name__)
    log.debug("Logging is configured.")
    return(log)

def whoami():
    log.debug("Starting debug")

def foo():
    log.info("I'm here")
    whoami()
    log.info("I'm back here again")

if __name__ == '__main__':
    loglevel = "DEBUG"
    log = start_log(loglevel)
    foo()