Saída de registro duplicada ao usar o módulo de registro Python

105

Estou usando o logger python. O seguinte é meu código:

import os
import time
import datetime
import logging
class Logger :
   def myLogger(self):
      logger = logging.getLogger('ProvisioningPython')
      logger.setLevel(logging.DEBUG)
      now = datetime.datetime.now()
      handler=logging.FileHandler('/root/credentials/Logs/ProvisioningPython'+ now.strftime("%Y-%m-%d") +'.log')
      formatter = logging.Formatter('%(asctime)s %(levelname)s %(message)s')
      handler.setFormatter(formatter)
      logger.addHandler(handler)
      return logger

O problema que tenho é que obtenho várias entradas no arquivo de log para cada logger.infochamada. Como posso resolver isso?

user865438
fonte
Funciona para mim. Python 3.2 e Windows XP.
Zuljin
2
Tem certeza de que não cria várias instâncias de logger?
Gandi
Sim. em arquivo diferente, estou tomando uma nova instância, como fizemos em projetos Java. Por favor, me especifique se isso está criando problema ou não.
user865438

Respostas:

94

O logging.getLogger()já é um singleton. ( Documentação )

O problema é que toda vez que você chama myLogger(), ele está adicionando outro manipulador à instância, o que causa os logs duplicados.

Talvez algo assim?

import os
import time
import datetime
import logging

loggers = {}

def myLogger(name):
    global loggers

    if loggers.get(name):
        return loggers.get(name)
    else:
        logger = logging.getLogger(name)
        logger.setLevel(logging.DEBUG)
        now = datetime.datetime.now()
        handler = logging.FileHandler(
            '/root/credentials/Logs/ProvisioningPython' 
            + now.strftime("%Y-%m-%d") 
            + '.log')
        formatter = logging.Formatter('%(asctime)s %(levelname)s %(message)s')
        handler.setFormatter(formatter)
        logger.addHandler(handler)
        loggers[name] = logger

        return logger
Werner Smit
fonte
3
Eu acho que você deveria ter loggers.update (dict ((name, logger))) em vez disso.
acrofobia de
por que loggers.update(dict(name=logger))? não é loggers[name] = loggermais simples?
Ryan J McCall
@RyanJMcCall Na época, era a convenção de codificação que eu usava. Mas ao revisar o código como ele está agora, vejo que está quebrado. loggers.update(dict(name=logger))criará um dicionário com uma única chave chamada namee atualizará continuamente essa mesma chave. Estou surpreso que ninguém não tenha mencionado isso antes, pois este código está bastante quebrado :) Fará as alterações necessárias.
Werner Smit
Vejo que @acrophobia estava se esquivando disso há muito tempo. Obrigado.
Werner Smit
o loggersdicionário global não é redundante com logging.getLogger? já que você realmente deseja apenas evitar adicionar manipuladores extras, parece que você prefere as respostas abaixo que verificam os manipuladores diretamente
partir de
60

Desde o Python 3.2, você pode apenas verificar se os manipuladores já estão presentes e, em caso afirmativo, desmarque-os antes de adicionar novos manipuladores. Isso é muito conveniente durante a depuração e o código inclui a inicialização do registrador

if (logger.hasHandlers()):
    logger.handlers.clear()

logger.addHandler(handler)
rm957377
fonte
Boa resposta, Thx :))
Gavriel Cohen
2
Observe que hasHandlers () retornará true em pytest onde um manipulador foi adicionado ao logger raiz, mesmo se seus manipuladores locais / personalizados ainda não tiverem sido adicionados. O len (logger.handlers) (de acordo com a resposta de Guillaume) retornará 0 neste caso, então pode ser uma opção melhor.
Grant
Esta é a solução real que eu estava procurando.
XCanG
45
import datetime
import logging
class Logger :
    def myLogger(self):
       logger=logging.getLogger('ProvisioningPython')
       if not len(logger.handlers):
          logger.setLevel(logging.DEBUG)
          now = datetime.datetime.now()
          handler=logging.FileHandler('/root/credentials/Logs/ProvisioningPython'+ now.strftime("%Y-%m-%d") +'.log')
          formatter = logging.Formatter('%(asctime)s %(levelname)s %(message)s')
          handler.setFormatter(formatter)
          logger.addHandler(handler)
        return logger

fez o truque para mim

usando python 2.7

Guillaume Cisco
fonte
1
Isso funciona mesmo quando o módulo é recarregado (o que não é o caso das outras respostas)
yco
3
Obrigado pela dica, BTW para verificar se uma lista está vazia ou não, você não precisa usar o operador "len" que você pode usar diretamente se my_list: ..
rkachach 01 de
26

Já usei o loggercomo Singleton e verifiquei if not len(logger.handlers), mas ainda tenho duplicatas : Era a saída formatada, seguida da não formatada.

Solução no meu caso: logger.propagate = False

Créditos a esta resposta e aos documentos .

Sr. B.
fonte
1
Eu descobri que o registro duplicado era do RootLogger e meu StreamHandler, mas não consegui resolver o problema (mantendo meu formatador no StreamHandler) até fazer isso.
Xander YzWich
10

Você está ligando Logger.myLogger()mais de uma vez. Armazene a instância do logger que retorna em algum lugar e reutilize- a .

Também esteja ciente de que, se você registrar antes de adicionar qualquer manipulador, um padrão StreamHandler(sys.stderr)será criado.

Matt Joiner
fonte
Na verdade, estou tentando acessar a instância do logger como usamos em java. Mas não sei se é necessário criar uma instância apenas uma vez para um projeto inteiro ou não.
user865438
1
@ user865483: Apenas uma vez. Todos os loggers de biblioteca padrão são singletons.
Matt Joiner
5

Isso é um acréscimo à resposta de @ rm957377, mas com uma explicação de por que isso está acontecendo . Quando você executa uma função lambda no AWS, eles chamam sua função de dentro de uma instância de agrupamento que permanece ativa para várias chamadas. Ou seja, se você chamar addHandler()dentro do código de sua função, ele continuará a adicionar manipuladores duplicados ao singleton de registro sempre que a função for executada. O singleton de registro persiste por meio de várias chamadas de sua função lambda.

Para resolver isso, você pode limpar seus manipuladores antes de defini-los por meio de:

logging.getLogger().handlers.clear()
logging.getLogger().addHandler(...)
Chad Befus
fonte
De alguma forma, no meu caso, os manipuladores de logger são adicionados no evento de .info()plantão que eu não entendo.
Evgeny
4

Seu logger deve funcionar como singleton. Você não deve criá-lo mais de uma vez. Aqui está um exemplo de como pode ser:

import os
import time
import datetime
import logging
class Logger :
    logger = None
    def myLogger(self):
        if None == self.logger:
            self.logger=logging.getLogger('ProvisioningPython')
            self.logger.setLevel(logging.DEBUG)
            now = datetime.datetime.now()
            handler=logging.FileHandler('ProvisioningPython'+ now.strftime("%Y-%m-%d") +'.log')
            formatter = logging.Formatter('%(asctime)s %(levelname)s %(message)s')
            handler.setFormatter(formatter)
            self.logger.addHandler(handler)
        return self.logger

s = Logger()
m = s.myLogger()
m2 = s.myLogger()
m.info("Info1")
m2.info("info2")
Zuljin
fonte
e, novamente, se vou usar a instância diferente em um arquivo diferente. Suponha que no arquivo 1 s = Logger () m = s.myLogger () e no arquivo 2 s = Logger () funcionará ou não m2 = s.myLogger ()
usuário865438
Ainda estou recebendo uma cópia do mesmo registro várias vezes. Tenho uma dúvida aqui se o log de thread interno imprime mais de um ou não. Por favor, me ajude nisso.
user865438
1
@ user865438, não precisamos nos preocupar em tornar a implementação um singleton (ela já é). Para fazer login em submódulos, siga o link oficial do Livro de receitas de registro . Basicamente, você precisa seguir a hierarquia de nomenclatura ao nomear os loggers e ele cuida do resto.
narayan
4

A implementação do logger já é um singleton.

Várias chamadas para logging.getLogger ('someLogger') retornam uma referência ao mesmo objeto logger. Isso é verdadeiro não apenas dentro do mesmo módulo, mas também entre os módulos, desde que esteja no mesmo processo do interpretador Python. É verdade para referências ao mesmo objeto; além disso, o código do aplicativo pode definir e configurar um criador de logs pai em um módulo e criar (mas não configurar) um criador de logs filho em um módulo separado, e todas as chamadas do registrador para o filho passarão para o pai. Aqui está um módulo principal

Fonte - usando o registro em vários módulos

Portanto, a maneira como você deve utilizar isso é -

Vamos supor que criamos e configuramos um logger chamado 'main_logger' no módulo principal (que simplesmente configura o logger, não retorna nada).

# get the logger instance
logger = logging.getLogger("main_logger")
# configuration follows
...

Agora em um submódulo, se criarmos um registrador filho seguindo a hierarquia de nomenclatura 'main_logger.sub_module_logger' , não precisamos configurá-lo no submódulo. Apenas a criação do logger seguindo a hierarquia de nomes é suficiente.

# get the logger instance
logger = logging.getLogger("main_logger.sub_module_logger")
# no configuration needed
# it inherits the configuration from the parent logger
...

E também não adicionará um manipulador duplicado.

Veja esta pergunta para uma resposta um pouco mais detalhada.

Narayan
fonte
1
redefinir manipuladores após getLogger parece funcionar para mim: logger = logging.getLogger('my_logger') ; logger.handlers = [logger.handlers[0], ]
radtek
2

A saída do registrador duplo (ou triplo ou ..- com base no número de recarregamentos) também pode ocorrer quando você recarregar seu módulo via importlib.reload(pelo mesmo motivo explicado na resposta aceita). Estou adicionando esta resposta apenas para uma referência futura, pois demorei um pouco para descobrir por que minha saída é duplicada (tripla).

rkuska
fonte
1

Uma solução simples é como

logger.handlers[:] = [handler]

Dessa forma, você evita anexar um novo manipulador à lista subjacente "manipuladores".

aihex
fonte
1

Para a maioria dos casos, quando isso acontece, é necessário chamar logger.getLogger () apenas uma vez por módulo. Se você tem várias aulas como eu, eu poderia chamar assim:

LOGGER = logger.getLogger(__name__)

class MyClass1:
    log = LOGGER
    def __init__(self):
        self.log.debug('class 1 initialized')

class MyClass2:
    log = LOGGER
    def __init__(self):
        self.log.debug('class 2 initialized')

Ambos terão seu próprio nome de pacote completo e método onde registrados.

Harlin
fonte
0

Você pode obter uma lista de todos os manipuladores para o logger específico, então você pode fazer algo assim

logger = logging.getLogger(logger_name)
handler_installed = False
for handler in logger:
    # Here your condition to check for handler presence
    if isinstance(handler, logging.FileHandler) and handler.baseFilename == log_filename:
        handler_installed = True
        break

if not handler_installed:
    logger.addHandler(your_handler)

No exemplo acima, verificamos se o manipulador de um arquivo especificado já está conectado ao logger, mas ter acesso à lista de todos os manipuladores dá a você a capacidade de decidir em quais critérios você deve adicionar outro manipulador ou não.

Mais procurados
fonte
0

Tive esse problema hoje. Como minhas funções eram @staticmethod, as sugestões acima foram resolvidas com random ().

Parecido com:

import random

logger = logging.getLogger('ProvisioningPython.{}'.format(random.random()))
Pacman
fonte
-1
from logging.handlers import RotatingFileHandler
import logging
import datetime

# stores all the existing loggers
loggers = {}

def get_logger(name):

    # if a logger exists, return that logger, else create a new one
    global loggers
    if name in loggers.keys():
        return loggers[name]
    else:
        logger = logging.getLogger(name)
        logger.setLevel(logging.DEBUG)
        now = datetime.datetime.now()
        handler = logging.FileHandler(
            'path_of_your_log_file' 
            + now.strftime("%Y-%m-%d") 
            + '.log')
        formatter = logging.Formatter('%(asctime)s %(levelname)s %(message)s')
        handler.setFormatter(formatter)
        logger.addHandler(handler)
        loggers.update(dict(name=logger))
        return logger
Avinash Kumar
fonte
Adicione uma explicação para tornar esta resposta mais valiosa para uso a longo prazo.
Aminah Nuraini de