Log4J는 어떻게 소스 코드 줄번호를 얻어오나? 그리고 효율적 로깅. 프로그래밍

Log4J는 로깅시 소스 코드 이름과 줄번호도 함께 출력해 준다.

대체 어떻게 소스코드 이름과 줄번호를 얻어온단 말이냐?

예외를 날려서 예외의 StackTrace를 파싱해서 소스코드 이름과 줄번호를 얻어온다고 한다.

흠... 그런데, 이 예외 발생은 상당한 시간을 잡아먹는 작업이다.

이러한 상황에서 log.debug(String ..) 을 남발하게 되면 당연히 속도 감소가 생길 수 밖에 없다.
착각이다. 예외를 통한 소스 위치 찾기는 log.debug()를 직접 호출하더라도 Debug레벨이 아니면 실제로 작동하지 않으므로, 속도에 영향을 줄 수 없다.

예외 뿐만 아니라 로그 메시지에 함께 보내는 String 객체들 때문에도 엄청난 속도 감소가 발생한다.
String 객체를 단 한개만 로그에 사용하면 상관 없지만, 보통 로그 메시지는 String + String + ... 식으로 여러 문자열을 더해서 날리게 되는데, String이 불변객체(값을 변경할 수 없고, 값 변경이 필요할 경우에는 새로운 객체를 생성)이기 때문에, String 더하기를 할 때마다 새로운 객체를 생성하는 오버헤드가 발생한다. 이 문자열 +로 인한 오버헤드는 if 문으로 어떤 로그 레벨인지를 검사하는 것보다 아주 매우 매우 큰 수준이라고 한다.(어디선가 비교 결과를 본적 있는데 까먹었음... --;)

이것을 막기 위해서는 딴건 몰라도 로깅할 때 log.isDebugEnabled()로 필히 검사하고 로그를 남겨야 겠다.
if (log.isDebugEnabled()) {
    log.debug("로그야~~");
}

당연한 얘기지만 System.out.println()을 통한 로깅은 소스코드에 관한 정보도 안알려주고, 어떤 쓰레드에서 실행됐는지도 알 수 없고, 조건절을 통해서 String + 연산을 막을 수도 없고, 경우에 따라 로그 레벨도 조절할 수 없다.

System.out.println()을 통한 로깅 절대 금지!!

또한, 나는 Log4J를 직접 사용하는 것 보다는 Jakarta Commons Logging 사용을 적극 권장하고 싶다.

로거간의 충돌 현상이나, Log4J 사용이 뭔지 알 수 없는 이유로 불가능한 상황에 직면할 수 있는데, Commons Logging 을 사용하면 자기가 원하는 로거로 마음대로 제거하거나 끼워 넣을 수 있고, Log4J를 사용할 경우에는 특별한 설정과정 없이 바로 사용할 수 있기때문에 별다르게 귀찮을 것도 없다.

덧글

  • 백일몽 2005/11/15 11:10 # 삭제

    Log4E 를 사용하게 되면 자동으로 로그 넣어주는 부분에서 저렇게 if 체크를 해서 왜 하나 궁금했는데요.
    프로퍼티에 설정한 레벨에 따라 로그를 찍는 것 아니었나요?
  • 권남 2005/11/15 12:34 #

    일단 제가 예외 발생으로 인한 속도 저하에 대해 말한부분은 착각이었습니다.
    Debug 레벨이 아니면 어쨌든 예외를 발생시켜서 소스 위치를 확인하는 절차를 거치지 않을 것이기 때문입니다.

    하지만 log.debug("XXX 값 : + xxx + ", yyy 값 : " + yyy); 처럼 호출할 경우 + 연산을 할 때마다 String 객체가 생성되기 때문에 속도 저하가 발생하게 됩니다. 이럴 때 log.debug() 문을 if (log.isDebugEnabled()) 로 감싸면 로그 레벨이 Debug 레벨이 아니면 아예 String + 연산을 실행하지 않으므로 속도 저하가 없습니다.
    하지만 로그레벨이 INFO이고, 로그 명령을 if 문으로 감싸지 않으면 log.debug() 문이 일단은 호출이 되어야하고 호출되면서 String + 연산이 발생하면서 속도저하가 일어나고 .debug() 메소드 내부로 들어간 뒤에서야 로그 레빌이 INFO 레벨이므로 DEBUG를 찍을 필요가 없다고 판단하고 로그 찍기를 중지하므로 String + 연산으로 인한 속도 저하를 그대로 가져가야만 합니다.

    그래서 저 같은 경우에는 INFO/WARN/ERROR에 대해서는 if 문으로 감싸지 않지만, 최소한 DEBUG 에 대해서는 if 문으로 감쌉니다.
  • 백일몽 2005/11/15 13:20 # 삭제

    아하.. 그렇게 돼겠네요...
    자세한 설명 감사합니다. 다 이유가 있었군요.
  • sup 2007/12/16 00:45 # 삭제

    이의제기 :
    Exception을 throw해서 소스코드의 위치를 얻어오는것은 맞으나, log4j에서 debug라고해서 상기행위를 하는것은 아니고 설정에서 optional하게 적용하는것으로 알고 있습니다.
    다시말해서 option에서 해당 소스의 위치를 보여주지 않도록 한다면, debug일지라도 해당 process를 적용하지 않을 것입니다.
  • 권남 2007/12/16 13:38 #

    sup// 넵~ 맞습니다. log4j.properties에서 소스 코드 위치를 얻어오는 format을 적용해 두지 않았다면, throw를 하지 않는다고 합니다.
    제가 디폴트로 항상 소스 코드 위치를 얻어오도록 하기 때문에 저렇게 썼던 것 같습니다.
※ 로그인 사용자만 덧글을 남길 수 있습니다.