Parte 2 – Open Telemetry en .NET 8 – Logging

Esta es la segunda parte de una serie de artículos que estaré publicando en este blog. En esta ocasión hablaremos sobre Logging con OpenTelemetry y .NET 8.

De todas las señales de telemetría, los registros (logs) tienen la mayor trayectoria. La mayoría de los lenguajes de programación disponen de capacidades de registro incorporadas o utilizan bibliotecas de registro muy conocidas y difundidas.

Para métricas y rastreos, OpenTelemetry adopta un enfoque innovador, creando una nueva API desde cero y proporcionando implementaciones completas en diversos lenguajes.

Pero, el enfoque con los registros es un poco distinto. Para que OpenTelemetry sea eficaz en el ámbito de los registros, es esencial que apoye la infraestructura existente y las bibliotecas de registro, al tiempo que ofrece mejoras e integración con el resto del ecosistema de observabilidad cuando sea posible.

Esta es, básicamente, la filosofía detrás del soporte de registros de OpenTelemetry. Se valoran las soluciones de registro existentes y se garantiza que OpenTelemetry sea compatible con las bibliotecas de registro actuales y con las soluciones de recopilación y procesamiento de registros.

Limitaciones de las soluciones que No Utilizan OpenTelemetry

Desafortunadamente, las soluciones de registro actuales están débilmente integradas con las demás señales de observabilidad. Los registros suelen tener un soporte limitado en las herramientas de rastreo y monitoreo, utilizando información de correlación disponible pero a menudo incompleta, como atributos de tiempo y origen.

No existe un método estandarizado para incluir información sobre el origen y la fuente de los registros que sea uniforme con los rastreos y métricas, lo que permitiría correlacionar completamente todos los datos de telemetría de manera precisa y robusta.

Así es como se ve una típica canalización de recolección de observabilidad no basada en OpenTelemetry hoy en día:

Como bien se visualiza anteriormente, a menudo, hay diferentes bibliotecas y agentes de recolección que utilizan distintos protocolos y modelos de datos, lo que resulta en datos de telemetría almacenados en sistemas separados que no saben cómo trabajar juntos de manera eficientemente.

Definamos algunos conceptos de OpenTelemetry:

En OpenTelemetry, los identificadores de rastreo y los identificadores de span son fundamentales para la observabilidad en sistemas distribuidos.

• Identificador de Rastreo (Trace ID): Es un identificador único que se asigna a una operación completa, permitiendo seguir una solicitud desde su inicio hasta su finalización a través de múltiples servicios.
• Identificador de Span (Span ID): Es un identificador único para cada operación específica dentro de un rastreo, representando una unidad de trabajo dentro de la operación más grande.

Estos identificadores permiten correlacionar y rastrear solicitudes de manera precisa, facilitando la identificación de problemas y la comprensión del comportamiento del sistema.

Logging en OpenTelemetry

El rastreo distribuido introdujo la propagación del contexto de rastreo, y este concepto puede aplicarse también a los registros. Si los registros incluyeran identificadores de contexto de rastreo, se lograría una mejor correlación entre registros y rastreos, así como entre registros de diferentes componentes en un sistema distribuido, aumentando su valor.

Uno de los enfoques evolutivos prometedores para las herramientas de observabilidad es estandarizar la correlación de registros con rastreos y métricas, añadir soporte para la propagación de contexto distribuido en registros y unificar la atribución de origen de estas señales. OpenTelemetry sigue esta visión emitiendo registros, rastreos y métricas conforme a sus modelos de datos, y procesándolos de manera uniforme con el OpenTelemetry Collector. Este enfoque asegura una correlación precisa de las señales en el backend. La siguiente imagen ejemplifica lo comentado anteriormente:

OpenTelemetry define una nueva API para rastreos y métricas, pero no para registros debido a la diversidad y legado existente en el ámbito de los registros. Hay muchas bibliotecas de registro en diferentes lenguajes, cada una con su propia API, y muchos lenguajes de programación tienen estándares establecidos para usar ciertas bibliotecas, como Log4j o Logback en Java.

También existen innumerables aplicaciones o sistemas preconstruidos que emiten registros en ciertos formatos. Los operadores de estas aplicaciones tienen poco o ningún control sobre cómo se emiten los registros. OpenTelemetry necesita soportar estos registros.

Dada esta situación, en OpenTelemetry se tiene el siguiente enfoque:

1. OpenTelemetry define un modelo de datos para los registros. El propósito de este modelo es tener un entendimiento común de qué es un LogRecord, qué datos necesitan ser registrados, transferidos, almacenados e interpretados por un sistema de registro.
2. Se espera que los sistemas de registro recién diseñados emitan registros según el modelo de datos de registros de OpenTelemetry.
3. Los formatos de registro existentes pueden ser mapeados de manera inequívoca al modelo de datos de registros de OpenTelemetry. El OpenTelemetry Collector puede leer estos registros y traducirlos al modelo de datos de registros de OpenTelemetry.
4. OpenTelemetry define una API de Puente para que los autores de bibliotecas conecten las bibliotecas de registro existentes con su modelo de datos. No se recomienda a los desarrolladores de aplicaciones usar esta API directamente, ya que las bibliotecas de registro actuales suelen ser más completas.
5. OpenTelemetry define una implementación de SDK de la API de Puente, que permite la configuración del procesamiento y exportación de LogRecords.

Este enfoque permite a OpenTelemetry leer los registros existentes de sistemas y aplicaciones, proporciona una manera para que las nuevas aplicaciones emitan registros ricos y estructurados que cumplan con OpenTelemetry, y asegura que todos los registros se representen finalmente según un modelo de datos de registro uniforme en el que los backends puedan operar.

OpenTelemetry Collector

El OpenTelemetry Collector se utiliza para la recolección de registros según la especificación de OpenTelemetry. Sus funcionalidades incluyen:

• Soporte para el tipo de datos de registros y las pipelines de registro.
• Capacidad para leer y monitorear archivos de texto, manejar esquemas comunes de rotación de registros y reanudar la lectura desde puntos de control.
• Capacidad para interpretar y personalizar formatos de registros de texto.
• Recepción de registros mediante protocolos de red comunes como Syslog.
• Envío de registros a través de protocolos de red comunes o formatos específicos de proveedores.

Logging en Aplicaciones .NET

El registro (Log) es crucial en el desarrollo de software, proporcionando información valiosa para la depuración, el monitoreo del rendimiento y la resolución de problemas. En .NET, frameworks como Log4Net y Serilog facilitan la configuración y las mejores prácticas de registro. Además, la interfaz ILogger de .NET ofrece una forma estandarizada de implementar el registro, integrándose con varios proveedores para añadir consistencia.

En OpenTelemetry, cualquier dato fuera de un rastreo distribuido o métrica se considera un registro. Estos registros, que incluyen eventos, contienen detalles para la depuración y diagnóstico.

La biblioteca Microsoft.Extensions.Logging soporta el registro en .NET, permitiendo a los desarrolladores registrar mensajes, filtrarlos y formatearlos según sea necesario, y configurar proveedores que manejan y almacenan los mensajes en diferentes destinos. OpenTelemetry mejora estos registros y permite su correlación con otras señales de observabilidad.

Configurar el Logging con OpenTelemetry

Requisitos previos:

• Descargar e instalar .NET SDK 8+ en tu computadora.
• Descargar Visual Studio Code o Visual Studio 2022.

Paso 1: Instalar los paquetes de dependencias de OpenTelemetry.

dotnet add package OpenTelemetry
dotnet add package OpenTelemetry.Exporter.OpenTelemetryProtocol
dotnet add package OpenTelemetry.Exporter.Console
dotnet add package OpenTelemetry.Extensions.Hosting
dotnet add package OpenTelemetry.AutoInstrumentation

Paso 2: Agregar OpenTelemetry como sistema de registro en Program.cs:

En el archivo Program.cs, agrega OpenTelemetry como sistema de registro. Aquí estamos configurando las siguientes variables:

• serviceName: Es el nombre de del servicio de registro. Configuramos el nombre del servicio con ResourceBuilder.

Aquí tienes un archivo Program.cs de ejemplo con las variables configuradas.

using System.Diagnostics;
using OpenTelemetry.Logs;
using OpenTelemetry.Resources;

var builder = WebApplication.CreateBuilder(args);

var resourceBuilder = ResourceBuilder.CreateDefault()
    // add attributes for the name and version of the service
    .AddService(serviceName: "OpenTelemetryDotnetLogging", serviceVersion: "1.0.0");

builder.Logging.ClearProviders()
    .AddOpenTelemetry(loggerOptions =>
    {
        loggerOptions
            .SetResourceBuilder(resourceBuilder)
            .AddConsoleExporter();

        loggerOptions.IncludeFormattedMessage = true;
        loggerOptions.IncludeScopes = true;
        loggerOptions.ParseStateValues = true;
    });


// Add services to the container.
// Learn more about configuring Swagger/OpenAPI at https://aka.ms/aspnetcore/swashbuckle
builder.Services.AddEndpointsApiExplorer();
builder.Services.AddSwaggerGen();

var app = builder.Build();

// Configure the HTTP request pipeline.
if (app.Environment.IsDevelopment())
{
    app.UseSwagger();
    app.UseSwaggerUI();
}

app.UseHttpsRedirection();

var summaries = new[]
{
    "Freezing", "Bracing", "Chilly", "Cool", "Mild", "Warm", "Balmy", "Hot", "Sweltering", "Scorching"
};

app.MapGet("/weatherforecast", () =>
{
    var forecast =  Enumerable.Range(1, 5).Select(index =>
        new WeatherForecast
        (
            DateOnly.FromDateTime(DateTime.Now.AddDays(index)),
            Random.Shared.Next(-20, 55),
            summaries[Random.Shared.Next(summaries.Length)]
        ))
        .ToArray();
    return forecast;
})
.WithName("GetWeatherForecast")
.WithOpenApi();

app.MapGet("/", (ILogger<Program> logger) => {
    var status = "Running";
    var currentTime = DateTime.UtcNow.ToString();

    logger.LogInformation($"El estado de la aplicación cambió a '{status}' a las '{currentTime}'");
    

    return $"Hola desde los registros de OpenTelemetry, aquí está mi id de actividad: {Activity.Current?.Id}";
});

app.Logger.StartingApp();

app.Run();

record WeatherForecast(DateOnly Date, int TemperatureC, string? Summary)
{
    public int TemperatureF => 32 + (int)(TemperatureC / 0.5556);
}

internal static partial class LoggerExtensions
{
    [LoggerMessage(LogLevel.Information, "Iniciando la aplicación...")]
    public static partial void StartingApp(this ILogger logger);
}

Detalles del código en el archivo Program.cs:

• LoggerExtensions es una clase estática parcial; el uso de partial permite extender esta clase a otros archivos.
• Contiene un único método estático, StartingApp, que está marcado como partial y tiene el atributo LoggerMessage aplicado.
• El atributo LoggerMessage define una plantilla de mensaje de registro con un ID de mensaje, nivel de registro (en este caso, Información) y el propio mensaje de registro (“Iniciando la aplicación…”).

Una vez iniciado el anterior programa, podremos ver en la consola algo similar a:

Building...
LogRecord.Timestamp:               2024-08-06T17:56:47.8872224Z
LogRecord.CategoryName:            opentelemetry-dotnet-logging
LogRecord.Severity:                Info
LogRecord.SeverityText:            Information
LogRecord.FormattedMessage:        Iniciando la aplicación...
LogRecord.Body:                    Iniciando la aplicación...
LogRecord.Attributes (Key:Value):
    OriginalFormat (a.k.a Body): Iniciando la aplicación...
LogRecord.EventId:                 225744744
LogRecord.EventName:               StartingApp

Resource associated with LogRecord:
service.name: OpenTelemetryDotnetLogging
service.version: 1.0.0
service.instance.id: cdebc516-7602-4d35-9647-dd166d3c8fe9
telemetry.sdk.name: opentelemetry
telemetry.sdk.language: dotnet
telemetry.sdk.version: 1.9.0

Los logs se visualizan a nivel de consola con información importante e identificadores que pueden ser de ayuda para rastrear una operación que incluso puede ser distribuida (lo vamos a ver más a profundidad en siguientes artículos). A continuación se muestra un log generado por la llamada HTTP al endpoint principal (“/”);

LLamada HTTP:

LogRecord.Timestamp:               2024-08-06T19:54:40.1276467Z
LogRecord.TraceId:                 996992c3a509f5d0c315ee59e5614aef
LogRecord.SpanId:                  7fe8a11e5dd07e14
LogRecord.TraceFlags:              None
LogRecord.CategoryName:            Program
LogRecord.Severity:                Info
LogRecord.SeverityText:            Information
LogRecord.FormattedMessage:        El estado de la aplicación cambió a 'Running' a las '8/6/2024 7:54:40 PM'
LogRecord.Body:                    El estado de la aplicación cambió a 'Running' a las '8/6/2024 7:54:40 PM'
LogRecord.Attributes (Key:Value):
    OriginalFormat (a.k.a Body): El estado de la aplicación cambió a 'Running' a las '8/6/2024 7:54:40 PM'
LogRecord.ScopeValues (Key:Value):
[Scope.0]:SpanId: 7fe8a11e5dd07e14
[Scope.0]:TraceId: 996992c3a509f5d0c315ee59e5614aef
[Scope.0]:ParentId: 0000000000000000
[Scope.1]:ConnectionId: 0HN5MA6DG4SFB
[Scope.2]:RequestId: 0HN5MA6DG4SFB:00000001
[Scope.2]:RequestPath: /

Resource associated with LogRecord:
service.name: OpenTelemetryDotnetLogging
service.version: 1.0.0
service.instance.id: 08992eae-31b4-4b7b-80eb-cadecb47f7a0
telemetry.sdk.name: opentelemetry
telemetry.sdk.language: dotnet
telemetry.sdk.version: 1.9.0

Como podemos observar el log posee información que puede ser co-relacionada de manera distribuida. El Log tiene la estructura de metadatos que son enviados vía protocolo OTEL.

Paso 3: Definición del nivel de logs predeterminado que se mostrará

En el archivo appsettings.json, la configuración para OpenTelemetry y los logs define niveles de registro específicos para mejorar la observabilidad:

{
  "Logging": {
    "LogLevel": {
      "Default": "Error",
      "Microsoft.AspNetCore": "Error"
    },
    "OpenTelemetry": {
      "LogLevel": {
        "Default": "Information",
        "Microsoft.AspNetCore": "Warning"
      }
    }
  }
}

Para modificar el nivel de registro a visualizarse, se puede modificar la sección OpenTelemetry, dónde las propiedades se definen a continuación:

• Default: Registra mensajes de nivel Information y superiores, capturando eventos significativos sin abrumar con detalles. Puede modificarse por ejemplo para mostrar a partir de mensajes de tipo Debug.
• Microsoft.AspNetCore: Registra mensajes de nivel Warning y superiores para componentes de ASP.NET Core relacionados con OpenTelemetry, ayudando a identificar problemas importantes. También puede personalizarse el nivel según se defina.

Paso 4: Cómo Funciona la Auto-Instrumentación

La auto-instrumentación en OpenTelemetry para .NET se logra utilizando las APIs DiagnosticSource y Activity, que proporcionan hooks en varias partes del runtime de .NET y sus bibliotecas. El SDK de OpenTelemetry .NET escucha estos hooks, recopila datos y crea spans en consecuencia.

Existen paquetes de auto-instrumentación disponibles para varias bibliotecas y frameworks populares, incluyendo:

• OpenTelemetry.Instrumentation.AspNetCore: Para instrumentar aplicaciones ASP.NET Core.
• OpenTelemetry.Instrumentation.Http: Para instrumentar solicitudes HTTP salientes realizadas con HttpClient.
• OpenTelemetry.Instrumentation.SqlClient: Para instrumentar llamadas a bases de datos SQL Server realizadas con System.Data.SqlClient o Microsoft.Data.SqlClient.

Paso 5: Habilitar la Auto-Instrumentación

Para habilitar la auto-instrumentación, se debe instalar los paquetes NuGet correspondientes a las bibliotecas que se desea instrumentar. Una vez instalados, se puede habilitar la auto-instrumentación añadiendo los métodos de extensión correspondientes como se indica a continuación:

builder.Services.AddOpenTelemetry().WithMetrics(opts => opts
    .SetResourceBuilder(ResourceBuilder.CreateDefault().AddService(serviceName: "OpenTelemetryDotnetLogging", serviceVersion: "1.0.0"))
    .AddMeter(builder.Configuration.GetValue<string>("BookStoreMeterName"))
    .AddAspNetCoreInstrumentation()
    .AddRuntimeInstrumentation()
    .AddProcessInstrumentation()
    .AddOtlpExporter(opts =>
    {
        opts.Endpoint = new Uri(builder.Configuration["Otlp:Endpoint"]);
    }));  

En conclusión, tenemos un conjunto de herramientas y librerías como lo es OpenTelemetry para integrar a nuestras aplicaciones de manera transparente e intercambiable si más adelante queremos utilizar otros proveedores ya afianzados en el mercado.

Hemos llegado al final de este artículo, en la siguiente parte profundizaremos mucho más en temas como Trace, Métricas, Exportadores e integración con servicios externos como Prometheus, Grafana, Loki, Jagger, entre otros.

Pueden obtener el código fuente de los ejemplos en el siguiente enlace.