24
Ago

Arquitectura de logging en Glassfish

GlassfishSí, sé lo que estáis pensando: “¿Un artículo sobre logging en Glassfish?” Los que visitan este blog y no son técnicos ni siquiera habrán llegado a esta línea y los que sí lo sois pensaréis “¿Qué tiene de interesante?”.

Y, sin embargo, lo es. El modo en el que Glassfish trabaja con logs es peculiar y guarda algún oscuro secreto.  Sólo te pido dos cosas:

    1. Cinco minutos de tu tiempo para que juzgues si lo he conseguido.
    2. Que, para vivir una experiencia completa, escuches la canción ‘Old Souls de la banda sonora de Origen mientras lees el artículo.

Lo peor que te puede pasar es que salgas de aquí aprendiendo algo nuevo y, por supuesto, siempre puedes tirarme tomates virtuales en los comentarios del artículo.  ¿Te animas?

EL MISTERIO DE LAS TRAZAS INEXPLICABLES

Como parte de mi asedio y conquista al entorno de trabajo de STORETTO, comencé a estudiar nuestro sistema de traza y la configuración del mismo. Parecía algo relativamente sencillo (una configuración típica de log4j) Sin embargo, algo no encajaba. Ni las trazas aparecían por donde debían ni tenían el formato que queríamos. Nada se parecía ni remotamente a lo que teníamos configurado.

Tampoco entendía por qué el equipo de STORETTO había configurado el sistema de log4j habitual de la compañía mediante una variable de sistema, en vez de colocar el fichero de configuración en el classpath de la aplicación.

¿Qué estaba pasando? ¿Era todo esto real o era un sueño? ¿Estaba soñando dentro de un sueño? ¿Cómo distinguir la realidad del sueño?

Como en el anterior caso de las JSPX desestructuradas, yo tenía un poco más de tiempo disponible que el equipo para comprender qué estábamos haciendo y por qué lo estábamos haciendo. Lo que averigüé fue SORPRENDENTE.

FRAMEWORK DE LOGGING DE GLASSFISH

Antes de nada, era importante conocer qué sistema de registro de trazas utiliza Glassfish y cómo funciona el mismo.

He resumido todo lo que se necesita saber en un par de párrafos:

Glassfish utiliza para su sistema de trazas la implementación por defecto de la especificación JSR-047, una API de logging, y recomienda el uso de la misma, aunque permite el uso de otras como Apache Commons Logging o log4j.

El uso de la API de logging del JDK implica varias cosas a tener en cuenta:

  1. Se basa en un sistema de Handlers, clases que heredan de java.util.logging.Handler y que son los que encapsulan tanto la lógica de publicación de trazas como la configuración de las mismas.
  2. Estableciendo un level o nivel por Handler podemos establecer el nivel mínimo de traza que queremos que recoja el HANDLER. Estableciendo un nivel determinado se recogerán todas las trazas de ese nivel y de los niveles superiores jerárquicamente (para conocer más sobre los nieles de traza, pinchar aquí). También se puede establecer el nivel mínimo de traza por paquete de clases, independientemente del nivel implementado por paquete (se usará la configuración más restrictiva)
  3. Además del nivel, se puede establecer un control secundario y opcional sobre lo que se registra o no, mediante la asignación de un filtro o Filter (clase que hereda de java.util.logging.Filter) a un Handler. Un Filter, básicamente, implementa un método isLoggeable que devuelve un booleano que indica si un log se debe trazar o no.
  4. Si se quiere formatear las trazas generadas con alguna estructura especifica, se debe implementar un Formatter (clase que herede java.util.logging.Formatter) y asignarlo al Handler deseado.
  5. Toda esta configuración se hace a través de un fichero denominado logging.properties

La primera diferencia que chocará a todos los que venimos de usar log4j es que todo se configura programándolo. Es decir, no tienes una manera de poder configurar de forma flexible el formato de tus trazas. Si quieres un Formatter que saque el patrón de tu traza de un fichero de propiedades, vas a tener que programártelo.

TRABAJANDO CON LOG4J

¿Son mis logs reales o sólo un sueño?

Para trabajar con log4j en Glassfish v2 se recomendaba configurar la librería de traza como librería del sistema para evitar problemas con el classloading pero esto ya no puede hacerse con Glassfish v3 así que la solución pasa por indicar al servidor la ruta del fichero de configuración de log4j.

En log4j se configuran Appender (el equivalente de los Handler en JSR-047) El Appender típico que todo el mundo utiliza al desarrollar es el org.apache.log4j.ConsoleAppender, que publica los logs en la salida por defecto de System.out.

El problema es que las trazas no salen por la consola habitual que esperamos todos los programadores sino en un fichero server.log que se encuentra en la ruta /midominio/logs/.

Eso es bastante fácil de explicar porque  ese fichero es la salida por defecto del servidor, así que, ésa es su consola.

Lo que no tiene ni pies ni cabeza es que nuestras trazas salgan con el formato de las trazas de la API de logging de JDK o, más exactamente, envueltas por su formato, puesto que nuestro traza aparece… pero sólo como parte del mensaje de la traza de logging del JDK.

Bueno… podemos pensar que, de alguna manera, el sistema está ignorando nuestra configuración de log4j. Sin embargo, si configuramos cualquier otro Appender, por ejemplo uno que publique en un fichero inception.log, log4j funciona PERFECTAMENTE.

¿Entonces? ¿Qué está pasando? ¿Por qué salen todas mis trazas rodeadas de almohadillas ‘#’  y con un retorno de carro cuando las publico por consola?

LA SOLUCIÓN AL MISTERIO

No, no estamos soñando. Nuestras trazas son reales y nuestra configuración también. No estamos haciendo nada mal. Simplemente, alguien ha estado jugando con nosotros. Alguien ha estado haciendo trampas.

Glassfish, utiliza una implementación propia y sobrescrita del objeto System cuyo método out devuelve un PrintWriter que redirige todas las salidas al sistema de logging del servidor. Probadlo, hacer un System.out.println en una clase desplegada en Glassfish. No sólo aparecerá en la salida por defecto -server.log- sino que, además, aparecerá con el formato específico del sistema de logging.

Lo más grave de todo esto es que System es una clase final. Es decir, que no puede ser extendida, precisamente para evitar lo que Glassfish ha conseguido: que nuestro código tenga un comportamiento extraño y nos desconcierte. Que nos tengamos que frotar los ojos para comprobar que no estamos soñando.

De acuerdo, Glassfish nos ha engañado pero ahora, después de leer este artículo sabemos cómo vencerlo:

  • ¿Queremos modificar el formato de las trazas del servidor? Implementaremos nuestro propio Formatter y se lo asignaremos al ConsoleHandler del fichero logging.properties
  • ¿Queremos que nuestras propias trazas no se mezclen con las del servidor? Nos olvidaremos de utilizar el ConsoleAppender
  • ¿Queremos que sólo nuestras trazas de error salgan en la salida por defecto del servidor? Podremos utilizar un ConsoleAppender y configurarlo en nuestro log4j.properties para que sólo registre trazas de nivel ERROR o superiores (recordad que sea cual sea el nivel de traza de log4j, la salida se publicará en System.out y el logging de JAVA las publicará por defecto como trazas de nivel INFO)

Glassfish ha luchado contra nosotros y ha perdido, por lo menos a nivel de logging. Nosotros le dominamos. No él, a nosotros. Y, desde luego, no estamos soñando… ¿o sí?

BONILINKS:

Artículos relacionados:

  1. Transacciones y bloqueos en Glassfish v3 con EJB3.1 y JPA2 (III) Tercera parte del tutorial sobre como utilizar transacciones y bloqueos...
  2. Transacciones y bloqueos en Glassfish v3 con EJB3.1 y JPA2 (II) Segunda parte del tutorial sobre como utilizar transacciones y bloqueos...
  3. Transacciones y bloqueos en Glassfish v3 con EJB3.1 y JPA2 (I) Un sencillo tutorial sobre como utilizar transacciones y bloqueos con...


free blog themes
free blog themes