Buenas Practicas Logging

En este post, me dedicaré a explicar que buenas practicas en logging se deben seguir cuando desarrollamos una aplicación web, que quede claro que este es un enfoque personal, que he podido formular con cierta experiencia.

Por otro lado, es necesario comentar que si bien es cierto el ejemplo en cuestión, lo voy a realizar usando Spring boot, la información que se debe obtener para enriquecer el log, puede variar de acuerdo a la tecnología que se va a usar (Net Core, Framework, Node, etc).

Empecemos primero, explicando un poco sobre los niveles de logging que se tienen y en qué caso es necesario usar uno u otro.

Como se puede ver en la imagen, el logging no solo sirve para capturar errores (lo cual es fundamental en el proceso de desarrollo y para el posterior soporte a las aplicaciones), sino también para determinar que feature es el más usado, información de configuración de la aplicación, entre otras.

Por otro lado, el logging se puede desarrollar en múltiples appenders (este nombre es usado en log4j o log4net), como una buena práctica es necesario que como mínimo se realice el grabado del log en dos appenders, siendo una de estos la base de datos y el otro un archivo de texto, en una ruta en específico (pudiendo ser dentro de la solución desplegada). Basicamente en este post me enfocaré en explicar la información que se debe guardar en un log de error (FATAL y ERROR). La información que vamos a considerar es la siguiente:

• Fecha y hora del log
• Nivel del log (FATAL, WARNING, etc)
• Mensaje
• Stack de la excepción
• Payload (en caso que la consulta sea un GET, DELETE se debe obtener la información enviada en el url, de ser un POST, UPDATE, PATCH El body)
• Callsite (el endpoint que es consumido que en el cual se termina generando el error)
• La acción bajo la cual se produce el error (nombre del método en el controlador)
• El usuario con el cual se produjo el error.
• El nombre del método en el cual se generó el error (de la capa de lógica de negocio)
• El nombre de la aplicación en la cual se generar el error (varía de solución en solución)

Claro, que de acuerdo a qué librería se este usando para realizar este grabado del log es posible tener todo tipo de appenders, uno que me llama mucho la atención es el que nos permite enviar esta información a herramientas como elastic search y luego al integrarlo con otras herramientas como grafana para generar reportes.

En nuestra aplicación demo, nos valdremos que ciertas características del framework para poder tener acceso a la información antes detallada.

HandlerInterceptorAdapter

Al implementar esta clase abstracta y hacer un override al método preHandle tenemos acceso en el pipeline del framework, además de anotarla como “Component”. Como podemos ver en la siguiente imagen.

Como podemos ver, nos valemos del HttpServletRequest para tener acceso a mucha información necesaria para enriquecer nuestro logging, detallemos cada uno de los puntos que nos servirán:

• La url a la cual se está consultando la obtenemos con el método “getRequestURI”.
• Para obtener el nombre del método, nos valemos de una pequeña lógica que obtiene el indice del último luego del “/” y con esto hace un substring para poder obtener el último texto.
• Para el hostname de la máquina, nos valemos de la librería “java.net.InetAddress”.
• Es necesario validar si la petición es del tipo “GET” para de este modo obtener los query params que se esten enviando. Si este fuera el caso usamos “getQueryString” para este fin.
• Obtenemos un parámetro denominado “username” que se está enviando en cada una de las peticiones, sea cual sea el método http, esto con la finalidad de guardar el usuario al cual está vinculado el log. Para esto tenemos opción de guardarlo en sesión en el caso nuestra solución sea del tipo MVC, pero al tener un Web API no es posible. Podrían usar un interceptos en angular (de ser este su caso) para que a cada una de las peticiones le adicione este parámetro.

Con esto, cubrimos en cierto aspecto la información que necesitamos para nuestro logging. Sin embargo, tenemos que considerar también las solicitudes http del tipo POST, y que por lo tanto tienen un body.

RequestBodyAdviceAdapter

Nos valdremos de esta clase abstracta, y especificamente en nuestra implementación haremos el override de “supports” y de “affterBodyRead” como podemos ver en la siguiente imagen:

Además, es necesario decorar la clase con la etiqueta “ControllerAdvice”. Veamos que información obtenemos de este método:

• El payload del body, el cual obtenemos del Object que se recibe de “afterBodyRead”, en mi caso se hace un “toString” dado que en las clases implementadas se está haciendo un override a esté metodo para darle la forma de json, como podemos ver en la siguiente imágen.

Además, es muy importante en nuestro logging tener grabadas en nombre del método en el cual se realizo la caída del sistema. Este método puede estar en el stack de la excepción, pero para tenerlo directamente me estoy valiendo de una característica propia del framework, la cual se denomina “aspects” en spring, en algún otro post me dedicaré a explicar los tipos que hay y como se ejecutan en detalle, en este post sólo presentaré como se están usando.

Aspects

Spring nos brinda una herramienta muy potente, la cual es denominada programación orientada aspectos, lo cual en pocas palabras, puede facilitarnos la vida en múltiples escenarios y evitarnos repetir código innecesariamente. Veamos la siguiente imagen:

Se creo un aspecto y se decoro con las etiquetas “Aspect” y “Component” para que se registre por el framework, lo que nos permite un aspecto es que esta sección de código de ejecute en ciertas condiciones. Para el caso, se llevará a cabo en la siguiente sintaxis:

“* com.project.loggingdoitright.service.implementation.*.*(..)”

Lo cual nos indica que el aspecto coberturará todos los métodos que se encuentren en el paquete “implementation” que tengan cualquier nombre (veamos los *.*), que tengan cualquier tipo de entrada (veamos los dos puntos dentro de los paréntesis) y el asterisco inicial, indica que coberturará cualquier tipo de devolución. Como variable de entrada de nuestros aspectos tenemos a la clase “JoinPoint”, la cual posee varia información interesante, para lo que necesitamos usaremos “getSignature().getName()” que nos brinda el nombre del método en el cual se registra el error y el cual llama nuestro aspecto.

Finalmente, para realizar el grabado del log y generar un identificador único del log, el cual debe ser proporcionado al usuario del aplicativo. Para esto, usamos algo que ya se explicado antes. Un “ControllerAdvice”, el cual actua como interceptor de los errores.

Finalmente, veamos como queda nuestro registro del log.

Divido la fila asi, para que se pueda visualizar mejor.

Finalmente, puede visualizar el video correspondiente a este post, donde se detalla paso a paso el funcionamiento de la aplicación, así como su prueba consumiento las APIs desde postman.

Espero que les haya sido de ayuda, como siempre dejo el código del proyecto en el repositorio.

REPO: GITHUB

Saludos.