uso una separar por funcion evaluar caracter cadenas python logging

una - string en python



Lazy Lager mensaje de cadena de evaluaciĆ³n (4)

Estoy usando el módulo de registro de Python estándar en mi aplicación de Python:

import logging logging.basicConfig(level=logging.INFO) logger = logging.getLogger("log") while True: logger.debug(''Stupid log message " + '' ''.join([str(i) for i in range(20)]) ) # Do something

El problema es que aunque el nivel de depuración no está habilitado, ese mensaje de registro estúpido se evalúa en cada iteración de bucle, lo que perjudica gravemente el rendimiento.

¿Hay alguna solución para esto?

En C ++ tenemos el paquete log4cxx que proporciona macros como este:
LOG4CXX_DEBUG(logger, messasage)
Eso efectivamente evalúa

if (log4cxx::debugEnabled(logger)) { log4cxx.log(logger,log4cxx::LOG4CXX_DEBUG, message) }

Pero dado que no hay macros en Python (AFAIK), ¿existe una manera eficiente de hacer el registro?


Como Shane señala, usando

log.debug("Some message: a=%s b=%s", a, b)

... en lugar de esto:

log.debug("Some message: a=%s b=%s" % (a, b))

ahorra tiempo solo al realizar el formateo de cadenas si el mensaje se registra realmente.

Sin embargo, esto no resuelve completamente el problema, ya que es posible que deba preprocesar los valores para formatear en la cadena, como por ejemplo:

log.debug("Some message: a=%s b=%s", foo.get_a(), foo.get_b())

En ese caso, obj.get_a() y obj.get_b() se computarán incluso si no se registra.

Una solución para eso sería usar funciones lambda, pero esto requiere algo de maquinaria adicional:

class lazy_log_debug(object): def __init__(self, func): self.func = func logging.debug("%s", self) def __str__(self): return self.func()

... entonces puede iniciar sesión con lo siguiente:

lazy_log_debug(lambda: "Some message: a=%s b=%s" % (foo.get_a(), foo.get_b()))

En ese caso, la función lambda solo se log.debug si log.debug decide realizar el formateo y, por lo tanto, llama al método __str__ .

Eso sí: la sobrecarga de esa solución puede exceder el beneficio :-) Pero al menos, en teoría, hace que sea posible hacer un registro perfectamente perezoso.


El módulo de registro ya tiene soporte parcial para lo que quiere hacer. Hacer esto:

log.debug("Some message: a=%s b=%s", a, b)

... en lugar de esto:

log.debug("Some message: a=%s b=%s" % (a, b))

El módulo de registro es lo suficientemente inteligente como para no producir el mensaje de registro completo a menos que el mensaje realmente se registre en alguna parte.

Para aplicar esta función a su solicitud específica, puede crear una clase lazyjoin.

class lazyjoin: def __init__(self, s, items): self.s = s self.items = items def __str__(self): return self.s.join(self.items)

Úselo así (tenga en cuenta el uso de una expresión del generador, que se suma a la pereza):

logger.info(''Stupid log message %s'', lazyjoin('' '', (str(i) for i in range(20))))

Aquí hay una demostración que muestra que esto funciona.

>>> import logging >>> logging.basicConfig(level=logging.INFO) >>> logger = logging.getLogger("log") >>> class DoNotStr: ... def __str__(self): ... raise AssertionError("the code should not have called this") ... >>> logger.info(''Message %s'', DoNotStr()) Traceback (most recent call last): ... AssertionError: the code should not have called this >>> logger.debug(''Message %s'', DoNotStr()) >>>

En la demostración, la llamada logger.info () golpeó el error de aserción, mientras que logger.debug () no llegó tan lejos.


Por supuesto, lo siguiente no es tan eficiente como una macro:

if logger.isEnabledFor(logging.DEBUG): logger.debug( ''Stupid log message '' + '' ''.join([str(i) for i in range(20)]) )

pero simple, evalúa de manera perezosa y es 4 veces más rápido que la respuesta aceptada :

class lazyjoin: def __init__(self, s, items): self.s = s self.items = items def __str__(self): return self.s.join(self.items) logger.debug( ''Stupid log message %s'', lazyjoin('' '', (str(i) for i in range(20))) )

Ver benchmark-src para mi configuración.


import logging import time logging.basicConfig(level=logging.INFO) logger = logging.getLogger("log") class Lazy(object): def __init__(self,func): self.func=func def __str__(self): return self.func() logger.debug(Lazy(lambda: time.sleep(20))) logger.info(Lazy(lambda: "Stupid log message " + '' ''.join([str(i) for i in range(20)]))) # INFO:log:Stupid log message 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19

Si ejecuta el script, notará que el primer comando logger.debug no tarda 20 segundos en ejecutarse. Esto muestra que el argumento no se evalúa cuando el nivel de registro está por debajo del nivel establecido.