IT story

log4j에서 로깅 전에 isDebugEnabled를 확인하면 성능이 향상됩니까?

hot-time 2020. 5. 14. 08:05
반응형

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 () 메소드에 의해 호출됩니다.

옵션 1에 따라 logger.debug()메소드 또는 클래스에 여러 명령문을 작성하고 메소드를 호출 debug()하면 옵션 2와 비교하여 Log4J 프레임 워크에 오버 헤드가 있다고 생각하지 않습니다 isDebugEnabled(). 매우 작은 메소드 (코드 측면에서)이므로 인라인을위한 좋은 후보자가 되십시오.


이 경우 옵션 1이 더 좋습니다.

가드 문 (확인 isDebugEnabled())은 toString()다양한 객체 메소드를 호출 하고 결과를 연결하는 경우 로그 메시지를 계산하는 데 비용이 많이 드는 것을 방지하기 위해 존재 합니다.

주어진 예에서, 로그 메시지는 상수 문자열이므로 로거가 로그를 버릴 수 있도록하면 로거의 사용 가능 여부를 확인하는 것만 큼 효율적이며 분기가 적기 때문에 코드의 복잡성이 줄어 듭니다.

더 좋은 방법은 로그 문이 형식 스펙과 로거가 대체 할 인수 목록을 취하지 만 로거가 사용 가능한 경우에만 "lazily"인 최신 로깅 프레임 워크를 사용하는 것입니다. 이것이 slf4j가 취하는 접근법 입니다.

자세한 정보는 log4j로 이와 같은 작업을 수행하는 예제와 관련 질문에 대한 답변을 참조하십시오 .


옵션 1에서 메시지 문자열은 상수이므로 조건으로 로깅 명령문을 랩핑하는 데 절대적으로 이득이 없습니다. 반대로, 로그 명령문이 디버그 가능 인 경우 isDebugEnabled()메소드 에서 한 번 두 번 평가 됩니다. debug()방법. 호출 비용은 isDebugEnabled()5 ~ 30 나노초 정도이며 대부분의 실제 목적에는 무시할 수 있습니다. 따라서 옵션 2는 코드를 오염시키고 다른 이득을 제공하지 않기 때문에 바람직하지 않습니다.


를 사용하면 isDebugEnabled()문자열을 연결하여 로그 메시지를 작성할 때 사용 됩니다.

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

그러나 귀하의 예에서는 문자열을 로깅하고 연결과 같은 작업을 수행하지 않으므로 속도가 향상되지 않습니다. 따라서 코드에 부풀림을 추가하고 읽기가 더 어려워집니다.

개인적으로 다음과 같이 String 클래스에서 Java 1.5 형식 호출을 사용합니다.

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);

훨씬 더 읽기 쉽습니다.


짧은 버전 : 부울 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.
*   */

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);

옵션 2가 더 좋습니다.

그 자체로는 성능이 향상되지 않습니다. 그러나 성능이 저하되지 않도록합니다. 방법은 다음과 같습니다.

일반적으로 logger.debug (someString);

그러나 일반적으로 응용 프로그램이 커짐에 따라 많은 손이 바뀌고 초보자 개발자는 eSP를 볼 수 있습니다.

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

등.

Even if log level is set to ERROR or FATAL, the concatenation of strings do happen ! If the application contains lots of DEBUG level messages with string concatenations, then it certainly takes a performance hit especially with jdk 1.4 or below. (Iam not sure if later versions of jdk internall do any stringbuffer.append()).

Thats why Option 2 is safe. Even the string concatenations dont happen.


As others have mentioned using the guard statement is only really useful if creating the string is a time consuming call. Specific examples of this are when creating the string will trigger some lazy loading.

It is worth noting that this problem can be completed avoided by using Simple Logging Facade for Java or (SLF4J) - http://www.slf4j.org/manual.html . This allows method calls such as:

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

This will only convert the passed in parameters to strings if debug is enabled. SLF4J as its name suggests is only a facade and the logging calls can be passed to log4j.

You could also very easily "roll your own" version of this.

Hope this helps.


Like @erickson it depends. If I recall, isDebugEnabled is already build in the debug() method of Log4j.
As long as you're not doing some expensive computations in your debug statements, like loop on objects, perform computations and concatenate strings, you're fine in my opinion.

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

would be better as

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());
}

For a single line, I use a ternary inside of logging message, In this way I don't do the concatenation:

ej:

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

I do:

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

But for multiple lines of code

ej.

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

I do:

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

Since many people are probably viewing this answer when searching for log4j2 and nearly all current answers do not consider log4j2 or recent changes in it, this should hopefully answer the question.

log4j2 supports Suppliers (currently their own implementation, but according to the documentation it is planned to use Java's Supplier interface in version 3.0). You can read a little bit more about this in the manual. This allows you to put expensive log message creation into a supplier which only creates the message if it is going to be logged:

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

It improves the speed because it's common to concatenate strings in the debug text which is expensive eg:

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

If you use option 2 you are doing a Boolean check which is fast. In option one you are doing a method call (pushing stuff on the stack) and then doing a Boolean check which is still fast. The problem I see is consistency. If some of your debug and info statements are wrapped and some are not it is not a consistent code style. Plus someone later on could change the debug statement to include concatenate strings, which is still pretty fast. I found that when we wrapped out debug and info statement in a large application and profiled it we saved a couple of percentage points in performance. Not much, but enough to make it worth the work. I now have a couple of macros setup in IntelliJ to automatically generate wrapped debug and info statements for me.


I would recommend using Option 2 as de facto for most as it's not super expensive.

Case 1: log.debug("one string")

Case2: log.debug("one string" + "two string" + object.toString + object2.toString)

At the time either of these are called, the parameter string within log.debug (be it CASE 1 or Case2) HAS to be evaluated. That's what everyone means by 'expensive.' If you have a condition before it, 'isDebugEnabled()', these don't have to be evaluated which is where the performance is saved.


As of 2.x, Apache Log4j has this check built in, so having isDebugEnabled() isn't necessary anymore. Just do a debug() and the messages will be suppressed if not enabled.


Log4j2 lets you format parameters into a message template, similar to String.format(), thus doing away with the need to do isDebugEnabled().

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

Sample simple 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

참고URL : https://stackoverflow.com/questions/963492/in-log4j-does-checking-isdebugenabled-before-logging-improve-performance

반응형