Identificar todas las trazas de una petición en una aplicación web Java con log4j

Escrito por picodotdev el , actualizado el .
java planeta-codigo programacion
Comentarios

Java

En una aplicación web hay múltiples usuarios realizando peticiones al servidor de modo que al usar una librería de logging como log4j las trazas de información de los diferentes usuarios aparecerán intercaladas. En esta maraña de trazas resulta difícil obtener la secuencia de trazas de una petición siendo la diferencia entre descubrir la causa de un error o pasar varias horas revisando trazas sin encontrar nada significativo en la inmensa cantidad de ellas relativas a otras peticiones. La librería log4j proporciona un mecanismo para seguir la secuencia completa de trazas de una petición con el concepto denominado fish tagging.

En el contexto de una aplicación web para seguir la secuencia de trazas de una petición consiste en asignar variables con información al thread que ejecuta la petición, el contenido de estas variables está disponible para emitirse en la traza. Asignando a cada petición un identificativo aleatorio único cuando se inicia la petición, en una aplicación web Java podría ser en un filtro, las trazas emitidas de cada petición quedarán relacionadas por compartir el mismo identificativo de contexto. Este identificativo significa que encontrada una relevante es posible obtener el resto de las peticiones muy fácilmente con un filtro usando ese identificativo.

El filtro podría ser el siguiente, el identificativo se genera de forma aleatoria con la clase UUID del JDK de Java, se asigna al ThreadContext y al finalizar se limpia de información la variable de contexto en la cláusula finally de un try-catch.

El emitir trazas no cambia en absoluto si utilizamos esta técnica para identificar trazas.

En el formato usado para determinar el contenido de la trazas se pueden referenciar las variables deseadas a incluir en la traza.

  • %X muestra el contenido completo del Map.
  • %X{key} muestra el valor de una clave especifica del Map.

Y este es el resultado de emitir varias trazas habiendo establecido un identificativo en el ThreadContext, todas las trazas emitidas por ese Thread incluirán el mismo identificativo.

En este conjunto las tres primeras corresponden a la petición de una página en la siguiendo el ciclo de vida de una página de Apache Tapestry se llama primero al método activate y posteriormente al método setupRender, estas tres poseen el mismo UUID ya que se ejecutan en la misma petición. Las otras dos corresponden cada una de ellas a una petición AJAX que realiza la página Index al cargarse en el navegador del cliente, cada una de estas dos peticiones AJAX se procesan en un nuevo hilo y por consiguiente poseen un UUID diferente.

Para emitir trazas de forma relacionada esta no es la única posibilidad, también puede interesar identificar con marcadores las trazas realacionadas emitidas en diferentes clases de una aplicación en diferentes clases pero pertenecientes a la misma funcionalidad, contexto delimitado o bounded context.

El código fuente completo del ejemplo puedes descargarlo del repositorio de ejemplos de Blog Bitix alojado en GitHub y probarlo en tu equipo ejecutando el comando ./gradlew run.