Структурное логирование делает один небольшой шаг вперед по сравнению с обычными записями.
Идея
Обычные лог-записи состоят из строк и для поиска записи среди массива текста нам приходится использовать регулярные выражение
_logger.Warning("Запись в лог файл. Пост на хабре ID"+postId); Структурное логирование хранит записи в виде объектов (структур). Например, с помощью JSON
_logger.Warning("Запись в лог файл. Пост на хабре {ID}", postId); Будет сохранено две записи:
- Шаблон для конечного вывода строки «Запись в лог файл. Пост на хабре {ID}»
- Объект, который будем подставлять в шаблон: {«ID»:1, type:Number}
Главное преимущество данного подхода заключается в том, что теперь можно хранить объект integer ID в виде отдельного параметра, например в NoSql БД. И осуществлять удобный и быстрый поиск с использованием типизированных операций сравнения вместо написания регулярных выражений.
Serilog
Одной из удобных библиотек .NET, которые поддерживают структурное логирование является Serilog.
Библиотека поддерживает все основные функции логирования, которые есть у log4net, Nlog, и других известных библиотек:
- Несколько общепринятых типов записи:
Verbose — самое низкоуровнивое и детальное логирование (например, пришедшие аргументы в метод)
Debug — данные для отладки кода, на один уровень выше Verbose (например, какой метод запускали, и результат выполнения)
Warning — предупреждение для бизнес-процесса, не должно содержать Debug данные (например, запустили расчет зарплат)
Error — ошибка в приложении, которое не ожидали
Fatal — исключительная ошибка останавливающая бизнес процессы приложения (например, перенаправили пользователя в PayPal и оплата покупателя не равна ожидаемой сумме).
- Разные типы хранения, называемых в Serilog стоком: текстовый файл, реляционные БД, NoSql БД, Windows Events, http/s запросы, и т.д.
- Удобная конфигурация через код, так и через .config файлы
Итак, после установки Serilog Nuget пакета, настраиваем конфигурацию. Сделаем это в коде вместо .config файла.
var logger = new LoggerConfiguration()
.MinimumLevel.Verbose() // ставим минимальный уровень в Verbose для теста, по умолчанию стоит Information
.WriteTo.ColoredConsole() // выводим данные на консоль
.WriteTo.RollingFile(@"C:\Logs\Log-{Date}.txt") // а также пишем лог файл, разбивая его по дате
// есть возможность писать Verbose уровень в текстовый файл, а например, Error в Windows Event Logs
.CreateLogger();Теперь можно передавать объект logger через Dipendency Injection, или сразу его использовать.
Допустим мы создаем программу для диагностики автомобиля и нам необходима информация о производителе, серии и дате впуска. И конечно, чтобы все хранилось в структурном виде.
logger.Debug("Request for vehicles {Manufature}, {Series}, {ProductionYear}", "BMW", "F02", new DateTime(2015, 1,1));
// search returns 10 vehicles
logger.Verbose("Found {FoundVehiclesCount}", 10);
Поскольку мы использовали вывод в консоль и файл, то и результат будет в виде привычной строки.
Одной из удобных особенностей является добавка часто используемых свойств. Для web приложения это может быть сессия пользователя, посещаемый URL, данные браузера. В более общем случае можно добавить версию приложения. Сделать это можно с помощью свойства Enrich и уже встроенных классов, или написать свой.
var logger = new LoggerConfiguration()
.Enrich.With<HttpRequestIdEnricher>()
.Enrich.With<HttpRequestUrlEnricher>()
.Enrich.With<HttpRequestUserAgentEnricher>()
.Enrich.With<UserNameEnricher>();
.Enrich.WithProperty("ApplicationVersion", config.ApplicationVersion)
.CreateLogger();
Для удобного вывода в консоль или текстовый файл сложных объектов лучше подсказать шаблону Serilog о том, что используем именно сложный объект, а не примитивный тип, добавив символ @. Иначе будет выводится typeof(MyClass).ToSting().
logger.Debug("We are using anonymous object instead of simple string/integer {@Car}", new {Manufacture="Toyota", Production = new DateTime(2015, 1,1)});
Seq
Приложение Seq приходит на помощь для удобного хранения и поиска структурных логов.
Работает Seq в виде windows сервиса, который принимает REST-запросы, а внутри хранит данные в NoSql БД.
После установки Seq необходимо также добавить в приложение Serilog.Sinks.Seq Nuget пакет. А далее подружить наш Serilog с Seq.
var logger = new LoggerConfiguration()
.MinimumLevel.Verbose()
.WriteTo.Seq("http://localhost:5341")
.CreateLogger();
Теперь можно удобно делать поиск по нашим полям, включая сравнение чисел и дат
Параметры поиска можно сохранять и использовать в других частях приложения. Добавляем Environment в Dashboard
А можно добавить real-time Dashboard отображение ошибок, пришедших именно от приложения «MyApp», версии «1.2.1» и произошедших в методе «Repository.GetUserByIdAndPassword()».
Бизнес требования
Как и любую новую, модную, светящуюся программу надо проверять, задавая вопросы:
«Какую выгоду несет данная программа для бизнеса?», «Какую задачу она решает и за какую цену?».
Часто в отношение логирования цели сводятся к
- Уменьшить трудозатраты по нахождению ошибок в программе.
- Иметь возможность восстановить историю действий пользователя. Например, для выяснения действительно ли товар оплачен.
- Быть в курсе ошибок, так как они ведут к потерям пользователей и прибыли.
Если первые два пункта решаются детальными записями и удобным поиском, то информирование об ошибках часто пропускают. Я это называю «спокойствием в неведении». Откроем журналы событий Windows и окажется, что почти на каждом сервере есть программы, которые сыпятся с критическими ошибками.
С помощью расширений Seq можно информировать о происходящих событиях. К примеру, сразу посылать сообщение программисту/администратору, если случилась критическая ошибка. И отправлять список всех ошибок, произошедших за день или неделю. Настроить расширения можно в разделе Seq -> Settings -> Apps
Минусы структурного логирования
К минусу структурного логирования можно отнести необходимость в определении параметров по которым будет производится поиск. Они же потом будут использоваться для создания NoSql индексов. Если забыли определить параметр, то поиск сводится к старому сканированию строк через регулярные выражения.
Гигантский шаг в этом направлении делает приложение Splunk. Идея заключается в сборе строковых данных, абсолютно любых и в любом формате (логи приложения, события о работе ОС, и т.д.). А далее потрясающее разбиение строки в зависимости от запросов и динамическое построение результата через Map/Reduce. Splunk является большой инфраструктурой для сбора и анализа данных, и выходит за тему логирования и данной статьи.
