로깅에 대하여

서버를 운영중이던 개발중이던 로그를 남기는 건 필수적 요소이다.

근데 이게 한번 제대로 팍 이해하고 넘어가지 않으면 그놈이 그놈같고 이게 뭔 차인가 싶으니 제대로 딱 정리 한번 하기로 마음 먹었다.

 

우선, 반드시 지켜야할 건 운영 시스템에는 System.out.println()같은 시스템 콘솔을 사용해서 필요한 정보를 출력하지 않고 별도의 로깅 라이브러리를 사용해서 로그를 출력해야 한다. 왜 그럴까? 가장 큰 이유는 불 필요한 로그를 운영 시스템에 찍을 필요가 없는데 이 시스템 콘솔에 찍는건 불 필요한 로그까지 다 남게 되기 때문이다. 

 

여기서 불필요한 로그라는 건? 아마 `TRACE`, `DEBUG` 레벨의 로그일거다. 운영상에 찍지 않고 개발중이거나 디버깅할때 또는 버그를 잡기 위해서 찍어보는 로그. 이게 운영상에 찍히게 되면 로그가 남발이 되니까 빨리 필요한 정보를 캐치하는것도 쉽지 않고, 로그 파일에 지저분하게 남기 때문에 성능도 가독성도 떨어지는 사태가 발생한다. 

 

근데, 시스템 콘솔로 찍는 경우는 이 레벨이란게 없기 때문에 모든 로그가 다 남게 된다. 그리고 가장 최악은 이 시스템 콘솔에 뭔가를 찍을때 연산 작업이 들어간다면 그것이야말로 성능의 가장 불필요한 낭비가 된다. 그래서 운영상에선 System.out.println()이런 시스템 콘솔에 직접 출력하는 것은 안된다.

 

여기서 말하는 연산 작업이란? 아래 같은 코드를 말한다.

int a = 10;
int b = 5;
System.out.println("a + b: " + (a + b));

참고로, 연산 작업이 아니더라도 그냥 기본적으로 System.out 보다 로그 라이브러리(내부 버퍼링, 멀티 쓰레드 등등)를 사용하는게 더 성능이 좋다. 

로깅 라이브러리

스프링 부트를 사용한다면, 스프링 부트 로깅 라이브러리(spring-boot-starter-logging)가 함께 포함된다.

스프링 부트 로깅 라이브러리는 기본으로 다음 로깅 라이브러리를 사용한다.

• SLF4J - `https://www.slf4j.org`
• Logback - `https://logback.qos.ch`

라이브러리를 두개나 사용하는 건가요? 아니다.

로그 라이브러리는 Logback, Log4J, Log4J2 등 수많은 라이브러리가 있는데 A 프로젝트는 이것, B 프로젝트는 저것 이렇게 프로젝트 또는 회사마다 다 다른 라이브러리를 사용하면 연동의 문제가 생기니 이럴때 항상 뭐다? 인터페이스 - 구현체가 등장한다.

 

그래서, 인터페이스가 SLF4J고 그 구현체가 Logback, Log4J, Log4J2가 된다. 실무에서는 스프링 부트가 기본으로 제공하는 Logback을 대부분 사용한다. 그럼 어떻게 사용하면 될까? 

 

LogTestController

package net.cwchoiit.springmvc.basic;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
public class LogTestController {
    private final Logger log = LoggerFactory.getLogger(LogTestController.class);

    @GetMapping("/logging")
    public String logging() {
        log.info("LogTestController.logging");
        return "ok";
    }
}

위 코드와 같이 스프링 부트 프로젝트에서 간단한 컨트롤러를 만들었다. 그리고 org.slf4j 패키지에 들어있는 Logger, LoggerFactory를 통해 log 인스턴스를 만들어 낸다. 그리고 log.info()와 같이 찍으면 된다. 그래서 실제로 이 URL로 요청을 날리면 다음과 같이 로그가 찍힌다.

우선 시스템 콘솔에 직접 찍는거보다 훨씬 많은 정보를 보여준다. 시간, 로그레벨, 쓰레드 정보, 패키지+클래스, 로그 내용까지.

근데 로그의 진가는 이것이 아니라 다음과 같은 것이다.

 

LogTestController

package net.cwchoiit.springmvc.basic;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
public class LogTestController {
    private final Logger log = LoggerFactory.getLogger(LogTestController.class);

    @GetMapping("/logging")
    public String logging() {
        log.trace("trace");
        log.debug("debug");
        log.info("info");
        log.warn("warn");
        log.error("error");
        return "ok";
    }
}

내가 모든 레벨에 대해서 로그를 출력하면 다음과 같은 결과를 얻는다.

 

어? TRACE, DEBUG 레벨은 안 찍혔다. 이게 로그의 진가이다. 내가 설정한 레벨부터 상위 레벨까지만 로그를 찍어주기 때문에 불필요한 로그를 남기지 않게 된다. 그럼 이 레벨은 어떻게 조정할까?

 

바로, application.yml 파일에서 지정하면 된다.

logging:
  level:
    net.cwchoiit.springmvc: DEBUG

이렇게 로그 레벨을 패키지별로 지정할 수 있다. 근데 아 이거 귀찮고 나는 모든 패키지가 다 DEBUG 레벨이면 좋겠어! 하면 이렇게 하면 된다.

application.yml

logging:
  level:
    root: DEBUG

근데 이러면 아예 프로젝트 자체 레벨을 바꾸는 거라 프로젝트 내 모든 라이브러리들 안에 찍은 로그들도 이 레벨에 맞춰 출력되기 때문에 내가 찍지도 않은 여러 로그들이 찍힐건데 여튼 방법은 이렇다. (기본값은 INFO)

참고로 로그 레벨은 다음과 같다.

• TRACE
• DEBUG
• INFO
• WARN
• ERROR

아래로 내려갈수록 더 심각도가 높은것이고 위처럼 DEBUG로 로그 레벨을 설정하면 DEBUG, INFO, WARN, ERROR 로그가 찍히게 된다. 그래서 운영 시스템에서 만약 TRACE로 로그 레벨을 설정하면 큰일이 난다 큰일이! 로그 폭탄을 맞게 된다. 그래서 레벨을 설정할 수 있는 것이다 환경에 따라. 

 

예를 들면, 로컬 환경은 TRACE로, 개발 서버에선 DEBUG로, 운영 서버에선 INFO로 이렇게 설정해서 각 서버 환경에 맞게 필요한 로그만 찍으면 보기도 좋고, 불필요한 정보도 남지 않고 성능에도 도움이 된다. 근데 System.out.println() 같은 건 그런게 없다. 그래서 사용하면 안된다. 

 

그리고 또 다른 장점은, 이 시스템 콘솔에 직접 출력하는 건 결국 콘솔에만 남기 때문에 보존이 불가능하지만 로그는 원한다면 설정을 통해 파일로 남길수도 있다. 그리고 파일로 남길 때는 일별로 남기는게 가능하고 특정 용량 이상이 되면 로그를 분할 할수도 있기 때문에 장점만 있다. 

 

중요!

로그를 찍을때도 이렇게 찍을 수가 있다.

String name = "cwchoiit";
log.trace("your name = " + name);

 

절대로 이렇게 찍으면 안된다. 반드시 다음과 같이 찍어야 한다.

String name = "cwchoiit";
log.trace("your name = {}", name);

왜 그럴까? 만약 내가 설정한 로그 레벨이 DEBUG라면, 이 TRACE 레벨의 로그는 출력되지 않을 것이다. 근데 출력을 하지 않는데도 불구하고 + 연산이 실행된다. 즉, 사용도 안 하는데 메모리와 CPU를 사용하게 된다는 것이다. 그리고 저렇게 연산을 하게 되면 

"your name = cwchoiit"

라는 문자열이 만들어지는데 이걸 또 가지고 있는다. (물론 이후에 GC에 의해 사용 안되면 정리되긴 한다) 그럼 가지고 있는 동안 또 메모리를 사용하는 것이다. 그래서 절대로 저렇게 사용하면 안된다.

 

"그럼 이 방식은 메모리와 CPU 안 사용해요?"

String name = "cwchoiit";
log.trace("your name = {}", name);

 

사용하지 않는다. 왜냐하면, 로그 레벨이 DEBUG이기 때문에 이 log.trace()라는 메서드는 호출되지 않는다. 호출이 안되고 파라미터로 넘기는 코드만 있을 뿐이라서 호출되지 않으면 메모리도 CPU도 사용되지 않기 때문에 아무런 문제가 일어나지 않는다.