2016-07-01 8 views
1

Недавно я экспериментировал с Log4j 2 протоколированием и попытался сравнить его производительность с Logback на моей локальной машине Mac. Удивительно, но я вижу, что Logback работает лучше в моих тестах. Я ожидал, что Log4j 2 будет лучше, чем Logback, как заявлено на сайте Log4j 2, поэтому я хочу проверить, не ошибаюсь ли я в использовании Log4j 2.Log4j 2 performance: однопоточное ведение журнала консоли в Logback, чем Log4j 2?

Для тестирования я использовал прямые Log4j 2 и Logback без используя SLF4J. Кроме того, ConsoleAppender использовали для обеих структур лесозаготовок, и образец, который я испытываемый:

<Pattern>%d{YYYY-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n</Pattern> 

Тест каротаж код:

logger.info("This is a bootstrap message"); 

long start = System.currentTimeMillis(); 
for (int i = 1; i <= 1000000; i++) { 
    logger.info("Order={} successfully processed", "ABC123"); 
} 
long end = System.currentTimeMillis(); 
logger.info("time taken to process={} ms", end - start); 

Я побежал тест 10 раз для каждого входа отдельно и попытался взять среднее время, затраченное на обработку. Неожиданно в каждом прогоне журнал выполнялся лучше. Я попытался отключить ведение журнала по умолчанию GC, который поставляется с Log4j 2 с использованием Params:

-Dlog4j2.enable.threadlocals=false -Dlog4j2.enable.direct.encoders=false 

, но я до сих пор не видел каких-либо улучшений по сравнению Logback. Может ли кто-нибудь подтвердить, что я делаю, правильно или нет?

log4j 2 конфигурации:

<Configuration status="INFO" debug="false"> 
<Appenders> 
    <Console name="Console" target="SYSTEM_OUT"> 
     <PatternLayout pattern="%d{YYYY-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n" /> 
    </Console> 
</Appenders> 

<Loggers> 
    <Logger name="com.mycompany.app" level="INFO"/> 
    <Root level="INFO"> 
     <AppenderRef ref="Console" /> 
    </Root> 
</Loggers> 
</Configuration> 

Logback конфигурации:

<configuration debug="true" scan="true" scanPeriod="1 hour"> 

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> 
    <layout class="ch.qos.logback.classic.PatternLayout"> 
     <Pattern> 
      %d{YYYY-MM-dd HH:mm:ss:S} [%thread] %-5level %logger{36} - %msg%n 
     </Pattern> 
    </layout> 
</appender> 

<logger name="com.mycompany.app" level="info"/> 

<root level="info"> 
    <appender-ref ref="STDOUT"/> 
</root> 

</configuration> 
+0

В любом случае вы можете сделать 'Task.Run (() => logger.info (« Order = {} успешно обработан »,« ABC123 »));' который будет запускать его в другом потоке, чтобы вы не заблокировать. Только проблема, которая может возникнуть, - это умение «забыть» и «забыть», то есть, если оно терпит неудачу, вы не узнаете об этом. – sed

+0

Привет, Стэн, спасибо, но это не имеет никакого значения для их производительности, и обе эти рамки будут вам полезны, я пытаюсь посмотреть, не сделал ли я что-то неправильно при настройке log4j 2 с моего конца. – Suresh

+0

Прошу также показать конфигурацию Log4j2 и Logback чтобы люди могли воспроизвести ваш тест. –

ответ

2

При создании тестов, как это вы действительно должны использовать JMH. Я бы предложил вам посмотреть тесты в модуле log4j-perf для примеров того, как это сделать.

Кроме того, вы проверяете только один поток. Многие проблемы с logback обнаруживаются только в многопоточных случаях. Вы можете видеть это на некоторых графиках по адресу http://logging.apache.org/log4j/2.x/performance.html. Обратите внимание, что все данные этих графиков взяты из тестов в модуле log4j-perf, которые вы можете запускать самостоятельно.

Кроме того, если вы не собираетесь регистрироваться на консоли, я бы не использовал это в тесте, так как это самое медленное место для регистрации, хотя следующая версия log4j будет иметь некоторые улучшения к этому.

И наконец, если у вас есть вопросы о наших тестах, пожалуйста, не стесняйтесь спрашивать в одном из списков рассылки log4j. Ремко работает с некоторыми экспертами по тестированию производительности и может предоставить вам хорошие рекомендации о том, как создавать хорошие осмысленные тесты.

+0

Привет @rgoers, Спасибо за ваш ответ – Suresh

7

Я думаю, это здорово, что вы пытаетесь самостоятельно убедиться, что производительность Log4j2 действительно так хороша, как рекламируется.

Я проверил ваш тест, и это мои результаты. Как вы можете видеть, ваш тест дает немного лучший результат для Log4j 2, чем Logback на моем ноутбуке.

Log4j 2.6.1 Logback 1.1.7 
----------- ------------- 
    7,337 ms  7,413 ms  
    6,956 ms  7,097 ms  
    6,748 ms  7,827 ms  
    6,828 ms  7,480 ms  
    6,745 ms  7,067 ms  
    7,146 ms  7,003 ms  
    6,852 ms  7,036 ms  

Итак, что означают эти результаты? Ваш тест показывает, что синхронная пропускная способность Консоль appender от поток немного лучше в Log4j 2, чем в Logback.

Чтобы получить более полное представление о производительности лесозаготовительных библиотек вы хотите сравнить асинхронных протоколирования, различные appenders (особенно файлов Appender) и ведение журнала с несколько нитей.

  • Asynchronous logging является гораздо быстрее, чем синхронная запись, а также приложения, которые заботятся о производительности, как правило, необходимо войти в асинхронном режиме. Я считаю, что производительность асинхронного журналирования является самым важным эталоном при сравнении производительности библиотек журналов.
  • Запись в консоль составляет не менее 50x slower (!), Чем запись в файл. Это замедлит ваше приложение и должно быть очень осторожно используется (и предпочтительно избегается) в производственной конфигурации. Таким образом, измерение записи в консоли не очень полезно. Большинство приложений регистрируются в файле, поэтому приложение «Файл» может стать лучшим местом для начала исследования эффективности.
  • Многие приложения многопоточные. Конфликт блокировок может замедлить ваше приложение, если библиотека регистрации не была тщательно разработана для решения этой проблемы. Если вы измеряете ведение журнала из нескольких потоков, вы обнаружите, что мелкозернистая блокировка Log4j 2 дает much higher throughput than Logback. (При асинхронном Протоколировании difference is even more pronounced.)

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

В целом я рекомендую посмотреть на JMH на очень прочный и простой в использовании инструмент для бенчмаркинга. Log4j 2 performance page указывает на тесты JMH, используемые для получения результатов на странице. (Например, FileAppenderBenchmark.) Это может быть хорошей отправной точкой для ознакомления с JMH и тестирования производительности в целом.

Удачи, и оставайтесь любопытными!

+0

Привет, @Remko, Спасибо за ваше время за запуск моих образцов кода. Я посмотрю JMH и попытаюсь сравнить результаты. Я опубликую результаты здесь в ближайшее время. – Suresh

+0

Как клонировать репозиторий Log4j2 на рабочий стол и запускать тесты локально? – Suresh

+0

Клонирование и строительство: https://logging.apache.org/log4j/2.x/build.html В большинстве тестов JMH есть javadoc о том, как их запускать. –

Смежные вопросы