Todo en esta vida tiene un coste, incluso el logging

Existen dos tipos de desarrolladores, y no es el chiste del binario: los que usan un depurador y los que depuran a base de líneas de log.

Seas uno, otro, o una mezcla de los dos, lo que está claro es que nos hemos acostumbrado a escribir líneas de log hasta para cagar, y sólo hace falta arrancar Spring o Struts en nivel de DEBUG para comprobarlo.

Pero, ¿por qué somos tan alegres con el logging?

Principalmente porque es una operación barata, y cito a la web de Log4j:

On an AMD Duron clocked at 800Mhz running JDK 1.3.1, it costs about 5 nanoseconds to determine if a logging statement should be logged or not.

Es decir, ejecutar una línea de log que al final no escribe nada porque es sólo para depuración no cuesta mucho tiempo de CPU. Habría que ejecutar 109 instrucciones de log para tener ocupado un núcleo durante 5 segundos. Una barbaridad de instrucciones...

¿De verdad crees que es una barbaridad de instrucciones? ¿En un servidor de producción, funcionando 24x7 durante años? Yo no.

En este momento seguro que te estás llevando las manos a la cara en un doble facepalm pensando en la optimización prematura. Yo también lo pensé, pero el final de la entrada igual te sorprende.

¿Por qué te preocupas por 5 nanosegundos, tarao?

Por dos motivos: son inevitables, y son completamente innecesarios. En el momento en que clavas un "logger.debug()" ya sabes que ahí se va una fracción del tiempo de CPU, y que se va en no hacer nada. Ene, a, de, a.

La JVM, con su compilación Just-in-time, es capaz de eliminar ramas de código que en tiempo de ejecución se demuestra que no son ejecutables. Lamentablemente, no conozco ninguna implementación de logging que sea capaz de ofrecer suficiente información como para que esto ocurra. Es decir, la instrucción de comparación que determina si un nivel de log está activado se ejecuta siempre.

Aserciones al rescate

No te voy a contar qué son las assertion de Java, porque ya deberías estar utilizándolas. Sin embargo, me permito recordarte una característica muy peculiar: si no están activadas, no se ejecutan. Dudo mucho que nadie corra aplicaciones en producción con las aserciones activadas, así que la sinergía es total. Tenemos un log que sólo queremos en desarrollo y una funcionalidad del lenguaje que hace exactamente eso:

assert debug("log this! rIn");

En la siguiente y última parte te ofreceré unos numeritos junto con una clase de prueba y una pequeña implementación de ejemplo.

Y galletitas, también.

Autor

Héctor

Viendo los bytes pasar desde mi ventana