Всем привет.
Пару лет назад мне пришлось заняться интеграцией СБП с АБС банка, писать надо было на C#. Первое о чём я подумал, конечно, это было логирование. Писать логи руками это конечно не мой выбор. Конечно хотелось чтобы при вызове метода в логи записывались его входные аргументы и выходные результаты и конечно эксепшены.
В C#, на тот момент (конец 2023 года), для этого надо было делать обёртку над классом, пример обёртки я приведу ниже. Этот код был проверкой гипотезы, для использования в работе надо дописать обработку множество нюансов (работа с итераторами хотя бы).
Что делает обёртка ? Обёртка проксирует вызовы к вложенному классу. При вызове метода обёртки происходит вызов соответствующего метода вложенного класса и возврат результата. Для логирования мы можем до запуска метода вложенного класса, записать в логи аргументы вызова, после вызова — записать в логи результат этого вызова. Если случиться эксепшен, то запишем этот эксепшен, и прокинем его дальше для перехвата и обработки уже там где положено по архитектуре.
Класс обёртка
Что нужно нашей обёртке ?
Класс обёртка должен быть наследником от DispatchProxy (using System.Reflection;)
Свойства класса:
-
Конечно логгер (FileArchivist Archivist)
-
Собственно экземпляр вложенного класса (T? _decorated)
-
Идентификатор входящего вызова для отслеживания цепочки выполнения (_correlationId)
public class LoggingDecorator<T> : DispatchProxy{ private readonly FileArchivist Archivist = new(); private T? _decorated; private string? _correlationId; } Реализацию логирования пишем в методе:
protected override object? Invoke( MethodInfo? targetMethod, object?[]? args ) Выполнение логирования
Собственно реализация:
var shouldLogging = targetMethod?.Name != "ToString"; if (shouldLogging) { Archivist.Before(DateTime.Now, args); } object? result; try { result = targetMethod?.Invoke(_decorated, args); } catch (Exception ex) when (ex is TargetInvocationException) { var realException = ex.InnerException ?? ex; if (shouldLogging) { Archivist.Exception(DateTime.Now, realException); } throw realException; } if (shouldLogging) { Archivist.After(DateTime.Now, result); } return result;Разберём построчно, что тут происходит.
var shouldLogging = targetMethod?.Name != "ToString";Определяемся с тем надо ли нам логировать этот вызов (хотя бы что бы не попасть на рекурсию).
if (shouldLogging) { Archivist.Before(DateTime.Now, args); }Если логировать надо, то логируем аргументы вызова.
object? result; try { result = targetMethod?.Invoke(_decorated, args); }Вызов оборачиваем в try / catch, что бы перехватить эксепшен, если он случиться.
catch (Exception ex) when (ex is TargetInvocationException) { var realException = ex.InnerException ?? ex; if (shouldLogging) { Archivist.Exception(DateTime.Now, realException); } throw realException; }Перехватываем исключения только от механизма вызова нужного метода у заданного экземпляра. Логируем исключение, если надо.
if (shouldLogging) { Archivist.After(DateTime.Now, result); } return result;Если надо логировать, то логируем результат.
Результат вызова возвращаем.
Как этим пользоваться
Теперь о том как этим пользоваться.
С использованием есть пара трудностей.
Во первых обёртка должна поддерживать точно тот же интерфейс что и вложенный класс. То есть, если у вложенного класса нет интерфейса, то его нельзя обернуть, то есть для всех классов который мы хотим автоматически логировать, придётся создать интерфейсы.
Второе, у класса обёртки в конструкторе не может быть ни каких аргументов, то есть инициализация состояния происходит отдельно, от создания экземпляра.
Собственно создание экземпляра происходит через статический метод, по сути заменяющий конструктор.
public static T Create(T decorated, string? correlationId) { object proxy = Create<T, LoggingDecorator<T>>() ?? throw new ArgumentNullException( "Fail on create proxy for " + (decorated?.GetType().FullName ?? "") ); ((LoggingDecorator<T>)proxy) .SetParameters(decorated, correlationId); return (T)proxy; }С помощью рефлексии создаём экземпляр класса обёртки, и инициализируем состояние экземпляра.
Метод инициализации:
private void SetParameters(T decorated, string? correlationId) { if (decorated == null) { throw new ArgumentNullException(nameof(decorated)); } _decorated = decorated; _correlationId = correlationId; Archivist.Initialize( _correlationId, _decorated); }Использование в коде
Интерфейс для класса, который хотим автоматически логировать:
public interface ICliProgram { public IArgumentStorage ProcureArguments( string[] args, ArgumentStorageFactory storageFactory ); public string Run(IArgumentStorage arguments); public IConfigurationRoot LoadProgramSettings(); public string[]? GatherArgumentsFromInput( string? input, string cliArgumentsSeparator, string optionNumbers ); public void SetCorrelationId(string correlationId); }В логах мы увидим только эти методы. Методы с модификатором доступа private и protected мы в логах не увидим. Из-за этого приходиться делать public методы, которые на самом деле private, но автоматически логи того стоят.
Собственно код с автоматическим логированием:
public static void Main(string[] args) { var correlationId = GetCorrelationId(args); var app = archivist. LoggingDecorator<ICliProgram>. Create(new Program(SettingsKey), correlationId); app.SetCorrelationId(correlationId); var arguments = app.ProcureArguments( args, new ArgumentStorageFactory() ); app.Run(arguments); }Построчный разбор кода с автоматическим логированием
Построчно:
var app = archivist. LoggingDecorator<ICliProgram>. Create(new Program(SettingsKey), correlationId);Создали прокси класс над нужным классом (что бы автоматически логировать его вызовы).
var arguments = app.ProcureArguments( args, new ArgumentStorageFactory() );Это уже поехала логика архитектуры, в логах мы увидим с какими аргументами вызывали метод и какой результат он вернул.
Архитектура предполагает вызов каждого приложения (CLI программы), как с аргументами вызова из командной строки, так и с аргументами вызова из «консольного» ввода (из потока STD_IN программы), откуда брать аргументы задаётся в конфиге программы.
app.Run(arguments);Запустили программу с надлежащими аргументами. В логах увидим с какими аргументами вызывали метод и какой результат он вернул.
Стоит ли так заморачиваться ради того, чтобы логи писали себя сами ? Я считаю оно того стоит. Такой стиль логирования побуждает дробить код на небольшие методы, потому что если писать стену текста, тогда и логи придётся писать вручную, а эта работа кажется лишней, когда эту работу за нас может сделать сам «компилятор».
Сериализация значений для записи в логи
Теперь про само логирование, о том как записывать в текстовый файл значения аргументов, которые не всегда строки. То есть каждый аргумент должен стать строкой, для этого можно у каждого класса переопределить метод ToString(). Но есть способ проще.
Воспользуемся сериализацией в JSON:
private static string serializeWithJson(object? obj) { var serilized = JsonConvert.SerializeObject(obj); if (serilized == "{}") { serilized = obj?.ToString(); } return serilized ?? "non-serializable-value"; }Если после сериализации получили пустой объект, то вызываем встроенный метод приведения к строке — ToString().
Если не смогли получить строковое представление, то возвращаем «non-serializable-value». (Когда увидим в логах «non-serializable-value», тогда напишем «кастомный» ToString() для этого класса).
Сериализация входных аргументов
args ??= Array.Empty<object>(); var arguments = new List<string?>(); foreach (var obj in args) { string serialized = serializeWithJson(obj); arguments.Add(serialized); } var values = new StringBuilder(). AppendJoin('\u00A0', arguments.ToArray());Аргументы вызова могу отсутствовать, это не редкость, поэтому если массив аргументов не задан, то присваиваем значение Array.Empty().
Каждый аргумент сериализуем отдельно, и склеиваем всё в одну строку через символ неразрывный пробел (‘\u00A0’). Логи надо писать так ,чтобы было потом удобно парсить, поэтому тут подумайте как будет лучше их писать — какой выбрать разделитель для отдельных частей лога, чтобы потом по этому разделителю, разбить строку на семантические части.
Сериализация результата на выходе
var jsonResult = serializeWithJson(result);Куда писать логи: в файл, в STD_OUT, в какой то сервис по UDP дело вкуса.
Полный код классов
Приведу законченные примеры кода для класса обёртки и для класса логера.
Класс обёртка
Класс обёртка
using System.Reflection; namespace archivist { /* base on https://learn.microsoft.com/ru-ru/archive/msdn-magazine/2014/february/aspect-oriented-programming-aspect-oriented-programming-with-the-realproxy-class */ /* base on https://stackoverflow.com/questions/38467753/realproxy-in-dotnet-core */ public class LoggingDecorator<T> : DispatchProxy { private readonly FileArchivist Archivist = new(); private T? _decorated; private string? _correlationId; protected override object? Invoke( MethodInfo? targetMethod, object?[]? args ) { var shouldLogging = targetMethod?.Name != "ToString"; if (shouldLogging && !Archivist.WasInitialized) { Archivist.Initialize(_correlationId, _decorated); } if (shouldLogging) { Archivist.GetReady(targetMethod); } if (shouldLogging) { Archivist.Before(DateTime.Now, args); } object? result; try { result = targetMethod?.Invoke(_decorated, args); } catch (Exception ex) when (ex is TargetInvocationException) { var realException = ex.InnerException ?? ex; if (shouldLogging) { Archivist.Exception(DateTime.Now, realException); } throw realException; } if (shouldLogging) { Archivist.After(DateTime.Now, result); } return result; } public static T Create(T decorated, string? correlationId) { object proxy = Create<T, LoggingDecorator<T>>() ?? throw new ArgumentNullException( "Fail on create proxy for " + (decorated?.GetType().FullName ?? "") ); ((LoggingDecorator<T>)proxy) .SetParameters(decorated, correlationId); return (T)proxy; } private void SetParameters(T decorated, string? correlationId) { if (decorated == null) { throw new ArgumentNullException(nameof(decorated)); } _decorated = decorated; _correlationId = correlationId; Archivist.Initialize(_correlationId, _decorated); } } }Класс логер
Класс логер
using Microsoft.Extensions.Configuration; using Newtonsoft.Json; using System.Reflection; using System.Text; namespace archivist { /* base on https://markpelf.com/1072/logging-proxy-in-c/ */ public class FileArchivist { private string CorrelationId = string.Empty; private string InvokeId = string.Empty; private string ClassName = string.Empty; private string MethodName = string.Empty; private Object LogLocker = new(); protected const string SettingsKey = "integrated-logger-settings-file"; private string? LogFilename = null; public bool WasInitialized { get; private set; } public FileArchivist() { WasInitialized = false; } private static string ProcureLogFilename { get { var secretConfig = new ConfigurationBuilder() .AddUserSecrets<FileArchivist>() .Build(); var fileWithSettings = secretConfig[SettingsKey] ?? ""; var config = File.ReadAllText(fileWithSettings); config = config.Trim(Environment.NewLine.ToArray<char>()); return config ?? string.Empty; } } private void MakeLogFilename() { if (LogFilename == null) { var filename = ProcureLogFilename; var isFileDefined = !string.IsNullOrEmpty(filename); if (!isFileDefined) { throw new Exception("Log filename is not defined"); } LogFilename = new StringBuilder(). AppendJoin( '_', new string?[] { filename, CorrelationId, DateTime.Now.Ticks.ToString(), $"{Guid.NewGuid()}.log" } ). ToString(); } } public void Initialize( string? correlationId, object? classExemplar ) { CorrelationId = correlationId ?? string.Empty; ClassName = classExemplar?.GetType().FullName ?? ""; MakeLogFilename(); WasInitialized = true; } public void GetReady( MethodInfo? methodInfo ) { InvokeId = $"invokeId={Guid.NewGuid()}"; MethodName = methodInfo?.Name ?? string.Empty; } public async void Before( DateTime now, object?[]? args) { args ??= Array.Empty<object>(); var arguments = new List<string?>(); foreach (var obj in args) { string serialized = SerializeWithJson(obj); arguments.Add(serialized); } var values = new StringBuilder(). AppendJoin('\u00A0', arguments.ToArray()); var message = new StringBuilder(). AppendJoin( ' ', new string?[] { now.Ticks.ToString(), CorrelationId, InvokeId, "RUN", ClassName, "->", MethodName, $"input ({values})", } ). ToString(); await WriteLogToFile(message); } private static string SerializeWithJson(object? obj) { var serialized = JsonConvert.SerializeObject(obj); if (serialized == "{}") { serialized = obj?.ToString(); } return serialized ?? "non-serializable-value"; } public async void After( DateTime now, object? result ) { var jsonResult = SerializeWithJson(result); var message = new StringBuilder(). AppendJoin( ' ', new string?[] { now.Ticks.ToString(), CorrelationId, InvokeId, "END", ClassName, "->", MethodName, $"output {jsonResult}", } ). ToString(); await WriteLogToFile(message); } public async void Exception( DateTime now, Exception exception) { var message = new StringBuilder(). AppendJoin( ' ', new string?[] { now.Ticks.ToString(), CorrelationId, InvokeId, "EXC", ClassName, "->", MethodName, exception.Message, } ). ToString(); await WriteLogToFile(message); } private Task WriteLogToFile(string logMessage) { lock (LogLocker) { if (!string.IsNullOrWhiteSpace(LogFilename)) { File.AppendAllText( LogFilename, logMessage + Environment.NewLine ); } } return Task.CompletedTask; } } } Проверку гипотезы (рабочий код) можно посмотреть на Гитхабе: https://github.com/SbWereWolf/ips-gateway
Подсказки в интернете которыми был вдохновлён этот код:
ссылка на оригинал статьи https://habr.com/ru/articles/931416/
Добавить комментарий