프로젝트에 적용할 Log 라이브러리 정하기
저는 프로젝트 Helparty를 만들어가면서 수많은 오류들을 만났고 그 오류들은 저의 사소한 오류인 것 부터 시작해 중요한 구조적인 문제까지 다양한 것들이었습니다.
이러한 오류들을 해결하기 위해서는 실행된 코드의 흔적을 알려주는 Log가 필요합니다. 그리고 코드를 훗날 유지보수 할 때 개발자의 시간을 절약해주고 편하게 작업하는데 Log는 필수적입니다. 하지만 이러한 목적을 위해서라면 System.out.println() [이하 sysout]을 사용해도 충분합니다. 그럼 왜 sysout을 사용하지 않고 로그 라이브러리를 사용해야 하는 지 알아보겠습니다.
System.out.println을 사용하지 않고 로그 라이브러리를 사용하는 이유
sysout을 사용하면 자바를 처음 배울 때 모두가 알게되는 log를 남겨주는 메서드입니다.
이 메서드는 다른 logger에 비해 로그를 남길 때 개발자들에게 알려주는 정보가 매우 빈약합니다 그리고 로그 정보를 파일에 남기지 않고 오직 콘솔에만 정보를 보여주어 다른 협업하는 개발자들에게 프로그램 정보를 공유하는 데 적절하지 않습니다.
하지만 이러한 이유들 보다 더 중요한 사용해서는 안되는 이유가 있습니다. 그것은 바로 두가지의 원인으로 인한 성능저하를 유발하기 때문입니다. 그 두가지 원인에 대해 알아보겠습니다.
1. Synchronized
sysout은 동기화 메서드입니다. 그 말은 여러 쓰레드가 sysout 메서드를 사용하려고 할 때, 하나의 쓰레드만 이 메서드를 사용하게 하고 다른 쓰레드들은 모두 대기한다는 것을 의미합니다.
더 자세하게 알아보면 sysout은 System이라는 Object 클래스를 상속받은 final 클래스에서 PrintStream의 인스턴스인 out을 사용해서 println메서드를 호출한 것입니다. 그리고 println은 write()와 newLine()으로 구성되어 있습니다.
println -> print -> write() + newLine()
여기서 write() 와 newLine()이 동기화 메서드입니다.
그래서 다른 쓰레드들을 대기시켜서 성능을 낮추는 결과를 만듭니다.
동기화는 멀티쓰레드를 운용하는 환경에서 데이터의 정합성을 유지시켜주어 프로그램의 안정성을 유지시켜주는 역할을 해주지만 서비스를 안정적으로 유지시켜주는 것과는 관련이 없는 Log를 찍어주는 작업에는 불필요합니다.
2. Blocking I/O
sysout을 사용하지 말아야 하는 이유 중 두번째는 sysout이 블로킹을 발생시킨다는 것입니다. 동기화 과정을 통해서 하나의 쓰레드만이 sysout에 들어가서 작업을 하고 있는데 화면에 보여줄 데이터가 준비되었고 이제 화면에 그 데이터를 보여주는 작업을 합니다. 이때 운영체제에서 하드웨어와 연결해주는 kernel에게 일을 시키고 응답을 기다리는데 이때, cpu는 잠깐 kernel이 일을 다할 때까지 기다리게 됩니다.
이러한 이유로 sysout은 동기화 처리로 하나의 스레드만을 처리해서 첫번째로 성능을 느리게 만들고 두번째로 blocking I/O를 발생시켜 cpu가 일을 하지 않게 되는 상황까지 유발하여 절대 실서비스를 하는 프로그램의 코드에는 남겨서는 안됩니다. 그리고 제가 사용하려는 Logger는 로깅을 비동기적으로 처리하고 메인 스레드를 block하지 않게 해줍니다.
그럼 이제 어떤 Log를 사용하여야 하는지 고르기 위해 Log라이브러리들을 비교해보겠습니다.
Log 라이브러리 비교
사람들이 많이 사용하는 Log 라이브러리에는 LogBack과 Log4j2가 있습니다. LogBack은 스프링 프레임워크에서 기본으로 제공하는 Logger입니다. Log4j2는 전에 있던 Log4j를 개선시켜 나온 라이브러리 입니다.
하나씩 알아보겠습니다.
LogBack
http://logback.qos.ch/reasonsToSwitch.html
Reasons to prefer logback
Reasons to prefer logback over log4j Logback brings a very large number of improvements over log4j, big and small. They are too many to enumerate exhaustively. Nevertheless, here is a non-exhaustive list of reasons for switching to logback from log4j. Keep
logback.qos.ch
LOGBack 공식 문서에서 특징을 정성스레 적어놔서 이를 기반으로 요약해서 알아보겠습니다.
Faster implementation
LogBack은 새롭게 작성된 것이 아니라 오랫동안 검증된 Log4j의 아키텍처를 기반으로 재작성 되었습니다.
다만, 강조하는 점은 성능은 약 10배 정도 개선되었고, 설치 메모리 공간은 더 적게 사용한다고 합니다.
Extensive batterty of tests
LogBack은 Log4j2와 같은 개발자가 만들었습니다. 따라서 log4j를 통해 얻은 많은 테스트 자료들이 있습니다. 그것이 Log4j보다 더 뛰어난 것을 만들 수 있는 기반이 되었습니다.
Automatic reloading of configuration files
LogBack을 사용하는 이유가 되는 기능 중 하나입니다.
하나의 예로 운영서버에서는 로그레벨을 WARN 또는 ERROR로 하는게 보통입니다.
하지만 특정 부분에서 더 자세한 로그를 봐야할 필요성이 있다면 INFO로 바꾸게 됩니다.
이때 log4j는 서버를 '셧다운'하고 '재설정'을 한 다음 '서버기동'을 해야합니다.
즉, 서버를 다시 '재기동'해야 한다는 번거러움이 있는데, LogBack은 그러지 않아도 됩니다.
그 이유는 내부를 스캐닝하는 별도의 스레드가 알아서 로그 레벨을 바꿔서 알려주기 때문입니다.
하지만, '이러한 추가적인 스레드를 운용하면 메모리 자원을 서비스를 하는 것을 희생해서 가져다 쓰는 것이 아닌가?'
하는 의문이 들 수 있습니다.
이러한 의문에 대한 답을 LogBack은 다시 적절하게 대처하고 있습니다.
공식문서를 보면 이러한 스레드를 '스캐닝 스레드'라고 부르고 이것은 메모리에 대한 점유율을 최소화하고
그 예로 '100개의 스레드가 초장 백만번 호출을 해도 시스템에 눈에 띄는 무리를 주지 않는다' 라고 답합니다.
Graceful recovery from I/O failures
LogBack은 FileAppender와 RollingFileAppender를 포함한 모든 하위 클래스는 I/O 장애로부터 정상적으로 복구할 수 있습니다. 따라서 파일 서버가 일시적으로 실패할 경우, 로그를 다시 실행하기 위해 프로그램을 다시 시작할 필요가 없습니다.
Automatic removal of old log archives
아카이빙 된 파일은 서비스를 지속하게 되면 계속 쌓이게 됩니다. 이러한 파일은 처음에 별로 양이 많지 않을 때는 괜찮겠지만 점점 쌓이게 되면 결국 자원 낭비로 이어질 것입니다.
이 부분을 해결하기 위해 LogBack은 일정 기간이 지나면 서비스에 부담을 주지 않기 위해 파일을 삭제할 것입니다.
Prudent mode
하나의 서버에서 다수의 JVM이 기동중일 경우 하나의 파일에 로그를 수집하려고 할 때 사용하는 기능입니다.
이 기능을 통해 멀티 스레드인 상황에서 LogBack을 사용하여 효율적으로 처리하게 됩니다.
이 이외에도 공식문서에서는 다양한 기능을 설명하고 있습니다.
요약
대략적으로 (1)불필요한 서버 재기동을 하지 않아도 되는 편의성, (2)메모리를 효율적으로 점유한 점, (3)멀티 스레드 환경에서의 대처법 이정도로 요약되는거 같습니다.
이제 Log4J2에 대해 알아보겠습니다.
Log4J2
http://logging.apache.org/log4j/2.x/index.html
Log4j – Apache Log4j 2
API Separation
Log4j2는 기본적으로 Log4j2를 보안한 라이브러리입니다. 그리고 Facade 패턴으로 구현되어 다른 Log 라이브러리들과 사용할 수 있습니다. 그 예로 LogBack의 앞에서 Facade 형태로 사용되어질 수 있습니다.
Improved Performance
Log4J2는 비동기 로거입니다. 그래서 다중 스레드 환경에서 비동기 로거는 Log4J 1.x 와 LogBack보다 처리량이 18배 높고 지연시간이 훨씬 낮습니다.
이부분이 Log4J2가 가장 힘주어 설명하는 부분입니다.
위의 표를 보면 비동기 상황에서 Log4J2는 동기 상황에 비해 훨씬 많은 작업을 처리합니다.
이제 다른 Log 라이브러리들과 비교해보겠습니다.
Log4j2는 다른 라이브러리들에 비해 운용하는 스레드의 숫자가 늘어갈 수록 훨씬 좋은 성능을 보여줍니다.
LogBack과 Log4J는 비동기 방식으로 처리할 때 AsyncAppender라는 클래스를 사용하는데 이것은 BlockingQueue를 사용하여 버퍼에 저장된 작업들을 처리합니다.
그리고 이 BlockingQueue가 대기시키는 작업들에 대해 공정성을 지키기 위해 순서를 정해주는데 이 과정에서 오버헤드가 발생합니다.
제가 예상하기에는 이 과정에서 운용하는 스레드가 많아질 수록 공정성을 지키기 위한 오버헤드의 양이 너무 많아져서 오히려 스레드가 많아질 수록 처리하는 작업의 양이 줄어들게 되는 것이 아닐까 생각합니다.
이에 반해 Log4J2는 락을 걸지 않고 비동기 방식으로 처리합니다.
Garbage-free
로그는 사용자가 사용하지 않는 서비스입니다. 개발자들의 편의를 위해 사용되는 라이브러리인 만큼 필요한 곳에만 사용되어져야 합니다. 이것도 객체를 생성하고 자원을 차지하는 것이기에 최대한 줄여서 gc가 일하는 부담을 덜어주어야 합니다.
Log4J2는 기본적으로 개체와 버퍼가 재사용되고 임시 개체가 최대한 할당되지 않는 garbage-free 모드로 실행됩니다.
이것은 Log4J2의 큰 장점 중 하나입니다. gc가 일을 하는 것은 어플리케이션 성능에 큰 영향을 주기 때문입니다.
요약
Log4J2는 Facade 패턴을 통한 구현의 유연성과 비동기 처리 방식, 가비지 프리 모드를 통한 성능 향상의 장점이 있습니다.
Log 라이브러리 정하기
로그는 사용자에게 실서비스 되는 것이 아니기에 최대한 프로그램에 부담이 가지 않는 것이 가장 중요하다고 생각합니다.
따라서 멀티 스레드 환경에서 구동되어질 Helparty를 생각해볼 때 비동기를 통해 다른 라이브러리들 보다 압도적인 성능을 보여주고 Garbage-free 모드를 통해 프로그램 성능에 최소한의 영향을 주는 Log4J2를 사용하기로 정했습니다.