Как Мгновенно Улучшить Вашу Журнал Java с 7 Твиками Logback

Тесты производительности помогут вам понять, как Logback работает под давлением

Ведение журнала важно для серверных приложений, но оно обходится дорого. Однако удивительно видеть, как небольшие изменения и изменения конфигурации могут оказать влияние на пропускную способность журналирования приложения. В этом посте мы будем оценивать производительность Logback с точки зрения количества записей в минуту. Мы выясним, какие приложения лучше всего работают, что такое разумный режим, и каковы некоторые из удивительных побочных эффектов методов Async, просеивания и ведения журнала консоли. Давайте доберемся до этого.

Основы для эталона

По своей сути, Logback основан на Log4j с настройками и улучшениями под предвидением Ceki Gülcü . Или, как говорится, лучше Log4j . Он имеет встроенный API-интерфейс slf4j, более быструю реализацию, конфигурацию XML, разумный режим и набор полезных приложений, о которых я расскажу чуть позже.

Тем не менее, существует немало способов войти в систему с различными наборами Appenders, шаблонами и режимами, доступными в Logback. Мы взяли набор часто используемых комбинаций и протестировали их на 10 параллельных потоках, чтобы выяснить, какие из них могут работать быстрее. Чем больше записей журнала записывается в минуту, тем эффективнее метод и больше ресурсов для обслуживания пользователей. Это не точная наука, но, если быть более точным, мы провели каждый тест 5 раз, удалили верхний и нижний выбросы и взяли среднее значение результатов. Чтобы быть честным, все написанные строки журнала также имели одинаковую длину 200 символов.

** Весь код доступен на GitHub прямо здесь . Тест проводился на компьютере Debian Linux с процессором Intel i7-860 (4 ядра при 2,80 ГГц) с 8 ГБ оперативной памяти.

Первый тест: сколько стоит синхронный лог-файл?

Сначала мы взглянули на разницу между синхронной и асинхронной регистрацией. При записи в один файл журнала FileAppender записывает записи непосредственно в файл, а AsyncAppender передает их в очередь, которая затем записывается в файл. Размер очереди по умолчанию равен 256, и когда он заполнен на 80%, он перестает пропускать новые записи более низких уровней (кроме WARN и ERROR).

Таблица сравнивает между FileAppender и различными размерами очереди для AsyncAppender. Async вышел на первое место с размером очереди 500.

• Твик # 1: AsyncAppender может быть в 3,7 раза быстрее, чем синхронный FileAppender. На самом деле, это самый быстрый способ войти во все приложения.

Он работал намного лучше, чем конфигурация по умолчанию, которая даже отстает от синхронизации FileAppender, который должен был завершиться последним. Так что же могло случиться?

Поскольку мы пишем сообщения INFO и делаем это из 10 одновременных потоков, размер очереди по умолчанию может быть слишком маленьким, а сообщения могли быть потеряны до порогового значения по умолчанию. Глядя на результаты 500 и 1 000 000 размеров очереди, вы заметите, что их пропускная способность была одинаковой, поэтому размер очереди и порог для них не были проблемой.

• Твик # 2: AsyncAppender по умолчанию может вызвать пятикратное снижение производительности и даже потерять сообщения. Обязательно настройте размер очереди и DiscardingThreshold в соответствии с вашими потребностями.

** Установка AsyncAppender’s queueSize и discardingThreshold

Второй критерий: действительно ли шаблоны сообщений имеют значение?

Теперь мы хотим увидеть влияние шаблонов записи журнала на скорость записи. Чтобы сделать это справедливым, мы сохранили длину строки журнала (200 символов) даже при использовании разных шаблонов. Запись Logback по умолчанию включает в себя дату, поток, уровень, имя регистратора и сообщение, поиграв с ним, мы попытались выяснить, как это повлияет на производительность.

Этот тест демонстрирует и помогает увидеть все преимущества соглашений об именах регистраторов. Просто не забудьте изменить его имя в соответствии с классом, в котором вы его используете.

• Твик № 3: Наименование регистратора по имени класса обеспечивает 3-кратное повышение производительности.

Удаление логгеров или имен потоков добавляло около 40-50-50 записей в минуту. Не нужно писать информацию, которую вы не собираетесь использовать. Переход на минимальный уровень также оказался немного более эффективным.

• Твик № 4: по сравнению с шаблоном по умолчанию, использование только полей уровня и сообщения обеспечило на 127 тыс. Больше записей в минуту.

Третий контрольный показатель: Дорогая осторожность, ты не выйдешь играть?

В разумном режиме один файл журнала может быть доступен из нескольких JVM. Это, конечно, снижает производительность из-за необходимости обрабатывать другую блокировку. Мы протестировали разумный режим на 2 JVM, записывающих в один файл, используя тот же тест, который мы использовали ранее.

Благоразумный режим принимает удар, как и ожидалось, хотя я предположил, что удар будет сильнее.

• Настройка № 5: Используйте разумный режим только тогда, когда он вам абсолютно необходим, чтобы избежать снижения пропускной способности.

** Настройка разумного режима в FileAppender

Четвёртый тест: как ускорить синхронную регистрацию?

Давайте посмотрим, как работают синхронные приложения, отличные от FileAppender. ConsoleAppender записывает в system.out или system.err (по умолчанию system.out) и, конечно, также может быть передан в файл. Вот так мы умеем считать результаты. SocketAppender выполняет запись в указанный сетевой ресурс через сокет TCP. Если цель не в сети, сообщение будет удалено. В противном случае он принимается так, как если бы он был создан локально. Для сравнения, сокет отправлял данные на одну и ту же машину, поэтому мы избегали проблем с сетью.

К нашему удивлению, явный доступ к файлу через FIleAppender обходится дороже, чем запись в консоль и передача его в файл. Тот же результат, другой подход и около 200 тысяч записей в минуту. SocketAppender работает аналогично FileAppender, несмотря на добавление сериализации между ними, сетевой ресурс, если он существует, будет нести большую часть накладных расходов.

• Твик # 6: передача ConsoleAppender в файл обеспечивает пропускную способность на 13% выше, чем при использовании FileAppender.

Пятый контрольный ориентир: Теперь мы можем поднять его на ступеньку выше?

Еще один полезный метод, который есть в нашем наборе инструментов, — SiftingAppender. Просеивание позволяет разбить журнал на несколько файлов. Наша логика заключалась в том, чтобы создать 4 отдельных журнала, каждый из которых содержал журналы 2 или 3 из 10 потоков, которые мы запускаем в тесте. Это делается путем указания дискриминатора, в нашем случае, logid, который определяет имя файла журналов:

** Настройка SiftingAppender

Еще раз наш FileAppender берет удар вниз. Чем больше выходных целей, тем меньше нагрузка на блокировки и меньше переключения контекста. Основным узким местом в ведении журнала, как и в примере с Async, является синхронизация файла.

• Твик № 7: Использование SiftingAppender может увеличить пропускную способность в 3,1 раза.

Вывод

Мы обнаружили, что способ достижения максимальной пропускной способности — использование настроенного AsyncAppender. Если вы должны использовать синхронное ведение журнала, лучше просеять результаты и использовать несколько файлов по некоторой логике. Я надеюсь, что вы нашли полезную информацию о тесте Logback и ждем ваших комментариев в комментариях ниже.