Log4j vs log4j2 성능과 기능 그리고 문제점 (자바 로깅 툴)

만약 현업 개발에 발을 담그지 못하신 분들이나 로거의 존재를 모르신다면 보통 자바의 시스템 출력기능을 사용 하 실 것이다.

 

그러나 System.out.print는 성능도 떨어지고 관리하기가 힘들기 때문에 개발 언어에 맞는 로깅 프레임 워크를 사용한다. Java 뿐만 아니라 모든 언어에서 말이다.

예를 들어 System.out.print는 콘솔에 출력을 할 때 기본으로 동기로 돌아가기 때문에 Concurrency 환경에서 성능 저하가 발생 할 수 있다. 반면 Logger들은 기본적으로 Asynchronous 형식으로 돌아가기 때문에 성능에는 문제가 없다.

취향과 상황에 맞게 데이터를 출력할지 말지를 커스터마이징 할 수 있다.

 

그 때문에 Logger, 혹은 Logging 툴이 존재 하는데 우리가 애플리케이션을 돌리고 상황을 모니터링하거나 기록된 출력물들을 보기 편하게 해주는 아주 편리한 도구이다. 개발 환경, 배포 환경에 따라서 로그 레벨을 지정해서 모든 로그를 볼 것인지, 보안을 위해 로그의 일부를 가릴 것인지, 아니면 심각한 에러 로그만 출력할지를 선택 할 수 있다.

 

추가로 Logging manager와 같은 부가 서비스는 실시간으로 출력된 로그들을 로그 매니징 서비스를 통해 원격서버에 스트리밍을 하거나 파일로 저장을 해서 로그 기록을 나중에 기간이 지나도 볼 수 있게 해주는 툴도 있다.

---

 

본인이 사용한 Java환경의 Logger에는 Log4j와 Log4j2가 있다. 이 둘은 기능 적인 면과 성능면에서 차이가 있지만 둘 다 지속적으로 사용되고 있는 로깅 패키지이다. 이번 글은 Perfomance와 reflection에 집중할 것이기 때문에 Logging 패키지의 사용법은 다루지 않겠다.

 

Log4j 와 Log4j2의 차이는 아래 공식 링크에 명시되어 있듯이 새로운 성능과 동기/기동기 기능들은 선보인다.

https://logging.apache.org/log4j/log4j-2.2/manual/index.html#:~:text=Log4j%202%20takes%20advantage%20of,at%20a%20fairly%20high%20level.

Overview - Apache Log4j 2

Apache log4j performance 출처: https://logging.apache.org/log4j/2.x/performance.html#tradeoffs

Log4j – Performance

 

그렇다면 왜 log4j 1은 아직도 존재하는가...? 확실하지 않지만 본인이 생각하기에는 이미 많은 레거시 코드가 log4j1을 사용하고 있기 때문이라 생각된다.

 

오늘 이 글을 작성하는 이유도 본인이 다른 팀의 코드를 사용하다가 log4j1을 기반으로 하는 코드로 일하게 되었는데, 아쉽게도 많은 불편함이 따르는 기법을 통해 성능저하를 피하고 있었기 때문이다.

 

이 전 게시글에 올렸던 것과 같이 String의 출력방식이 문제가 있어 다른 방식으로 logger를 사용한 것이다. 

https://marcobackman.tistory.com/18

String, String format, 그리고 String builder

 

해당팀의 logging 레벨은 debug는 로컬과 개발환경에서만, info레벨은 테스팅 환경에서만, 그리고 나머지 상위 레벨들은 다른 환경에서도 출력되게 끔 만들었다. 그러나 logger가 debug 이외의 환경에서 출력은 안 해도 string을 조합하는 것이 성능 저하의 문제점이다.

 

log4j string 성능 저하의 예시이다.

logger.debug("This is a code runs in debug. id=" + id + " , num=" + num);

 

더 정확하게 말하자면 실제 애플리케이션 환경이 테스팅이나 그 이상의 개발 환경이면 출력을 안하는 것은 정상작동 하지만, String을 조합을 먼저 하고 나중에 환경을 판별해 버리기 때문에 이미 JVM string pool 메모리에는 다음과 같은 string 문구들이 조합이 되어있는 상황이다. (id = 12, num = 1234이라고 가정하면)

• This is a code runs in debug. id=
• This is a code runs in debug. id=12
• This is a code runs in debug. id=12 , num=
• This is a code runs in debug. id=12 , num=1234

위와 같이, 코드 한 줄을 출력하기 위해 총 네줄의 string 구문이 제작되는 것도 모자라 환경에 맞지 않는 로그 레벨인데도 위의 스트링 열들이 하나도 사용되지가 않는 것이다.

 

그러면 우리는 어떻게 해서든 debug레벨이 적용이 안 되는 환경에서 debug 메시지를 조합하지 못하게 막아야 한다. 바로 if case로 제한을 하는 것이다.

if(logger.isDebugEnabled()) {
   logger.debug("This is a code runs in debug. id=" + id + " , num=" + num);
}

 

역시나 코드줄이 쓸모없이 길어졌고, 개발환경에 있는 다른 사람들이 디버그 로그를 작성한다면, 실수로 성능 저하 로그방식을 그대로 사용해 버릴 수도 있기 때문이다. 그러기 때문에 더 낳은 로그 매니징이 필요 한 것이다.

 

log4j2의 parametized string기법으로 아래의 코드 줄과 같이 작성해서 위의 모든 문제점이 해결되게 한다.

logger.debug("This is a code runs in debug. id={}, num={}", id, num);

이렇게 되면 코드는 판별 뒤, 스트링 조합이 들어가고 이 전 string format 게시물과 같이 4개의 스트링 문을 조합하는 것이 아닌 메모리에 한 줄의 스트링 열만 조합된다.

 

우리 팀은 항상 log4j2만 사용해 왔었기 때문에 log4j1을 사용하는 다른 팀의 코드를 봤을 때 이런 경험이 새로워서 올려본다.

 

추가로 해당 팀의 코드 logger에서 Reflection 문제까지 발견되었었는데 다음 글에서 다루어 보도록 하겠다.

 

---

여담으로 항상 로컬에서 임시 테스트 목적으로 logger가 아닌 print문을 사용하고 깜빡해서 안지우고 PR을 올리는 경우가 있는데 이 부분은 코드 검수자들이 잡아 줘야 한다. 한편으로 이러한 실수가 공감이 많이 가는데, 가장 빠르고 즉흥적으로 출력문을 바로 볼수 있는 방법이 print문이기 때문이다..