Como adicionar um nível de log personalizado ao recurso de registro do Python

Eu gostaria de ter o nível de log TRACE (5) para meu aplicativo, pois não acho que debug()seja suficiente. Além disso, log(5, msg)não é o que eu quero. Como posso adicionar um nível de log personalizado a um logger Python?

Tenho um mylogger.pycom o seguinte conteúdo:

import logging

@property
def log(obj):
    myLogger = logging.getLogger(obj.__class__.__name__)
    return myLogger

No meu código, eu o uso da seguinte maneira:

class ExampleClass(object):
    from mylogger import log

    def __init__(self):
        '''The constructor with the logger'''
        self.log.debug("Init runs")

Agora eu gostaria de ligar self.log.trace("foo bar")

Agradeço antecipadamente por sua ajuda.

Editar (8 de dezembro de 2016): Eu mudei a resposta aceita para pfa's que é, IMHO, uma excelente solução baseada na muito boa proposta de Eric S.

@Eric S.

A resposta de Eric S. é excelente, mas aprendi por experimentos que isso sempre fará com que as mensagens registradas no novo nível de depuração sejam impressas - independentemente do nível de log definido. Portanto, se você fizer um novo número de nível 9, se você ligar setLevel(50), as mensagens de nível inferior serão impressas erroneamente.

Para evitar que isso aconteça, você precisa de outra linha dentro da função "debugv" para verificar se o nível de registro em questão está realmente ativado.

Exemplo corrigido que verifica se o nível de registro está habilitado:

import logging
DEBUG_LEVELV_NUM = 9 
logging.addLevelName(DEBUG_LEVELV_NUM, "DEBUGV")
def debugv(self, message, *args, **kws):
    if self.isEnabledFor(DEBUG_LEVELV_NUM):
        # Yes, logger takes its '*args' as 'args'.
        self._log(DEBUG_LEVELV_NUM, message, args, **kws) 
logging.Logger.debugv = debugv

Se você olhar o código para class Loggeremlogging.__init__.py para Python 2.7, isso é o que todas as funções de log padrão fazer (.critical, .debug, etc.).

Aparentemente, não posso postar respostas às respostas dos outros por falta de reputação ... espero que Eric atualize sua postagem se vir isso. =)

Peguei a resposta "evitar ver lambda" e tive que modificar onde o log_at_my_log_level estava sendo adicionado. Eu também vi o problema que Paul fez "Eu não acho que isso funciona. Você não precisa do logger como o primeiro argumento em log_at_my_log_level?" Isso funcionou para mim

import logging
DEBUG_LEVELV_NUM = 9 
logging.addLevelName(DEBUG_LEVELV_NUM, "DEBUGV")
def debugv(self, message, *args, **kws):
    # Yes, logger takes its '*args' as 'args'.
    self._log(DEBUG_LEVELV_NUM, message, args, **kws) 
logging.Logger.debugv = debugv

Combinando todas as respostas existentes com um monte de experiência de uso, acho que vim com uma lista de todas as coisas que precisam ser feitas para garantir o uso totalmente contínuo do novo nível. As etapas abaixo pressupõem que você está adicionando um novo nível TRACEcom valor logging.DEBUG - 5 == 5:

1. logging.addLevelName(logging.DEBUG - 5, 'TRACE') precisa ser chamado para obter o novo nível registrado internamente para que possa ser referenciado pelo nome.
2. O novo nível precisa ser adicionado como um atributo a loggingsi para a consistência: logging.TRACE = logging.DEBUG - 5.
3. Um método chamado traceprecisa ser adicionado ao loggingmódulo. Ele deve se comportar exatamente como debug, info, etc.
4. Um método chamado traceprecisa ser adicionado à classe de logger configurada atualmente. Como isso não é 100% garantido logging.Logger, use em seu logging.getLoggerClass()lugar.

Todas as etapas são ilustradas no método abaixo:

def addLoggingLevel(levelName, levelNum, methodName=None):
    """
    Comprehensively adds a new logging level to the `logging` module and the
    currently configured logging class.

    `levelName` becomes an attribute of the `logging` module with the value
    `levelNum`. `methodName` becomes a convenience method for both `logging`
    itself and the class returned by `logging.getLoggerClass()` (usually just
    `logging.Logger`). If `methodName` is not specified, `levelName.lower()` is
    used.

    To avoid accidental clobberings of existing attributes, this method will
    raise an `AttributeError` if the level name is already an attribute of the
    `logging` module or if the method name is already present 

    Example
    -------
    >>> addLoggingLevel('TRACE', logging.DEBUG - 5)
    >>> logging.getLogger(__name__).setLevel("TRACE")
    >>> logging.getLogger(__name__).trace('that worked')
    >>> logging.trace('so did this')
    >>> logging.TRACE
    5

    """
    if not methodName:
        methodName = levelName.lower()

    if hasattr(logging, levelName):
       raise AttributeError('{} already defined in logging module'.format(levelName))
    if hasattr(logging, methodName):
       raise AttributeError('{} already defined in logging module'.format(methodName))
    if hasattr(logging.getLoggerClass(), methodName):
       raise AttributeError('{} already defined in logger class'.format(methodName))

    # This method was inspired by the answers to Stack Overflow post
    # http://stackoverflow.com/q/2183233/2988730, especially
    # http://stackoverflow.com/a/13638084/2988730
    def logForLevel(self, message, *args, **kwargs):
        if self.isEnabledFor(levelNum):
            self._log(levelNum, message, args, **kwargs)
    def logToRoot(message, *args, **kwargs):
        logging.log(levelNum, message, *args, **kwargs)

    logging.addLevelName(levelNum, levelName)
    setattr(logging, levelName, levelNum)
    setattr(logging.getLoggerClass(), methodName, logForLevel)
    setattr(logging, methodName, logToRoot)

Essa questão é um tanto antiga, mas eu apenas tratei do mesmo assunto e encontrei uma forma semelhante às já mencionadas que me parece um pouco mais limpa. Isso foi testado no 3.4, então não tenho certeza se os métodos usados ​​existem em versões mais antigas:

from logging import getLoggerClass, addLevelName, setLoggerClass, NOTSET

VERBOSE = 5

class MyLogger(getLoggerClass()):
    def __init__(self, name, level=NOTSET):
        super().__init__(name, level)

        addLevelName(VERBOSE, "VERBOSE")

    def verbose(self, msg, *args, **kwargs):
        if self.isEnabledFor(VERBOSE):
            self._log(VERBOSE, msg, args, **kwargs)

setLoggerClass(MyLogger)

Quem iniciou a má prática de usar métodos internos ( self._log) e por que cada resposta é baseada nisso ?! A solução pythônica seria usar em self.logvez disso, para que você não tenha que mexer com qualquer coisa interna:

import logging

SUBDEBUG = 5
logging.addLevelName(SUBDEBUG, 'SUBDEBUG')

def subdebug(self, message, *args, **kws):
    self.log(SUBDEBUG, message, *args, **kws) 
logging.Logger.subdebug = subdebug

logging.basicConfig()
l = logging.getLogger()
l.setLevel(SUBDEBUG)
l.subdebug('test')
l.setLevel(logging.DEBUG)
l.subdebug('test')

Acho mais fácil criar um novo atributo para o objeto logger que passa a função log (). Acho que o módulo logger fornece o addLevelName () e o log () por esse motivo. Portanto, nenhuma subclasse ou novo método é necessário.

import logging

@property
def log(obj):
    logging.addLevelName(5, 'TRACE')
    myLogger = logging.getLogger(obj.__class__.__name__)
    setattr(myLogger, 'trace', lambda *args: myLogger.log(5, *args))
    return myLogger

agora

mylogger.trace('This is a trace message')

deve funcionar como esperado.

Embora já tenhamos muitas respostas corretas, o seguinte é, na minha opinião, mais pitônico:

import logging

from functools import partial, partialmethod

logging.TRACE = 5
logging.addLevelName(logging.TRACE, 'TRACE')
logging.Logger.trace = partialmethod(logging.Logger.log, logging.TRACE)
logging.trace = partial(logging.log, logging.TRACE)

Se você deseja usar mypyem seu código, é recomendado adicionar # type: ignorepara suprimir avisos de adição de atributo.

Acho que você terá que criar uma subclasse da Loggerclasse e adicionar um método chamado traceque basicamente chama Logger.logcom um nível inferior a DEBUG. Não tentei fazer isso, mas é o que os documentos indicam .

Dicas para criar um registrador personalizado:

1. Não use _log, use log(você não precisa verificar isEnabledFor)
2. o módulo de registro deve ser aquele que cria a instância do registrador personalizado, já que ele faz alguma mágica getLogger, então você precisará definir a classe viasetLoggerClass
3. Você não precisa definir __init__para o logger, classe se você não estiver armazenando nada

# Lower than debug which is 10
TRACE = 5
class MyLogger(logging.Logger):
    def trace(self, msg, *args, **kwargs):
        self.log(TRACE, msg, *args, **kwargs)

Ao chamar este registrador, use setLoggerClass(MyLogger)para torná-lo o registrador padrão dogetLogger

logging.setLoggerClass(MyLogger)
log = logging.getLogger(__name__)
# ...
log.trace("something specific")

Você precisará setFormatter, setHandlere setLevel(TRACE)na handlere sobre alog própria para realmente se Este traço de baixo nível

Isso funcionou para mim:

import logging
logging.basicConfig(
    format='  %(levelname)-8.8s %(funcName)s: %(message)s',
)
logging.NOTE = 32  # positive yet important
logging.addLevelName(logging.NOTE, 'NOTE')      # new level
logging.addLevelName(logging.CRITICAL, 'FATAL') # rename existing

log = logging.getLogger(__name__)
log.note = lambda msg, *args: log._log(logging.NOTE, msg, args)
log.note('school\'s out for summer! %s', 'dude')
log.fatal('file not found.')

O problema lambda / funcName foi corrigido com logger._log conforme @marqueed apontado. Acho que usar lambda parece um pouco mais limpo, mas a desvantagem é que ele não aceita argumentos de palavra-chave. Eu nunca usei isso, então não é nada demais.

  Configuração NOTA: a escola acabou para o verão! cara
  Configuração FATAL: arquivo não encontrado.

Na minha experiência, esta é a solução completa para o problema da operação ... para evitar ver "lambda" como a função na qual a mensagem é emitida, vá mais fundo:

MY_LEVEL_NUM = 25
logging.addLevelName(MY_LEVEL_NUM, "MY_LEVEL_NAME")
def log_at_my_log_level(self, message, *args, **kws):
    # Yes, logger takes its '*args' as 'args'.
    self._log(MY_LEVEL_NUM, message, args, **kws)
logger.log_at_my_log_level = log_at_my_log_level

Nunca tentei trabalhar com uma classe de logger autônoma, mas acho que a ideia básica é a mesma (use _log).

Adição ao exemplo do Mad Physicists para obter o nome do arquivo e o número da linha corretos:

def logToRoot(message, *args, **kwargs):
    if logging.root.isEnabledFor(levelNum):
        logging.root._log(levelNum, message, args, **kwargs)

com base na resposta fixada, escrevi um pequeno método que cria automaticamente novos níveis de registro

def set_custom_logging_levels(config={}):
    """
        Assign custom levels for logging
            config: is a dict, like
            {
                'EVENT_NAME': EVENT_LEVEL_NUM,
            }
        EVENT_LEVEL_NUM can't be like already has logging module
        logging.DEBUG       = 10
        logging.INFO        = 20
        logging.WARNING     = 30
        logging.ERROR       = 40
        logging.CRITICAL    = 50
    """
    assert isinstance(config, dict), "Configuration must be a dict"

    def get_level_func(level_name, level_num):
        def _blank(self, message, *args, **kws):
            if self.isEnabledFor(level_num):
                # Yes, logger takes its '*args' as 'args'.
                self._log(level_num, message, args, **kws) 
        _blank.__name__ = level_name.lower()
        return _blank

    for level_name, level_num in config.items():
        logging.addLevelName(level_num, level_name.upper())
        setattr(logging.Logger, level_name.lower(), get_level_func(level_name, level_num))

config pode funcionar assim:

new_log_levels = {
    # level_num is in logging.INFO section, that's why it 21, 22, etc..
    "FOO":      21,
    "BAR":      22,
}

Como alternativa para adicionar um método extra à classe Logger, eu recomendaria usar o Logger.log(level, msg)método.

import logging

TRACE = 5
logging.addLevelName(TRACE, 'TRACE')
FORMAT = '%(levelname)s:%(name)s:%(lineno)d:%(message)s'


logging.basicConfig(format=FORMAT)
l = logging.getLogger()
l.setLevel(TRACE)
l.log(TRACE, 'trace message')
l.setLevel(logging.DEBUG)
l.log(TRACE, 'disabled trace message')

Estou confuso; com python 3.5, pelo menos, ele simplesmente funciona:

import logging


TRACE = 5
"""more detail than debug"""

logging.basicConfig()
logging.addLevelName(TRACE,"TRACE")
logger = logging.getLogger('')
logger.debug("n")
logger.setLevel(logging.DEBUG)
logger.debug("y1")
logger.log(TRACE,"n")
logger.setLevel(TRACE)
logger.log(TRACE,"y2")
    

resultado:

DEBUG: root: y1

TRACE: root: y2

Caso alguém queira uma maneira automatizada de adicionar um novo nível de registro ao módulo de registro (ou uma cópia dele) dinamicamente, criei esta função, expandindo a resposta de @pfa:

def add_level(log_name,custom_log_module=None,log_num=None,
                log_call=None,
                   lower_than=None, higher_than=None, same_as=None,
              verbose=True):
    '''
    Function to dynamically add a new log level to a given custom logging module.
    <custom_log_module>: the logging module. If not provided, then a copy of
        <logging> module is used
    <log_name>: the logging level name
    <log_num>: the logging level num. If not provided, then function checks
        <lower_than>,<higher_than> and <same_as>, at the order mentioned.
        One of those three parameters must hold a string of an already existent
        logging level name.
    In case a level is overwritten and <verbose> is True, then a message in WARNING
        level of the custom logging module is established.
    '''
    if custom_log_module is None:
        import imp
        custom_log_module = imp.load_module('custom_log_module',
                                            *imp.find_module('logging'))
    log_name = log_name.upper()
    def cust_log(par, message, *args, **kws):
        # Yes, logger takes its '*args' as 'args'.
        if par.isEnabledFor(log_num):
            par._log(log_num, message, args, **kws)
    available_level_nums = [key for key in custom_log_module._levelNames
                            if isinstance(key,int)]

    available_levels = {key:custom_log_module._levelNames[key]
                             for key in custom_log_module._levelNames
                            if isinstance(key,str)}
    if log_num is None:
        try:
            if lower_than is not None:
                log_num = available_levels[lower_than]-1
            elif higher_than is not None:
                log_num = available_levels[higher_than]+1
            elif same_as is not None:
                log_num = available_levels[higher_than]
            else:
                raise Exception('Infomation about the '+
                                'log_num should be provided')
        except KeyError:
            raise Exception('Non existent logging level name')
    if log_num in available_level_nums and verbose:
        custom_log_module.warn('Changing ' +
                                  custom_log_module._levelNames[log_num] +
                                  ' to '+log_name)
    custom_log_module.addLevelName(log_num, log_name)

    if log_call is None:
        log_call = log_name.lower()

    setattr(custom_log_module.Logger, log_call, cust_log)
    return custom_log_module