Buenas prácticas al registrar logs en desarrollo de software

La información que generamos de logs en nuestros sistemas es vital para encontrar donde se da un problema puntual. Con la gran cantidad de logs generados, que pueden ser hasta millones al día, el proceso de encontrar un dato específico se puede volver muy difícil y a veces podemos no encontrar lo que buscamos.

Por eso, siempre digo que el análisis de logs es como "Encontrar una aguja en un pajar".

En este documento les comentaré sobre las mejores prácticas basadas en investigación y experiencia para obtener los mejores resultados.

Seguridad

No por casualidad el punto seguridad está al principio. La seguridad de sistemas hoy en día es más relevante que nunca, ya que cada vez hay más ataques para obtener información y utilizarla para fines ilícitos.

Si por ejemplo utilizamos archivos de texto plano o un software como Kibana-local -que por defecto no trae control de usuario y contraseña- tenemos nuestra información expuesta. Esto quiere decir que debemos tener "mucho" cuidado de no exponer información sensible -como credenciales, contraseñas, números de tarjetas de crédito, etc.- en los logs.

Sobre le punto Kibana-Elasticsearch, aquí dejo un link para profundizar en el punto sobre data-leaks: What is Elasticsearch and why is it involved in so many data leaks? | TechRadar

Particularmente quiero hacer foco en el registro datos serializados como JSON y XML, donde muchas veces va más información de la que necesitamos.

Tomemos como regla:

"Siempre previo al registro de un log, revisar si es necesario ofuscar algún dato sensible"

Tengamos en cuenta que toda persona o sistema con acceso a los logs, tendrá acceso a esta información registrada.

Nivel de registro

En la mayoría de los sistemas de logs, veremos incluyen el nivel de registro para distinguir el tipo de log generado. En general tendremos varios tipos, aquí simplificaremos en los más importantes:

• Debug/Trace: Información para debug de nuestras aplicaciones. Nunca debiera estar activo en producción.
• Info: Información que siempre se genera en ciertos procesos sensibles. Nos sirve para identificar e investigar problemas en producción.
• Warning: Información de algo que es potencialmente un error. Muchas veces puede ser utilizado por ejemplo en validaciones que le impiden a un usuario realizar un proceso. Un ejemplo de esto podría ser un error de acceso de un usuario a cierta área del sistema. 
• Error: Aquí se identificó un error explícito, como un servicio que no está respondiendo a nuestras peticiones.

El registro de log es importante, por ejemplo, cuando recibimos notificaciones no vamos a querer recibir notificaciones de los logs tipo INFO ya que pueden ser demasiados. Sin embargo, nos interesará recibir notificaciones de logs tipo Warning o Error, y por ende, deben estar bien definidos para que nos lleguen únicamente las notificaciones necesarias.

Si recibimos más notificaciones de las que debiéramos recibir, muchas veces sucede que no se terminan revisando, y por ende terminan siendo inútiles. Cuando sucede lo anterior, podemos estar perdiéndonos de notificaciones cuando sucede algo realmente serio.

Registro de Logs

Aquí debemos tener en cuenta algunos puntos para registrar información útil y poder encontrar -a posteriori- lo que buscamos. En el proceso de registro de logs, debemos tener en cuenta que -en un mundo de microservicios, balanceo de carga y procesos descentralizados- el repositorio de logs tiende a ser centralizado y podemos tener decenas de miles de logs por hora.

A continuación repasaremos la información que debiera estar asociada a cada registro de log:

• Identificación de la aplicación que generó el log
  Generalmente se codifica para que sea más sencillo filtrar y encontrar. Ej.:
• Backoffice sistema central - CENTRAL.BO
• Procesos batch sistema central - CENTRAL.BATCH
• Microservicios Central - CENTRAL.MS
  
  
• IP o ubicación - ¿Dónde?
  El saber donde se generó el log es importante para poder conectarnos a ese equipo y revisar logs puntuales, por ejemplo, del sistema operativo.
  
  
• Usuario - ¿Quién?
  No es menor saber, si es posible, por qué usuario se generó el log. De esta forma podremos hacerle alguna pregunta para entender por donde se generó la situación.
  Sobre el usuario, también puede ser importante registrar la IP/Ubicación del usuario.
  
  Cuando hablamos de usuario, cabe aclarar que no solo puede ser una persona física, sino que puede ser otro sistema conectándose a nuestros servicios. 
  
  
• Programa
  Este punto es fundamental para saber que donde revisar a nivel de código. Por ejemplo, si se genera mal una comisión, podremos ir directamente al fuente que está generando el problema.
  
  
• Identificación de transacción, operación. etc.
  Si registramos un log que diga "Error al realizar cambio de estado" no es lo mismo que "Error al realizar cambio de estado - ServicioId: 123". Como podemos ver en el último caso, podremos ir directamente al Servicio 123 para ver cual es el problema con el cambio de estado.
  
  De nuevo, aquí debemos tener en cuenta que pueden existir varias aplicaciones concurrentes generando logs con milisegundos de diferencia. Esto hace que sea tan importante tener la información relevante en el propio registro de log.
  
  
• Fecha/Hora a nivel "mínimo" de milisegundo - ¿Cuando?
  Parece obvio pero es bueno dejar claro que este es un dato fundamental a la hora de buscar logs, para poder restringir la búsqueda y revisar el menor conjunto posible de datos.
  
  
• Hilo/Thread
  El hilo es el identificador de un hilo particular que está generando el log. Muchas veces, cuando investigamos una situación, podemos filtrar el hilo para entender que estaba pasando antes que se diera el problema. Este tipo de filtro nos genera un contexto para aislar el incidente.