Структурное логирование в .NET на примере Serilog

Все мы знаем, что логирование — вещь очень полезная для современного проекта. С помощью него можно быстро локализовать и устранить ошибку в продукте, восстановить кейс, который к ней привёл, посмотреть историю действий пользователя.

Существует несколько видов логирования, такие как:

1. Классическое — когда весь лог это набор строк, в котором порой сложно разобраться и что-то в нём проанализировать.

_logger.LogInformation($"The magic number is {number}");

2. Структурное — когда на одно событие будет создаваться две записи лога, одна запись это шаблон вывода сообщения, вторая запись — объект, который будет подставлен в шаблон.

_logger.LogInformation("The magic number is {number}", number);

Структурное логирование открывает возможности хранить и анализировать события в различного рода хранилищах, таких как NoSql, Sql базах данных. Для .NET существует множество сторонних библиотек для такого логирования, например Serilog или NLog.
Давайте рассмотрим, как воспользоваться одной из этих библиотек и начать вести лог правильно?

Классическое логирование

1. Создадим новый проект по шаблону ASP.NET Core Web API. По умолчанию после создания мы будем иметь такую структуру решения:

2. Изменим метод Get контроллера WeatherForecast, заменив его на следующий код:

public IEnumerable<WeatherForecast> Get(string city, int day) {     _logger.LogInformation($"Requested weather for city {city} on {day} day");      return Enumerable.Range(1, 5).Select(index => new WeatherForecast     {         Date = DateTime.Now.AddDays(index),         TemperatureC = Random.Shared.Next(-20, 55),         Summary = Summaries[Random.Shared.Next(Summaries.Length)]     })     .ToArray(); }

3. Запустим приложение и выполним GET запрос к http://localhost:7005/weatherforecast?city=Moscow&day=1 и посмотрим результат выполнения в консоли:

Видно, что запись события это просто строка, и куда бы она ни попала (файл, СУБД, журнал событий) — она так и останется строкой, из которой что-то значимое для анализа можно будет вытащить только с помощью регулярных выражений, как пример. Такой вариант мало кого устраивает и на помощь приходит структурное логирование.

Структурное логирование

Теперь изменим немного проект, который создали выше. Для его модификации будем использовать библиотеку Serilog.

1. Установим NuGet-пакеты Serilog, Serilog.Sinks.Console и Serilog.Extensions.Hosting.

2. В файле Program.cs добавим настройку и добавление Serilog в качестве логгера:

using Microsoft.AspNetCore.Builder; using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Hosting; using Microsoft.Extensions.Logging; using Serilog;  var builder = WebApplication.CreateBuilder(args); /* ..................................... */  Log.Logger = new LoggerConfiguration()     .Enrich.FromLogContext()     .WriteTo.Console()     .CreateLogger();  builder.Host.ConfigureLogging(logging => {     logging.AddSerilog();     logging.SetMinimumLevel(LogLevel.Information); }) .UseSerilog();  /* ..................................... */

3. В методе Get контроллера WeatherForecast изменим запись в лог:

_logger.LogInformation("Requested weather for city {City} on {Day} day", city, day);

Мы убрали интерполяцию строки и теперь значения city и day по порядку будут подставляться вместо якорей {City} и {Day} в шаблоне.

4. Снова запустим приложение и выполним GET запрос к http://localhost:7005/weatherforecast?city=Moscow&day=1 и посмотрим результат выполнения в консоли:

Видно, что наши значения, передаваемые в логгер окрасились в разные цвета. Всё потому, что они больше не считаются простой строкой, а являются объектами, подставляемыми в шаблон.

Также можно передавать и более сложные объекты, например пользовательские типы данных.
Единственное, что нужно помнить для сложных объектов — при указании якоря впереди ставится @ {@Weather} для обозначения Serilog’у, что объект пользовательский, либо в пользовательском объекте нужно переопределить метод ToString, дополнив его собственной реализацией.

Снова изменим код метода Get контроллера WeatherForecast:

public IEnumerable<WeatherForecast> Get(string city, int day) {     var result = Enumerable.Range(1, 5).Select(index => new WeatherForecast     {         Date = DateTime.Now.AddDays(index),         TemperatureC = Random.Shared.Next(-20, 55),         Summary = Summaries[Random.Shared.Next(Summaries.Length)]     })     .ToArray();      _logger.LogInformation("Requested weather for city {City} on {Day} day. The weather is {@Weather}", city, day, result.First());      return result; }

Затем запустим приложение и выполним GET запрос к http://localhost:7005/weatherforecast?city=Moscow&day=1 и посмотрим результат выполнения в консоли:

Сложный объект «разложился» по своим свойствам и в будущем готов для анализа логов(если мы сейчас говорим о чём-то более сложном, чем консоль).
В следующий раз мы разберемся, как воспользоваться структурным логированием в связке с ElasticSearch и увидим, как оно позволяет анализировать логи нашего приложения.

Вывод

У структурного логирования есть плюсы, такие как возможность отделять данные от события, с последующим анализом, простота настройки и использования.