Salida de registro duplicada cuando se usa el módulo de registro de Python

105

Estoy usando Python Logger. El siguiente es mi 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

El problema que tengo es que obtengo varias entradas en el archivo de registro para cada logger.infollamada. ¿Como puedo resolver esto?

usuario865438
fuente
Funciona para mi. Python 3.2 y Windows XP.
Zuljin
2
¿Está seguro de que no crea varias instancias de registrador?
Gandi
Si. en un archivo diferente, estoy tomando una nueva instancia como lo hicimos en los proyectos de Java. Por favor, especifique si eso está creando un problema o no.
user865438

Respuestas:

94

El logging.getLogger()ya es singleton. ( Documentación )

El problema es que cada vez que llama myLogger(), se agrega otro controlador a la instancia, lo que genera registros duplicados.

¿Quizás algo como esto?

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
fuente
3
Creo que deberías tener loggers.update (dict ((name, logger))) en su lugar.
acrofobia
¿Por qué loggers.update(dict(name=logger))? no es loggers[name] = loggermás simple?
Ryan J McCall
@RyanJMcCall En ese momento utilicé la convención de codificación. Pero al revisar el código tal como está ahora, veo que está roto. loggers.update(dict(name=logger))creará un diccionario con una sola clave llamada namey actualizará continuamente esa misma clave. Me sorprende que nadie no haya mencionado esto anteriormente ya que este código está bastante roto :) Hará las modificaciones necesarias.
Werner Smit
Veo que @acrophobia estaba eludiendo esto hace mucho tiempo. Gracias.
Werner Smit
¿No es loggersredundante el diccionario global logging.getLogger? ya que realmente solo desea evitar agregar controladores adicionales, parece que prefiere las respuestas a continuación que verifiquen los controladores directamente
mway
60

Desde Python 3.2, puede verificar si los controladores ya están presentes y, de ser así, borrarlos antes de agregar nuevos controladores. Esto es bastante conveniente al depurar y el código incluye la inicialización de su registrador

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

logger.addHandler(handler)
rm957377
fuente
Buena respuesta, gracias :))
Gavriel Cohen
2
Tenga en cuenta que hasHandlers () devolverá verdadero en pytest donde se haya agregado un controlador al registrador raíz, incluso si sus controladores locales / personalizados aún no se han agregado. El len (logger.handlers) (según la respuesta de Guillaume) devolverá 0 en este caso, por lo que puede ser una mejor opción.
Grant
Esta es la solución real que estaba buscando.
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

me hizo el truco

usando python 2.7

Guillaume Cisco
fuente
1
Esto funciona incluso cuando se recarga el módulo (que no es el caso de las otras respuestas)
yco
3
Gracias por la sugerencia, por cierto, para comprobar si una lista está vacía o no, no es necesario utilizar el operador "len" que puede utilizar directamente si my_list: ..
rkachach
26

Ya usé el loggercomo Singleton y lo verifiqué if not len(logger.handlers), pero aún obtuve duplicados : era la salida formateada, seguida de la sin formato.

Solución en mi caso: logger.propagate = False

Créditos a esta respuesta y a los documentos .

Sr. B.
fuente
1
Me había dado cuenta de que el registro duplicado era de RootLogger y mi StreamHandler, pero no pude resolver el problema (mientras mantenía mi formateador en StreamHandler) hasta que hice esto.
Xander YzWich
10

Estás llamando Logger.myLogger()más de una vez. Almacenar la instancia registrador vuelve en algún lugar y volver a utilizar que .

También tenga en cuenta que si inicia sesión antes de agregar cualquier controlador, StreamHandler(sys.stderr)se creará un controlador predeterminado .

Matt Joiner
fuente
En realidad, estoy tratando de acceder a la instancia del registrador como la usamos en Java, pero no sé si es necesario crear una instancia solo una vez para un proyecto completo o no.
user865438
1
@ user865483: Solo una vez. Todos los registradores de biblioteca estándar son singletons.
Matt Joiner
5

Esta es una adición a la respuesta de @ rm957377 pero con una explicación de por qué sucede esto . Cuando ejecuta una función lambda en AWS, llaman a su función desde dentro de una instancia de envoltura que permanece activa para múltiples llamadas. Es decir, si llama addHandler()dentro del código de su función, continuará agregando controladores duplicados al singleton de registro cada vez que se ejecute la función. El singleton de registro persiste a través de múltiples llamadas de su función lambda.

Para resolver esto, puede borrar sus controladores antes de configurarlos a través de:

logging.getLogger().handlers.clear()
logging.getLogger().addHandler(...)
Chad Befus
fuente
De alguna manera, en mi caso, los controladores del registrador se agregan en el evento de .info()llamada que no entiendo.
Evgeny
4

Su registrador debería funcionar como singleton. No deberías crearlo más de una vez. A continuación se muestra un ejemplo de cómo podría verse:

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
fuente
luego de nuevo si voy a tomar la instancia diferente en un archivo diferente. Supongamos que en el archivo 1 s = Logger () m = s.myLogger () y en el archivo 2 s = Logger () Funcionará o no m2 = s.myLogger ()
user865438
Aún así, recibo una copia del mismo registro varias veces. Tengo una duda aquí si el registro de subprocesos internos imprime más de uno o no. Por favor, ayúdame en esto.
user865438
1
@ user865438, no tenemos que preocuparnos por hacer que la implementación sea un singleton (ya lo es). Para iniciar sesión en submódulos, siga el enlace oficial de Logging Cookbook . Básicamente, debe seguir la jerarquía de nombres al nombrar los registradores y se encarga del resto.
Narayan
4

La implementación de logger ya es un singleton.

Varias llamadas a logging.getLogger ('someLogger') devuelven una referencia al mismo objeto de registrador. Esto es cierto no solo dentro del mismo módulo, sino también entre módulos siempre que esté en el mismo proceso de intérprete de Python. Es cierto para las referencias al mismo objeto; Además, el código de la aplicación puede definir y configurar un registrador padre en un módulo y crear (pero no configurar) un registrador secundario en un módulo separado, y todas las llamadas del registrador al niño pasarán al padre. Aquí hay un módulo principal

Fuente: uso de registro en varios módulos

Entonces, la forma en que debe utilizar esto es:

Supongamos que hemos creado y configurado un registrador llamado 'main_logger' en el módulo principal (que simplemente configura el registrador, no devuelve nada).

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

Ahora en un submódulo, si creamos un registrador secundario siguiendo la jerarquía de nombres 'main_logger.sub_module_logger' , no necesitamos configurarlo en el submódulo. Basta con la creación del registrador siguiendo la jerarquía de nombres.

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

Y tampoco agregará un controlador duplicado.

Consulte esta pregunta para obtener una respuesta un poco más detallada.

narayan
fuente
1
redefinir los controladores después de getLogger parece funcionar para mí: logger = logging.getLogger('my_logger') ; logger.handlers = [logger.handlers[0], ]
radtek
2

La salida del registrador doble (o triple o ..- según el número de recargas) también puede ocurrir cuando recarga su módulo a través de importlib.reload(por la misma razón que se explica en la respuesta aceptada). Estoy agregando esta respuesta solo para una referencia futura, ya que me tomó un tiempo descubrir por qué mi salida está duplicada (triple).

rkuska
fuente
1

Una solución simple es como

logger.handlers[:] = [handler]

De esta forma, evita agregar un nuevo controlador a los "controladores" de la lista subyacente.

aihex
fuente
1

En pocas palabras, para la mayoría de los casos cuando esto sucede, solo es necesario llamar a logger.getLogger () solo una vez por módulo. Si tiene varias clases como yo, podría llamarlo así:

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 tendrán su propio nombre de paquete completo y método donde se registren.

Harlin
fuente
0

Puede obtener una lista de todos los controladores para el registrador en particular, por lo que puede hacer algo como esto

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)

En el ejemplo anterior, verificamos si el controlador de un archivo especificado ya está conectado al registrador, pero tener acceso a la lista de todos los controladores le permite decidir qué criterios debe agregar o no a otro controlador.

Más buscado
fuente
0

Tuve este problema hoy. Dado que mis funciones eran @staticmethod, las sugerencias anteriores se resolvieron con random ().

Mirando algo como:

import random

logger = logging.getLogger('ProvisioningPython.{}'.format(random.random()))
Pacman
fuente
-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
fuente
Agregue una explicación para que esta respuesta sea más valiosa para un uso a largo plazo.
Aminah Nuraini