В log4j проверка производительности isDebugEnabled перед регистрацией улучшает производительность?

Я использую Log4J в моем приложении для регистрации. Ранее я использовал отладочный вызов, как:

Опция 1:

logger.debug("some debug text");

но некоторые ссылки предполагают, что лучше isDebugEnabled()сначала проверить , например:

Вариант 2:

boolean debugEnabled = logger.isDebugEnabled();
if (debugEnabled) {
    logger.debug("some debug text");
}

Поэтому мой вопрос: « Улучшает ли вариант 2 производительность каким-либо образом? ».

Потому что в любом случае у каркаса Log4J такая же проверка на debugEnabled. Для варианта 2 может быть полезно, если мы используем несколько операторов отладки в одном методе или классе, где каркасу не нужно вызывать isDebugEnabled()метод несколько раз (при каждом вызове); в этом случае он вызывает isDebugEnabled()метод только один раз, а если Log4J настроен на уровень отладки, то фактически он вызывает isDebugEnabled()метод дважды:

1. В случае присвоения значения переменной debugEnabled и
2. На самом деле вызывается методом logger.debug ().

Я не думаю, что если мы напишем несколько logger.debug()операторов в методе или классе и вызываем debug()метод в соответствии с вариантом 1, тогда это накладные расходы для каркаса Log4J по сравнению с вариантом 2. Поскольку isDebugEnabled()это очень маленький метод (с точки зрения кода), он может быть хорошим кандидатом на встраивание.

В этом конкретном случае вариант 1 лучше.

Защитный оператор (проверка isDebugEnabled()) предназначен для предотвращения потенциально дорогостоящих вычислений сообщения журнала, когда он включает в себя вызов toString()методов различных объектов и объединение результатов.

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

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

Смотрите мой ответ на связанный вопрос для получения дополнительной информации, и пример того, как сделать что-то подобное с log4j.

Так как в варианте 1 строка сообщения является константой, нет абсолютно никакой выгоды в обёртывании оператора ведения журнала условием, напротив, если в операторе журнала разрешена отладка, вы будете выполнять оценку дважды, один раз в isDebugEnabled()методе и один раз в debug()метод. Стоимость вызова isDebugEnabled()составляет порядка 5–30 наносекунд, что для большинства практических целей должно быть незначительным. Таким образом, вариант 2 нежелателен, потому что он загрязняет ваш код и не дает никакой другой выгоды.

Использование isDebugEnabled()зарезервировано для того, когда вы создаете сообщения журнала путем объединения строк:

Var myVar = new MyVar();
log.debug("My var is " + myVar + ", value:" + myVar.someCall());

Однако в вашем примере выигрыш в скорости отсутствует, поскольку вы просто регистрируете строку и не выполняете такие операции, как конкатенация. Поэтому вы просто добавляете в свой код раздувание и усложняете его чтение.

Я лично использую вызовы формата Java 1.5 в классе String следующим образом:

Var myVar = new MyVar();
log.debug(String.format("My var is '%s', value: '%s'", myVar, myVar.someCall()));

Я сомневаюсь, что есть много оптимизаций, но это легче читать.

Обратите внимание, что большинство API-интерфейсов ведения журналов предлагают форматирование «из коробки»: slf4j, например, обеспечивает следующее:

logger.debug("My var is {}", myVar);

который даже легче читать.

В Java 8 вам не нужно использовать isDebugEnabled()для повышения производительности.

https://logging.apache.org/log4j/2.0/manual/api.html#Java_8_lambda_support_for_lazy_logging

import java.util.logging.Logger;
...
Logger.getLogger("hello").info(() -> "Hello " + name);

Короткая версия: Вы также можете выполнить логическую проверку isDebugEnabled ().

Причины:
1- Если сложная логика / конкат строки. добавлен к вашему заявлению отладки, у вас уже будет проверка на месте.
2. Вам не нужно выборочно включать оператор в «сложные» отладочные операторы. Все заявления включены таким образом.
3- Вызов log.debug выполняет перед регистрацией следующее:

if(repository.isDisabled(Level.DEBUG_INT))
return;

Это в основном то же самое, что журнал вызовов. или кот. isDebugEnabled ().

ТЕМ НЕ МЕНИЕ! Это то, что думают разработчики log4j (как и в их javadoc, и вы, вероятно, должны пойти по этому пути).

Это метод

public
  boolean isDebugEnabled() {
     if(repository.isDisabled( Level.DEBUG_INT))
      return false;
    return Level.DEBUG.isGreaterOrEqual(this.getEffectiveLevel());
  }

Это Javadoc для него

/**
*  Check whether this category is enabled for the <code>DEBUG</code>
*  Level.
*
*  <p> This function is intended to lessen the computational cost of
*  disabled log debug statements.
*
*  <p> For some <code>cat</code> Category object, when you write,
*  <pre>
*      cat.debug("This is entry number: " + i );
*  </pre>
*
*  <p>You incur the cost constructing the message, concatenatiion in
*  this case, regardless of whether the message is logged or not.
*
*  <p>If you are worried about speed, then you should write
*  <pre>
*    if(cat.isDebugEnabled()) {
*      cat.debug("This is entry number: " + i );
*    }
*  </pre>
*
*  <p>This way you will not incur the cost of parameter
*  construction if debugging is disabled for <code>cat</code>. On
*  the other hand, if the <code>cat</code> is debug enabled, you
*  will incur the cost of evaluating whether the category is debug
*  enabled twice. Once in <code>isDebugEnabled</code> and once in
*  the <code>debug</code>.  This is an insignificant overhead
*  since evaluating a category takes about 1%% of the time it
*  takes to actually log.
*
*  @return boolean - <code>true</code> if this category is debug
*  enabled, <code>false</code> otherwise.
*   */

Как уже упоминалось, использование оператора guard полезно только в том случае, если создание строки требует много времени. Конкретные примеры этого - при создании строки будет запускаться ленивая загрузка.

Стоит отметить, что этой проблемы можно избежать, используя Simple Logging Facade для Java или (SLF4J) - http://www.slf4j.org/manual.html . Это позволяет вызывать методы, такие как:

logger.debug("Temperature set to {}. Old temperature was {}.", t, oldT);

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

Вы также можете очень легко «свернуть свою» версию этого.

Надеюсь это поможет.

Вариант 2 лучше.

По сути, это не улучшает производительность. Но это гарантирует, что производительность не ухудшается. Вот как.

Обычно мы ожидаем logger.debug (someString);

Но, как правило, по мере того, как приложение растет, многие переходят из рук в руки, особенно начинающие разработчики.

logger.debug (str1 + str2 + str3 + str4);

и тому подобное.

Даже если для уровня журнала установлено значение ERROR или FATAL, конкатенация строк происходит! Если приложение содержит много сообщений уровня DEBUG с конкатенацией строк, то это, безусловно, требует снижения производительности, особенно с jdk 1.4 или ниже. (Я не уверен, что в более поздних версиях jdk internall есть какой-либо stringbuffer.append ()).

Вот почему Вариант 2 безопасен. Даже конкатенации строк не происходит.

Как @erickson это зависит. Насколько я помню, isDebugEnabledуже debug()встроен метод Log4j.
Пока вы не выполняете дорогостоящих вычислений в своих операторах отладки, таких как циклы над объектами, выполняете вычисления и объединяете строки, на мой взгляд, все в порядке.

StringBuilder buffer = new StringBuilder();
for(Object o : myHugeCollection){
  buffer.append(o.getName()).append(":");
  buffer.append(o.getResultFromExpensiveComputation()).append(",");
}
log.debug(buffer.toString());

было бы лучше как

if (log.isDebugEnabled(){
  StringBuilder buffer = new StringBuilder();
  for(Object o : myHugeCollection){
    buffer.append(o.getName()).append(":");
    buffer.append(o.getResultFromExpensiveComputation()).append(",");
  }
  log.debug(buffer.toString());
}

Для одной строки я использую троичную часть внутри сообщения регистрации. Таким образом, я не делаю конкатенацию:

EJ:

logger.debug(str1 + str2 + str3 + str4);

Я делаю:

logger.debug(logger.isDebugEnable()?str1 + str2 + str3 + str4:null);

Но для нескольких строк кода

EJ.

for(Message mess:list) {
    logger.debug("mess:" + mess.getText());
}

Я делаю:

if(logger.isDebugEnable()) {
    for(Message mess:list) {
         logger.debug("mess:" + mess.getText());
    }
}

Поскольку многие люди, вероятно, просматривают этот ответ при поиске log4j2 и почти все текущие ответы не учитывают log4j2 или недавние изменения в нем, следует надеяться, что это ответ на вопрос.

log4j2 поддерживает поставщиков (в настоящее время их собственная реализация, но согласно документации планируется использовать интерфейс поставщика Java в версии 3.0). Вы можете прочитать немного больше об этом в руководстве . Это позволяет вам поставить дорогое создание сообщения журнала в поставщика, который создает сообщение, только если оно будет зарегистрировано:

LogManager.getLogger().debug(() -> createExpensiveLogMessage());

Это повышает скорость, потому что обычно объединять строки в тексте отладки, что дорого, например:

boolean debugEnabled = logger.isDebugEnabled();
if (debugEnabled) {
    logger.debug("some debug text" + someState);
}

Начиная с версии Log4j2.4 (или slf4j-api 2.0.0-alpha1), гораздо лучше использовать свободный API (или лямбда-поддержку Java 8 для отложенной регистрации ), поддерживающую Supplier<?>аргумент сообщения журнала, который может быть задан lambda :

log.debug("Debug message with expensive data : {}", 
           () -> doExpensiveCalculation());

ИЛИ с API slf4j:

log.atDebug()
            .addArgument(() -> doExpensiveCalculation())
            .log("Debug message with expensive data : {}");

Если вы используете вариант 2, вы делаете булеву проверку, которая выполняется быстро. В первом варианте вы выполняете вызов метода (помещая вещи в стек), а затем выполняете логическую проверку, которая все еще быстра. Проблема, которую я вижу, это последовательность. Если некоторые из ваших операторов отладки и информации обернуты, а некоторые нет, это не соответствует стилю кода. Плюс кто-то позже мог бы изменить оператор отладки, чтобы включить строки сцепления, что все еще довольно быстро. Я обнаружил, что когда мы завершили отладку и информацию в большом приложении и профилировали его, мы сэкономили пару процентов производительности. Не много, но достаточно, чтобы оно того стоило. Теперь у меня есть пара настроек макросов в IntelliJ для автоматического создания завернутых отладочных и информационных операторов для меня.

Я бы порекомендовал использовать Вариант 2 как де-факто для большинства, так как это не супер дорого.

Случай 1: log.debug («одна строка»)

Case2: log.debug («одна строка» + «две строки» + object.toString + object2.toString)

В то время, когда любой из них вызывается, строка параметра в log.debug (будь то CASE 1 или Case2) должна быть оценена. Вот что все подразумевают под «дорогой». Если перед ним есть условие isDebugEnabled (), их не нужно оценивать, где сохраняется производительность.

Начиная с версии 2.x, в Apache Log4j встроена эта проверка, поэтому в ней isDebugEnabled()больше нет необходимости. Просто сделайте, debug()и сообщения будут подавлены, если не включены.

Log4j2 позволяет форматировать параметры в шаблон сообщения, аналогично String.format(), избавляя от необходимости делать isDebugEnabled().

Logger log = LogManager.getFormatterLogger(getClass());
log.debug("Some message [myField=%s]", myField);

Пример простого log4j2.properties:

filter.threshold.type = ThresholdFilter
filter.threshold.level = debug
appender.console.type = Console
appender.console.name = STDOUT
appender.console.layout.type = PatternLayout
appender.console.layout.pattern = %d %-5p: %c - %m%n
appender.console.filter.threshold.type = ThresholdFilter
appender.console.filter.threshold.level = debug
rootLogger.level = info
rootLogger.appenderRef.stdout.ref = STDOUT