registrador Lazy evaluación cadena de mensaje

Question

estoy usando módulo de registro estándar de Python en mi solicitud de pitón:

 
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 

La cuestión es que, si bien el nivel de depuración no se permite, que el mensaje de registro estúpida es evaluado en cada repetición del bucle, que perjudica el rendimiento.

¿Hay alguna solución para esto?

En C++ tenemos log4cxx paquete que proporciona macros de la siguiente manera:
LOG4CXX_DEBUG(logger, messasage)
que evalúa de manera efectiva a

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

Pero dado que no existen macros en Python (que yo sepa), si hay una manera eficiente para hacer el registro?

Answer 1

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

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 registra 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) 

utilizar de esta manera (nótese el uso de un generador de expresión, añadiendo a la pereza):

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

Aquí es 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 demo, La logger.info() llamada dio en el error de aserción, mientras logger.debug() no llegó tan lejos.

Answer 2

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 la secuencia de comandos, se dará cuenta de la primera logger.debug comando no tiene 20 segundos para ejecutar. Esto muestra que el argumento no se evalúa cuando el nivel de registro está por debajo del nivel establecido.

Answer 3

Como señala Shane, utilizando

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 algún tiempo sólo realizar el formato de cadenas de si el mensaje es en realidad conectado.

esto no resuelve completamente el problema, sin embargo, ya que puede tener para preprocesar los valores formatear en la cadena, tales como:

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á incluso si no se registra.

Una solución a ese sería el uso de las funciones lambda, pero esto requiere un poco 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() 

... a continuación, puede iniciar sesión con el siguiente:

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

En ese caso , se llamará a la función lambda solo si log.debug decide realizar el formateo, llamando al método __str__.

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

Answer 4

Por supuesto, el siguiente no es tan eficiente como un macro:

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

pero simple, evaluates in lazy fashion 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 preparar.