Расширяем log4net. Конкурентное логирование

Библиотека log4net известна и в представлении не нуждается. В ней есть практически всё, что нужно, «из коробки». Однако, есть специфические ситуации, в которых необходимо добавлять/расширять функциональность библиотеки. Конкретная ситуация: есть некоторая библиотека, которая выполняет логирование через log4net в некоторый логер (или несколько — не суть). Эта библиотека используется в N службах. Как сделать так, чтобы логирование происходило в единственный файл? Под катом объяснение, почему FileAppender+MinimalLock не подходит, и реализация Appender'а, который решает задачу. Отдельно хочу сказать, что вопрос о логировании в БД, по сети и т.п. в статье не рассматривается, т.к. это гораздо более серьёзная задача, которая (особенно для больших систем) требует длительного обдумывания и внедрения.

Сразу оговорюсь про тестовое окружение, поскольку в своих доводах я буду опираться на результаты тестов. Процессор i7 (4 ядра, 8 с учётом hyper-threading), приложение log4net.Extensions.Console выполняет в 8 потоках запись в лог с произвольным Sleep после записи. Количество записей в лог — 10000. Приложение BulkStarter запускает 10 экземпляров log4net.Extensions.Console и дожидается их выполнения. Таким образом, 10 процессов, по 8 потоков в каждом выполняют запись в единственный файл. Все временные характеристики были получены в таком тесте с помощью Stopwatch (таймер высокого разрешения до тактов).

FileAppender+MinimalLock

В log4net для записи логов в файл есть FileAppender. В нём реализована возможность эксклюзивной блокировки (используется по умолчанию) и, так называемой, MinimalLock. ExclusiveLock при инициализации log4net открывает файл для записи с возможностью чтения для остальных процессов. MinimalLock выполняет открытие/закрытие файла на каждую запись в файл. Соответственно, ExclusiveLock нам не подходит совсем (поскольку файл для всех процессов, кроме первого, который захватил блокировку над файлом, будет недоступен), а у MinimalLock есть ряд серьёзных недостатков:
Очень медленный (из 1:56 теста, непосредственно вызовы метода логирования заняли 1:40);
Конфликт блокировок, когда несколько процессов пытаются получить поток для записи (а это обозначает не запись в лог).
Пример конфигурации FileAppender'а с MinimalLock:
<appender name="FileAppender" type="log4net.Appender.FileAppender">
<file value="D:\1\test-minlock.log"/>
<lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%message%n"/>
</layout>
</appender>

ConcurrentMinimalLock

В поиске достойной замены я набрёл на статью 2008 года на Code Project — Logging into single file from multi-process. В статье описывается реализация ConcurrentMinimalLock, в которой производится буферизация сообщений, а также выполняется открытие файла в цикле (пока блокировка-таки не будет установлена). Вроде бы всё хорошо, однако время вызова метода логирования 1:04 из 1:20. Т.е. по-прежнему долго. И это ещё с учётом того, что это частично асинхронное логирование (при жёстком закрытии приложения всё из очередей будет потеряно).

ConcurrentFileAppender

Read more: Habrahabr.ru

Posted via email from Jasper-net