Beneficios del registro estructurado en comparación con el registro básico

Hay dos avances fundamentales con el enfoque estructurado que no se pueden emular utilizando registros de texto sin (a veces niveles extremos) un esfuerzo adicional.

Tipos de eventos

Cuando escribes dos eventos con log4net como:

log.Debug("Disk quota {0} exceeded by user {1}", 100, "DTI-Matt");
log.Debug("Disk quota {0} exceeded by user {1}", 150, "nblumhardt");

Esto producirá un texto similar:

Disk quota 100 exceeded by user DTI-Matt
Disk quota 150 exceeded by user nblumhardt

Pero, en lo que respecta al procesamiento de la máquina, son solo dos líneas de texto diferente.

Es posible que desee encontrar todos los eventos de "cuota de disco excedida", pero el caso simplista de buscar los eventos like 'Disk quota%' caerá tan pronto como ocurra otro evento como este:

Disk quota 100 set for user DTI-Matt

El registro de texto desecha la información que tenemos inicialmente sobre la fuente del evento, y esto debe reconstruirse al leer los registros, generalmente con expresiones de coincidencia más y más elaboradas.

Por el contrario, cuando escribe los siguientes dos eventos Serilog :

log.Debug("Disk quota {Quota} exceeded by user {Username}", 100, "DTI-Matt");
log.Debug("Disk quota {Quota} exceeded by user {Username}", 150, "nblumhardt");

Estos producen una salida de texto similar a la versión log4net, pero detrás de las escenas, ambos eventos llevan la "Disk quota {Quota} exceeded by user {Username}" plantilla de mensaje .

Con un receptor apropiado, más tarde puede escribir las consultas where MessageTemplate = 'Disk quota {Quota} exceeded by user {Username}' y obtener exactamente los eventos donde se excedió la cuota de disco.

No siempre es conveniente almacenar la plantilla de mensaje completa con cada evento de registro, por lo que algunos de ellos descartan la plantilla de mensaje en un valor numérico EventType (por ejemplo, 0x1234abcd ), o puede agregar un enricher a la tubería de registro a hazlo tú mismo .

Es más sutil que la siguiente diferencia a continuación, pero una poderosa a la hora de manejar grandes volúmenes de registro.

Datos estructurados

Nuevamente, considerando los dos eventos sobre el uso del espacio en disco, puede ser bastante fácil usar registros de texto para consultar a un usuario en particular con like 'Disk quota' and like 'DTI-Matt' .

Pero, los diagnósticos de producción no siempre son tan sencillos. ¿Imagina que es necesario encontrar eventos en los que la cuota de disco excedida sea inferior a 125 MB?

Con Serilog, esto es posible en la mayoría de los sumideros utilizando una variante de:

Quota < 125

Es posible construir este tipo de consulta a partir de una expresión regular , pero se cansa rápidamente y generalmente termina siendo una medida de último recurso.

Ahora agregue a esto un tipo de evento:

Quota < 125 and EventType = 0x1234abcd

Usted comienza a ver aquí cómo estas capacidades se combinan de una manera directa para hacer que la depuración de la producción con los registros se sienta como una actividad de desarrollo de primera clase.

Otro beneficio, tal vez no es tan fácil de prevenir por adelantado, pero una vez que la depuración de la producción se ha retirado de la tierra de la piratería de expresiones regulares, los desarrolladores comienzan a valorar los registros mucho más y a tener más cuidado y consideración al escribirlos. Mejores registros - > aplicaciones de mejor calidad - > más felicidad por todos lados.

Cuando recopila registros para procesar, ya sea para analizarlos en una base de datos y / o buscar en los registros procesados más tarde, usar el registro estructurado hace que parte del procesamiento sea más fácil / más eficiente. El analizador puede aprovechar la estructura conocida ( por ejemplo JSON, XML, ASN.1, lo que sea) y usar máquinas de estado para el análisis, a diferencia de las expresiones regulares (que pueden ser computacionalmente caras) compilar y ejecutar). El análisis de texto de formato libre, como el sugerido por su compañero de trabajo, tiende a depender de las expresiones regulares, y confían en que el texto no cambia . Esto puede hacer que el análisis de texto de forma libre sea bastante frágil ( es decir, el análisis está estrechamente relacionado con el texto exacto en el código).

Considere también el caso de búsqueda / búsqueda, por ejemplo :

SELECT text FROM logs WHERE text LIKE "Disk quota";

LIKE requieren comparaciones con cada valor de fila text ; una vez más, esto es relativamente costoso desde el punto de vista computacional, particularmente cuando se usan comodines:

SELECT text FROM logs WHERE text LIKE "Disk %";

Con el registro estructurado, su mensaje de registro relacionado con errores de disco podría tener este aspecto en JSON:

{ "level": "DEBUG", "user": "username", "error_type": "disk", "text": "Disk quota ... exceeded by user ..." }

Los campos de este tipo de estructura pueden asignarse con bastante facilidad a por ejemplo los nombres de las columnas de la tabla SQL, lo que a su vez significa que la búsqueda puede ser más específica / granular:

SELECT user, text FROM logs WHERE error_type = "disk";

Puede colocar índices en las columnas cuyos valores espera buscar / buscar con frecuencia, siempre y cuando no use las cláusulas LIKE para esos valores de columna . Cuanto más pueda desglosar su mensaje de registro en categorías específicas, más específico podrá hacer su búsqueda. Por ejemplo, además del campo / columna error_type en el ejemplo anterior, puede hacer que incluso sea "error_category": "disk", "error_type": "quota" o somesuch.

Mientras más estructura tenga en sus mensajes de registro, más sistemas de análisis / búsqueda (como fluentd , elasticsearch , kibana ) podrá aprovechar esa estructura y realizar sus tareas con mayor velocidad y menos CPU / memoria.

Espero que esto ayude!

No obtendrá mucho beneficio del registro estructurado cuando su aplicación cree unos cientos de mensajes de registro por día. Definitivamente lo hará cuando tenga unos pocos cientos de mensajes de registro por segundo provenientes de diferentes aplicaciones implementadas.

Relacionado, la configuración donde los mensajes de registro terminan en el ELK Stack también es apropiada para la escala donde el registro en SQL se convierte en un cuello de botella.

He visto la configuración de "registro y búsqueda básica" con SQL select .. like y regexps empujados a sus límites donde se derrumba: hay falsos positivos, omisiones, código de filtro horrible con errores conocidos que es difícil de mantener y no -uno quiere tocar, los nuevos mensajes de registro que no siguen las suposiciones del filtro, la renuencia a tocar las declaraciones de registro en el código para que no rompan los informes, etc.

Por lo tanto, están surgiendo varios paquetes de software para tratar este problema de una mejor manera. Hay Serilog, escuché que el equipo de NLog lo está viendo , y escribimos StructuredLogging.Json for Nlog , también veo que el nuevo ASP.Net abstracciones de registro del núcleo "hace posible que los proveedores de registro implementen ... registro estructurado".

Un ejemplo con StructuredLogging. Se registra en un registrador NLog como este:

logger.ExtendedError("Order send failed", new { OrderId = 1234, RestaurantId = 4567 } );

Estos datos estructurados van a kibana. El valor 1234 se almacena en el campo OrderId de la entrada de registro. A continuación, puede buscar utilizando la sintaxis de consulta kibana para, por ejemplo, todas las entradas de registro donde @LogType:nlog AND Level:Error AND OrderId:1234 .

Message y OrderId ahora son solo campos en los que se pueden buscar coincidencias exactas o inexactas según sea necesario, o se pueden agregar para los recuentos. Esto es potente y flexible.

De las mejores prácticas de StructuredLogging :

  

El mensaje registrado debe ser el mismo cada vez. Debería ser un   cadena constante, no una cadena formateada para contener valores de datos como   Ids o cantidades. Entonces es fácil de buscar.

     

El mensaje registrado   debe ser distinto, es decir, no es lo mismo que el mensaje producido por un   declaración de registro no relacionada. Entonces buscarlo no coincide   cosas no relacionadas también.