Serilog: структурное логирование в .NET

28.01.2021

Теги: #dotnet #csharp #aspnetcore #logging #serilog

Все разработчики используют логирование в своих приложениях, всем приходится их рано или поздно читать. Обычно логи пишутся и сохраняются “примитивно”, обычной строкой. Но далеко не всегда удобно искать нужную информацию в логах, записанных в таком формате.

Допустим, у нас есть задача логировать экземпляр класса RequestData, представленного ниже

internal class RequestData
{
    public string Property1 { get; } = "test1";
    public int Property2 { get; } = new Random().Next(1, 10);
    public DateTime Timestamp { get; } = DateTime.UtcNow;        
}

Используя встроенный в AspNetCore механизм логирования, пытаемся записать сообщение:

_logger.LogInformation("requestData = {RequestData}", requestData);
// или так, форма записи значения в данном примере не имеет
_logger.LogInformation($"requestData = {requestData}");
// в итоге на выходе получаем обычную строку вида:
// "requestData = AspNetCoreSerilogExample.Controllers.RequestData"

Чтобы залогировать все поля, нужно перегрузить для класса метод ToString, тогда на выходе мы можем получить примерно следующую строку - requestData = Property1='test1' Property2='3' Timestamp='28.01.2021 03:12:35'

Чтобы избежать подобного подхода, а также облегчить фильтрацию и чтение логов, лучше использовать структурное логирование. Для этого существует великолепный NuGet-пакет Serilog.

Serilog позволяет хранить записи в виде структур (объектов), имеет много возможных “таргетов” (Sinks), а также позволяет “расширять” логируемые данные с помощью Enrichments.

Для AspNetCore есть специальный пакет Serilog.

Настройка очень простая, все что нам нужно - это модифицировать класс Program:

public static class Program
{
    public static void Main(string[] args)
    {
        Log.Logger = new LoggerConfiguration()
            // минимальный уровень логирования - Debug
            .MinimumLevel.Debug()
            // Скрываем логи с уровнем ниже Warning для пространства имен Microsoft.AspNetCore*
            .MinimumLevel.Override("Microsoft.AspNetCore", LogEventLevel.Warning)
            // расширяем логируемые данные с помощью LogContext
            .Enrich.FromLogContext()
            // пишем логи в консоль с использованием шаблона
            .WriteTo.Console(outputTemplate: "[{Timestamp:HH:mm:ss} {Level:u3} {SourceContext}] {Message:lj}{NewLine}{Exception}")
            .CreateLogger();
        
        CreateHostBuilder(args).Build().Run();
    }

    private static IHostBuilder CreateHostBuilder(string[] args) =>
        Host.CreateDefaultBuilder(args)
            .UseSerilog() // подключаем Serilog как пройдера логирования по умолчанию
            .ConfigureWebHostDefaults(webBuilder => { webBuilder.UseStartup<Startup>(); });
}

После настройки Serilog, из конфигурационных файлов можно удалять секцию Logging, она больше не требуется.

Теперь наши логи будут писаться через Serilog в консоль, попробуем записать логи для простых типов данных, а также залогировать объект целиком:

// => requestData = {"Property1": "test1", "Property2": 2, "Timestamp": "2021-01-28T03:56:39.6968268Z", "$type": "RequestData"}
_logger.LogInformation("requestData = {@RequestData}", requestData);
// => Property2 = 3
_logger.LogInformation("Property2 = {Property2}", requestData.Property2);

В консоли вывод тоже выглядит симпатично, иногда помогает при локальных запусках приложений:

Но все это лишь малая доля полезностей от структурного логирования, в следующих статьях будет рассмотрена конфигурация Serilog с записью логов в ElasticSearch, а также использование Kibana для их чтения и анализа.

Исходный код проекта из статьи.

Полезные ссылки:

1. Serilog: GitHub репозиторий
2. Serilog Sinks
3. NuGet пакеты, связанные с Serilog
4. Плагин для работы со структурными логами в JetBrains Rider/Resharper

---

Комментарии