Registro idiomático de Python: formato de cadena + lista de args vs. formato de cadena en línea - ¿cuál es el preferido?

Question

¿Es ventajoso llamar a funciones de registro con formato de cadena + lista de args frente a formato en línea?

que he visto (y escrito) código de registro que utiliza en línea el formato de cadenas:

logging.warn("%s %s %s" % (arg1, arg2, arg3)) 

y sin embargo yo supongo que es mejor (en cuanto al rendimiento, y más idiomática) a utilizar:

logging.warn("%s %s %s", arg1, arg2, arg3) 

porque la segunda forma evita las operaciones de formateo de cadenas antes de invocar la función de registro. Si el nivel de registro actual filtra el mensaje de registro, no es necesario formatearlo, lo que reduce el tiempo de cálculo y las asignaciones de memoria.

¿Estoy en el camino correcto aquí o me he perdido algo?

Answer 1

En mi humilde opinión, para los mensajes que es muy probable que se muestren, como los dados a error o warn, no hace mucha diferencia.

Para los mensajes que se muestran con menos frecuencia, definitivamente me decantaría por la segunda versión, principalmente por motivos de rendimiento. A menudo doy grandes objetos como un parámetro al info, que implementa un costoso método __str__. Claramente, enviar esto preformateado a info sería un desperdicio de rendimiento.

ACTUALIZACIÓN

acabo de revisar el código fuente del módulo logging y, de hecho, el formato se realiza después de comprobar el nivel de registro. Por ejemplo:

class Logger(Filterer): 
    # snip 
    def debug(self, msg, *args, **kwargs): 
     # snip 
     if self.isenabledfor(debug): 
      self._log(debug, msg, args, **kwargs) 

Se puede observar que msg y args son intacta entre llamar log y comprobar el nivel de registro.

ACTUALIZACIÓN 2

Spired por Levon, quiero añadir algunas pruebas para objetos que tienen un método costoso __str__:

$ python -m timeit -n 1000000 -s "import logging" -s "logger = logging.getLogger('foo')" -s "logger.setLevel(logging.ERROR)" "logger.warn('%s', range(0,100))" 
1000000 loops, best of 3: 1.52 usec per loop 
$ python -m timeit -n 1000000 -s "import logging" -s "logger = logging.getLogger('foo')" -s "logger.setLevel(logging.ERROR)" "logger.warn('%s' % range(0,100))" 
1000000 loops, best of 3: 10.4 usec per loop 

En la práctica, esto podría dar un impulso bastante alto rendimiento.

Answer 2

En caso de que esto sea útil, aquí es una prueba rápida para la sincronización sólo las dos opciones de formato:

In [61]: arg1='hello' 
In [62]: arg2='this' 
In [63]: arg3='is a test' 

In [70]: timeit -n 10000000 "%s %s %s" % (arg1, arg2, arg3) 
10000000 loops, best of 3: 284 ns per loop 

In [71]: timeit -n 10000000 "%s %s %s", arg1, arg2, arg3 
10000000 loops, best of 3: 119 ns per loop 

parece dar el segundo enfoque el borde.

Answer 3

Evitar la cadena de formato en línea hace ahorrar algo de tiempo si el nivel de registro actual filtra el mensaje de registro (como yo esperaba) - pero no mucho:

In [1]: import logging 

In [2]: logger = logging.getLogger('foo') 

In [3]: logger.setLevel(logging.ERROR) 

In [4]: %timeit -n 1000000 logger.warn('%s %s %s' % ('a', 'b', 'c')) 
1000000 loops, best of 3: 1.09 us per loop 

In [12]: %timeit -n 1000000 logger.warn('%s %s %s', 'a', 'b', 'c') 
1000000 loops, best of 3: 946 ns per loop 

Así que, como user1202136 pointed out, la diferencia de rendimiento global depende cuánto tiempo lleva formatear la cadena (lo que podría ser significativo dependiendo del costo de llamar a __str__ en los argumentos que se pasan a la función de registro).