Покращте продуктивність логування у .NET в 10 разів із мінімальними зусиллями

Цей допис досліджує еволюцію технік логування (logging) у .NET — від базових реалізацій до просунутих. Ми розглянемо типові помилки, способи їх уникнення та як суттєво підвищити продуктивність логування (logging) з майже нулем зусиль. Поїхали!

Ітерація №0

Ми всі знаємо, наскільки важливе логування (logging) у наших застосунках, і майже в кожному проєкті можна знайти безліч операторів логування. Розгляньмо, наприклад, такий оператор логування (logging statement):

logger.LogTrace(  
 "Event {EventName} has been processed in {Time} ms",   
 eventName, time  
);

Роздивившись цей оператор логування уважніше, можна помітити кілька проблем:

  1. Надлишкове виділення пам’яті для рядків (string allocation), навіть якщо логер (logger) налаштований на вищий мінімальний рівень логування, ніж цей оператор.
  2. Викликається зайве упаковування (boxing) параметрів повідомлення у масив об’єктів, що створює проблеми, пов’язані з пам’яттю.
  3. Потенційні помилки під час виконання (runtime errors) у випадку відсутності параметра.
  4. Обмежене кешування форматерів (formatters), які перетворюють шаблони в реальні лог-повідомлення.

Ітерація №1

Щоб вирішити ці проблеми, Microsoft представила метод LoggerMessage.Define, який дозволяє задавати власне форматування та усувати зазначені проблеми.

Для цього потрібно визначити делегат оператора логування (logging statement delegate), наприклад:

private static readonly Action _callback =   
 LoggerMessage.Define(  
 LogLevel.Trace,  
 new EventId(eventId, nameof(EventProcessed)),  
 "Event {EventName} has been processed in {Time} ms"  
 );

Хоча це вирішує більшість проблем, код виглядає більше зрозумілим для машин, ніж для людей. Він важкий для підтримки, і важко уявити когось, хто із задоволенням замінить стандартні виклики логера (logger calls) на це.

Ітерація №2

Microsoft випустила генератор коду LoggerMessage (LoggerMessage source generator), який став основним інструментом для ефективного логування (logging). Цей генератор створює методи LoggerMessage.Define автоматично на основі певних декларацій методів. Наприклад:

[LoggerMessage(  
 Level = LogLevel.Trace,  
 Message = "Event {EventName} has been processed in {Time} ms"  
)]  
public partial void LogEventProcessesing(string eventName, double time);

По суті, він генерує той самий код, що і в попередньому прикладі, але у більш зрозумілій формі. Виглядає непогано, чи не так?

Я спробував використати цей підхід у проєкті середнього розміру, де є тисячі операторів логування (logging statements), але здався вже після чотирьох 😣. Я виявив, що цей підхід, хоча і кращий за ітерацію №1, все ж має кілька викликів:

  1. Він змушує вас організовувати свій проєкт певним чином. Ви або використовуєте окремий статичний клас для декларацій ваших лог-повідомлень (log message declarations), роблячи їх віддаленими від місць використання, або ж у вас з’являється купа часткових методів (partial methods) у класі, де ці оператори знаходяться (занадто багато не пов’язаного з бізнес-логікою коду + сам клас також потрібно зробити частковим 🫣).
  2. Все одно це багато шаблонного коду (boilerplate). Кількість коду для кожного оператора логування можна легко помножити на три…
  3. Це може призводити до непослідовності у використанні логера (logger) у вашому проєкті. А якщо ви бачите змішані підходи тут і там, це виглядає не дуже добре, як на мене.

pic

Ітерація №3

Я хочу повернутися до ітерації №0, оскільки вона пропонує простіший спосіб написання операторів логування (logger statements), зберігаючи переваги пізніших ітерацій. Як це можна реалізувати?

Ось тут і стає у нагоді AutoLoggerMessage.
Це ще один генератор коду (source generator), який виконує всю рутинну роботу за вас. Використовуючи звичайні методи ILogger.Log+, ви можете досягти приросту продуктивності до 90% відповідно до бенчмарків.

pic

Приріст продуктивності при використанні AutoLoggerMessage у порівнянні зі стандартними викликами методів ILogger.Log+.

Демонстрація:

pic

Як це працює?

Для тих, хто цікавиться деталями, я пояснив, як це працює тут, але давайте коротко розглянемо виклики, з якими я зіткнувся.

Розширення логера

Поточний набір методів-розширень для логера (logger extension methods) приймає лише params object[] для параметрів. Деякі реалізації логерів (наприклад, NLog) підтримують універсальну версію (generic version), але типова абстракція (default abstraction) цього не робить, що досить прикро.

Щоб уникнути упаковування (boxing) під час цих викликів, генератор AutoLoggerMessage забезпечує набір універсальних методів-розширень (generic extension methods), які будуть вибрані через правило більшої специфічності типів параметрів методу. Це гарантує, що незалежно від того, як ви викликаєте свої методи логування (logging methods), генератор має відповідну перевантажену версію, готову до використання.

Генератор коду (Source Generator)

Далі, генератор сканує ваш код у пошуках будь-яких методів Logger.Log+ і фіксує параметри, передані цим методам, які згодом використовуються для створення відповідних методів LoggerMessage.

Нарешті, генератор створює набір перехоплювачів (interceptors). Докладніше про перехоплювачі можна прочитати тут, але коротко — це своєрідний міст між викликами ваших методів логування (logging calls) і згенерованими методами LoggerMessage. Перехоплювачі перенаправляють запити на логування до правильних методів, забезпечуючи плавну роботу. Це доступно лише у .NET 8+, тому основною причиною, чому цільова платформа встановлена на 8, є саме це.

pic

Обмеження:

  • Цільова платформа — net8+. Її можна знизити до .NET 6, але це вимагатиме змін у репозиторії .NET runtime, що може зайняти більше часу. Для отримання оновлень перегляньте цю дискусію.
  • Це працює лише з абстракцією Microsoft.Extensions.Logging.ILogger.

Встановлення:

Є лише два швидкі кроки, щоб почати:

  1. Встановіть пакет: ви можете додати AutoLoggerMessage до свого проєкту через NuGet:
dotnet add package stbychkov.AutoLoggerMessage
  1. Увімкніть перехоплювачі (interceptors): ви можете увімкнути їх глобально для всіх проєктів через Directory.Build.props або для конкретного проєкту, додавши наступну конфігурацію:

 $(InterceptorsPreviewNamespaces);Microsoft.Extensions.Logging.AutoLoggerMessage   

І це все! З цього моменту пакет самостійно виконує всю необхідну роботу.

Чому б не спробувати і не поділитися своїми враженнями? Якщо вам подобається проєкт, ви можете поставити йому зірочку (star), щоб зробити його більш помітним для інших. Насолоджуйтесь!

Перекладено з: Boost .NET Logging Performance 10x with Minimal Effort

Leave a Reply

Your email address will not be published. Required fields are marked *