Qu es el Logging?

El Logging son bitcoras del comportamiento del sistema que se persisten en algn lado o se pueden visualizar en alguna interfaz.

No suele darse importancia al logging, pero cuando los problemas comienzan a salir en un sistema en produccin, lo primero a lo que recurres son los logs. Tener logs bien estructurados y con informacin til, suelen salvar el trasero de muchos.

El logging tiene muchos propsitos, pero principalmente nos ayuda a investigar las causas races de los problemas que suceden en el sistema, analizar bugs y revisar problemas de rendimiento y hasta para auditar un sistema.

ASP.NET Core ya cuenta con un sistema de logging el cual por default est configurado para mandar logs a consola, a event logs de windows y entre otros (esto se configura por default en el HostBuilder). Pero, para irnos ms lejos de solo logs en consola, se necesita ms configuracin y esfuerzo.

Para esto viene Serilog, es una herramienta que nos ayuda a no reinventar la rueda.

El cdigo siempre lo encontrars en mi GitHub.

Qu es Serilog?

Serilog es una herramienta que nos permite hacer logs para diagnostico que se pueden guardar en archivos, mostrarse en consola y muchas otras opciones. Es muy fcil de configurar y tiene una API muy limpia y se puede usar en distintas versiones de .NET sin problemas.

A diferencia de otras libreras, los parmetros pasados en los logs no son "convertidos" a texto, sino que su estructura es conservada y nos permite ver de forma muy efectiva los valores de los objetos y dependiendo en donde guardamos los logs, podremos conservar sus estructuras e incluso hacer bsquedas.

No se hace log de texto, se hace log de datos.

Para sacar jugo de Serilog, debemos de usar message templates, esto implica no solo concatenar texto (de hecho, no debes de concatenar strings al hacer logs).

Nota : Este vdeo explica lo que acabo de decir .

Un message template podra ser de esta forma:

var input = new { Latitude = 25, Longitude = 134 };var time = 34;log.Information("Processed {@SensorInput} in {TimeMS:000} ms.", input, time);

Obtendremos este resultado en consola:

09:14:22 [Information] Processed { Latitude: 25, Longitude: 134 } in 034 ms. 

El operador @ que est en SensorInput le dice a Serilog que mantenga la estructura del objeto que se pasa ah. Si esto es omitido, serilog mandar a llamar el mtodo ToString() para mostrar el valor de dicho objeto.

Este ejemplo cuenta con dos propiedades, SensorInput y TimeMS. Estos se guardarn en el log event y no solo como un texto que vemos en la consola.

Las propiedades capturadas, en formato JSON se podrn visualizar as:

{ "SensorInput": { "Latitude": 25, "Longitude": 134 }, "TimeMS": 34 }

Sinks

La segunda cosa importante de utilizar Serilog, son los Sinks. Los sinks son aquellos lugares en donde podemos decirle a Serilog que guarde los logs. Pueden ser archivos en JSON, pueden ser registros en una base de datos, eventos en un Application Insights (este ) y entre muchas cosas.

Por eso es importante usar Message Templates porque tal vez en consola no podemos ver mucha informacin, pero cuando se guarda la informacin en un lugar como Elastic Search, podemos hacer bsquedas por usuario, por tipo de operacin que hizo y entre otros.

Serilog tambin es una alternativa al uso de Audit.NET que expliqu en otro post. La idea es aprender de las alternativas que tenemos al usar ASP.NET.

Guardar los logs en un Application Insights es super til, ya que AI te ayuda a agrupar los logs segn los requests y operaciones que se hacen en tu Web API. Hacer el tracing de esa informacin es super til al estar diagnosticando tu aplicacin cuando falla o tiene problemas de rendimiento.

Un ejemplo de cmo se ve un log generado con Serilog y mandado a Application Insights:

Puse en rojo mi Message template, pero a Serilog le indiqu que agregu ms propiedades al Log Event. Aunque yo no los vea en consola, en los Sinks los podremos ver.

Configurando Serilog en MediatRExample

Como lo puedes ver, esta es la parte 9 de una serie de publicaciones. Todo enfocado a ASP.NET Core y temas que considero, todos deberamos saber.

Primero, empezaremos instalando Serilog para ASP.NET Core en Web API:

dotnet add package Serilog.AspNetCore

Por default, aqu vendr incluido el Sink para mandar los logs a consola, pero si necesitas cualquier Sink diferente, debers buscar en Github como configurarlo.

Agregando Serilog a Program.cs

La configuracin es muy sencilla, porque se integrar totalmente con ILogger<T> que ya hemos estado usando todo el tiempo. Solo en Program.cs hacemos lo siguiente:

// ... cdigo omitidovar builder = WebApplication.CreateBuilder(args);builder.Host.UseSerilog();Log.Logger = new LoggerConfiguration()    .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)    .Enrich.FromLogContext()    .WriteTo.Console()    .CreateLogger();// ... cdigo omitidotry{    Log.Information("Iniciando Web API");    await SeedProducts();    Log.Information("Corriendo en:");    Log.Information("https://localhost:7113");    Log.Information("http://localhost:5144");    app.Run();}catch (Exception ex){    Log.Fatal(ex, "Host terminated unexpectedly");    return;}finally{    Log.CloseAndFlush();}// ... cdigo omitido

Aqu la seccin "Log" de appsettings.json la podemos borrar, ya que no se usar.

El Message Template que tengo en el AuditLogBehavior es:

_logger.LogInformation("{RequetsName}: {@User} with request {@Request}", typeof(TRequest).Name, _currentUserService.User.Id, request);

Y al correr la aplicacin, se ver de la siguiente manera:

Y si queremos guardar los logs en un archivo en el mismo Web Server (que sirve como para consultarlos en tiempo real si usamos Azure), hacemos lo siguiente en Program.cs:

Log.Logger = new LoggerConfiguration()    .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)    .Enrich.FromLogContext()    .WriteTo.Console()    .WriteTo.File("log.txt", rollingInterval: RollingInterval.Day)  // <-------    .CreateLogger();

Con esto, si corremos la aplicacin, se crearn archivos txt con el nombre log{yyyyMMdd}.txt en la raiz del proyecto y con el siguiente contenido:

2022-04-14 10:42:31.447 -06:00 [INF] Iniciando Web API2022-04-14 10:42:32.417 -06:00 [INF] Corriendo en:2022-04-14 10:42:32.420 -06:00 [INF] https://localhost:71132022-04-14 10:42:32.422 -06:00 [INF] http://localhost:51442022-04-14 10:42:34.539 -06:00 [INF] CreateProductCommand: 759aa503-f916-4962-96ed-be0b416b5632 with request {"Description":"New Product","Price":9952,"$type":"CreateProductCommand"}2022-04-14 10:42:35.738 -06:00 [INF] CreateProductCommand: 759aa503-f916-4962-96ed-be0b416b5632 with request {"Description":"New Product","Price":9952,"$type":"CreateProductCommand"}2022-04-14 10:42:36.893 -06:00 [INF] CreateProductCommand: 759aa503-f916-4962-96ed-be0b416b5632 with request {"Description":"New Product","Price":9952,"$type":"CreateProductCommand"}2022-04-14 10:42:37.547 -06:00 [INF] CreateProductCommand: 759aa503-f916-4962-96ed-be0b416b5632 with request {"Description":"New Product","Price":9952,"$type":"CreateProductCommand"}2022-04-14 10:42:38.342 -06:00 [INF] CreateProductCommand: 759aa503-f916-4962-96ed-be0b416b5632 with request {"Description":"New Product","Price":9952,"$type":"CreateProductCommand"}2022-04-14 10:42:38.839 -06:00 [INF] CreateProductCommand: 759aa503-f916-4962-96ed-be0b416b5632 with request {"Description":"New Product","Price":9952,"$type":"CreateProductCommand"}2022-04-14 10:42:39.234 -06:00 [INF] CreateProductCommand: 759aa503-f916-4962-96ed-be0b416b5632 with request {"Description":"New Product","Price":9952,"$type":"CreateProductCommand"}

WriteTo.File tiene ms opciones de configuracin. Les recuerdo, hay Sinks para todo tipo de persistencia.

Y te preguntars al final, para qu sirve todo esto? La respuesta corta es: Diagnosticar. Cuando algo pasa en tu aplicacin, sabes aproximadamente cuando sucedi, lo nico que puedes hacer es ir a ver los logs y revisar que hizo el usuario para que tronara la aplicacin.

El sink de archivos es algo til, pero es ms til si usamos sinks como de Elastic Search o Application Insights. Permitir bsqueda y hacer Tracing de los Requests de tu aplicacin es un s o s que debes de tener en produccin.

Nota : Puedes visitar Github para ver todos los sinks disponibles.

Conclusin

El Logging y Tracing son temas que nos deben de interesar. Aunque solo hemos visto como crear Logs y mandarlos a un Sink de archivos y a Consola, de aqu puedes investigar ms y revisar que cumple las necesidades de tu proyecto.

Como siempre, cualquier pregunta, no dudes en buscarme en mi twitter en @balunatic.

Referencias

• serilog/serilog-aspnetcore - Github
• serilog/serilog - Github
• Ultimate Guid to Logging