Log4J, aprendiendo a hacer trazas

Comenzamos esta andadura 2.0 con Java, para calentar motores aprenderemos a utilizar una herramienta muy útil que dará un valor añadido a nuestras aplicaciones. Log4J (Apache, Log for Java, http://logging.apache.org/log4j/1.2/) es una forma fácil de tener un sistema de logging que nos permitirá "controlar" y monitorizar nuestras aplicaciones de forma transparente al usuario y sobretodo de una forma mucho más elegante que los típicos System.out.println de marras que son muy sencillos de insertar pero siempre podemos caer en el error de que se nos quede alguno sin borrar de nuestro código y eso da bastante mala imagen de cara a por ejemplo entregar una práctica (los mensajes aparecerán por consola) o presentar un trabajo más profesional.

Para todo lo relacionado con Java que aparezca en este post siempre se utilizará Eclipse como IDE debido a que es el más utilizado y gratuito, el proceso para utilizar otros (NetBeans por ejemplo) debería de ser análogo.

Obteniendo el JAR

Antes de nada debemos de ir a este enlace y descargarnos el siguiente zip que contiene el jar:

http://apache.rediris.es//logging/log4j/1.2.16/apache-log4j-1.2.16.zip

en este enlace, pulsaremos sobre la versión HTTP y se nos descargará. Una vez lo tengamos en nuestro poder, descomprimiremos únicamente el archivo log4j-1.2.16.jar que es el que tiene la funcionalidad de Log4J.

Configurando el proyecto

Ahora abriremos Eclipse, y crearemos un nuevo proyecto (File->New..->Java Proyect) , para este caso le llamaremos PruebaLog4J (por ejemplo). Una vez tengamos creado nuestro proyecto, añadiremos una carpeta "lib"(New->Folder) que dependerá del proyecto y en la cual pegaremos (o descomprimiremos) el jar antes mencionado. Con el jar ya descomprimido en la carpeta "lib", haremos click derecho sobre el propio jar y en el ítem "Build Path" presionaremos sobre "Add to Build Path". Automáticamente se añadirá a nuestro path y podremos utilizarlo en nuestras clases.

Estructura final del proyecto

Creando nuestra clase con Log4J

En este punto vamos a crear una clase donde probaremos los diferentes niveles de log que nos proporciona Log4J. Comenzaremos creando un paquete "test" (nunca utilizar default package) donde introduciremos una clase de prueba, por ejemplo PruebaLog4J y seleccionamos que nos genere el main también para ahorrarnos un poco en código.

Ya tenemos la clase sobre la cual hacer logging, para utilizar Log4J necesitaremos crear una instancia en todas las clases donde vayamos a usarla de la siguiente forma: 

Log4J por defecto utilizará una especie de Singleton (algún día escribiré sobre patrones) que se creará solo una vez y te dará la instancia cuando se necesite. Al método getLogger, le pasaremos siempre el nombre de la clase en la que estemos .class para que nos "personalice" los mensajes de log que nos mostrará.

Poseemos una variable logger, ¡usémosla!

Vamos a comenzar con lo básico, dentro del método main introduzcamos esto:

Con la sentencia de encima, conseguimos meter ese mensaje entrecomillado en nuestro log. 

Ahora toca hacerlo funcionar...

Si intentamos ejecutar lo que hemos hecho hasta ahora, nos mostrará un error porque falta configurar cómo queremos que Log4J nos grabe los logs.

Configurando Log4J

Hay 2 formas de configurarlo, una más básica y que no quiero ver aquí porque nos interesa más entrar en cómo hacer una configuración más a medida y que cada uno la prepare a su gusto.

Para configurarlo, tenemos que crear un archivo log4j.properties (New->File) dentro de "src" para que la biblioteca lo reconozca por defecto y dentro introduciremos el siguiente texto:

# Niveles de Log

log4j.rootLogger=trace, stdout, R

# Configuracion del Appender de la consola

log4j.appender.stdout=org.apache.log4j.ConsoleAppender

# Pattern to output the caller's file name and line number.

log4j.appender.stdout.layout=org.apache.log4j.PatternLayout

log4j.appender.stdout.layout.ConversionPattern=%5p [%t] (%F:%L) - %m%n

# Appender del fichero

log4j.appender.R=org.apache.log4j.RollingFileAppender

# Path and file name to store the log file.

log4j.appender.R.File=./logs/testlog4j.log

log4j.appender.R.MaxFileSize=500KB

# Manten solo un fichero

log4j.appender.R.MaxBackupIndex=1

# Plantilla del fichero

log4j.appender.R.layout=org.apache.log4j.PatternLayout

log4j.appender.R.layout.ConversionPattern=%d - %c - %p - %m%n

Lo seguido de # son comentarios.

Vamos a intentar entender un poco qué definimos en estas líneas.

A grosso modo, un fichero .properties es un fichero de configuración que se basa en definir líneas de tipo clave=valor.

La primera línea útil que nos encontramos es la siguiente:

log4j.rootLogger=trace, stdout, R

Aquí estamos definiendo el log "maestro", que hará logging sobre todas las clases, le estamos indicando el nivel traza, por salida estándar y que lo llamaremos R.

Cada vez que veamos la R en el fichero, estamos haciendo referencia a este log que hemos definido aquí.

log4j.appender.stdout=org.apache.log4j.ConsoleAppender

Definimos un appender para la consola.

log4j.appender.stdout.layout=org.apache.log4j.PatternLayout

log4j.appender.stdout.layout.ConversionPattern=%5p [%t] (%F:%L) - %m%n

Definimos que layout (estilo) llevará nuestro log y debajo definiremos el patrón que queramos que siga.

log4j.appender.R=org.apache.log4j.RollingFileAppender

Definimos otro appender con nuestro ROOT, queremos que sea un RollingFileAppender, eso quiere decir que queremos que nos cree un fichero de texto con el log (opción fundamental de un log).

log4j.appender.R.File=./logs/testlog4j.log

log4j.appender.R.MaxFileSize=500KB

log4j.appender.R.MaxBackupIndex=1

log4j.appender.R.layout=org.apache.log4j.PatternLayout

log4j.appender.R.layout.ConversionPattern=%d - %c - %p - %m%n

Aquí definimos lo relacionado con el log que hemos definido como ROOT, la ruta que tendrá el archivo (lo ideal es mantener esta estructura), el tamaño máximo que tendrá el archivo, los backups que quieres tener del fichero, qué layout seguirá y qué patrón seguirá.

Podemos añadir tantos appenders como queramos y para que salgan por diferentes archivos (esto sería lo ideal para tener un control total de nuestro programa, pero no es realmente necesario).

Con todo el fichero properties definido (y espero que más o menos entendido), ya podemos ejecutar nuestra aplicación, y así podemos ver los resultados.

Veremos por consola un mensaje del tipo:

y en la carpeta logs aparecerá el fichero pruebalog4j.log :

Ya tenemos nuestro log funcionando. Cada mensaje que queramos poner en nuestra aplicación, tendremos que hacer una sentencia como la anterior del tipo:

logger.info("Otro mensaje para el log");

Recuerden que en cada clase hay que obtener el logger para usarlo.

Niveles de Log

Ahora que ya sabemos como hacer nuestros logs, pasemos a ver qué es esto de los niveles de logging.

Existen 5 niveles en la jerarquía de logging que son de menor a mayor dureza: DEBUG, INFO, WARN, ERROR y FATAL.

DEBUG: Usaremos este nivel cuando queramos ver por dónde va la traza, así tendremos un control exhaustivo de nuestros desarrollos.

INFO: Aquí podemos definir información que puede ser útil del funcionamiento del programa, como por ejemplo decir que se están tomando correctamente unos parámetros.

WARN: Utilizaremos este nivel para mostrar un funcionamiento anómalo de nuestra aplicación pero que no afectará al funcionamiento de la misma.

ERROR: Utilizaremos este para decir que ha ocurrido un error.

FATAL: Este es el nivel superior de la jerarquía y con él definiremos un error fatal de la aplicación que llevará a la finalización inmediata de la misma.

Que estos niveles siguen una jerarquía quiere decir que si definimos un log con nivel DEBUG se mostrarán todos los mensajes que definamos, desde los logger.debug("loquesea"); hasta los logger.fatal("estovamal");

Si por el contrario definimos un nivel FATAL, solo aparecerán los logger.fatal("estorompió");

Así mismo, esto que acabo de escribir sirve para orientarse de cómo escribir diferentes niveles de log en nuestra aplicación.

Finalizando

Ya hemos terminado, sólo queda que cada uno mire los patrones de cómo configurar los layouts y esa no es tarea fácil pero seguro que será muy reconfortante una vez se tiene definido como uno quiere puesto que hay infinidad de opciones. Aquí estan todas.

Al principio comenté que a diferencia de los System.out.println el log podía quitarse para no dejar rastro en la ejecución, aquí entra otra vez el fichero properties y los niveles de la jerarquía. Lo ideal es poner un nivel INFO cuando se pasa a producción y tan sólo en el fichero, quitaríamos el appender de la consola. El código permanecerá en nuestros ficheros que una vez haya que mantener ese código, solo tendremos que reestablecer el nivel DEBUG.

Pues hasta aquí el primer post-tutorial de cómo conseguir definir nuestro propio sistema de Logging, espero que os haya servido de ayuda y ojalá alguien me comente sus experiencias y qué patrones ha seguido en sus configuraciones. Para ello, tenéis a vuestra disposición mi cuenta de Twitter @Minikisto y los comentarios de este mismo post. En la próxima entrega, probablemente nos centremos en JUnit y unas nociones básicas de estructuración de la información de un proyecto.

Proyecto de Eclipse

Fuentes del artículo: http://logging.apache.org/log4j/1.2/manual.html