[Spring Boot] 6. 로깅(Logging)

#로깅(Logging)

참조:https://docs.spring.io/spring-boot/docs/current/reference/htmlsingle/#boot-features-logging

I. 기초

..아는거지만 한번 싹 정리하자.
나중에 밑에놈들이 물어보면 이거 보라고 하면 되지..


1. 로그란?

프로그램 운영시 발생하는 문제점을 추적하거나 운영상태를 모니터링 위한 텍스트 정보를
로그라고 하며 이 로그를 기록하는 행동을 로깅이라고 한다.

다들 기초 책에서처럼 System.out.println()으로 찍을 수도 있지만
이 경우 운영서버 배포시 이부분을 언제 다 삭제하거나 안찍히게 해야한다.
보안정보가 노출 될 수도 있고 퍼포먼스에도 치명적이기 때문이다.

System.out.println()는 IO리소스를 많이 사용한다.

또한 에러가 발생했을 경우 이미 콘솔에 뿌려진 화면을 찾기도 어렵기 떄문에
로그를 파일로 저장해서 분석할 필요가 있는데 표준출력(standard out)을 통해 출력하는
것은 파일에 저장하기 불편하고 성능도 낮다.

로그 패키지를 이용하면 에러발생시 필요한 정보들을 수동으로 일일히 만들지 않아도
만들어 줄수 있으며 파일로 출력하거나 관리자에게 이메일로 보내게 할 수 있다.

2. LOG4J의 등장

LOG4J는 로그를 전담하는 프레임워크로 과거 가장많이 사용되었던 로그 구현체다.

3. Aapche Jakarta Commons-logging : JCL

아파치 재단의 Commons 라이브러리는 프로그램 개발시 재사용 가능한 자바 컴포넌트들을
모아둔 라이브러리로 프로젝트에서 공통적으로 쓰거나 유틸리티 클래스를 다른 프로젝트에서
재사용 할 수 있게 컴포넌트 형태로 개발해서 제공한다. 대부분의 아파치 프로젝트에서도
중복 개발을 피하기 위에 이 Commons라이브러리를 사용하며 구글 라이브러리와 함께
개발자들이 가장많이 사용하는 라이브러리다. JCL은 이 Commons라이브러리중 TOP5에
속할 정도로 널리 쓰이는 로깅 퍼사드(Facade) 라이브러리이다.

Facade는 실제 로거가 아닌 로그 API를 추상해 놓은 인터페이스들의 집합들로
facade 패턴을 적용한 로깅 프레임워크로 구현체를 포함하고 있지는 않는다. 개발자에게
단순한 로깅 추상화 계층을 제공한다.

Commons Logging API를 사용하면 구현체를 LOG4J를 사용하든 자바의 로깅API를
사용하든 동일한 방법으로 로깅 코드를 작성할 수 있게 된다. 스츠러츠,스프링 프레임워크등
많은 프레임워크들이 기본적으로 Commons-Logging을 사용하며 또 많은 써드 파티 로깅
프레임워크들이 commons-logging 기반으로 구현이 되어 있다.

4. log4j

log4j는 로그 구현체로 효율적인 메모리 관리와 빠른 속도를 가지며 thread-safe로
멀티쓰레드에서도 문제가 없으며 로그를 화면출력이나 파일저장뿐 아닌 tcp원격서버,
원격 유닉스 데몬, 원격 JMS 구독자, 윈도우 NT의 이벤트로그, 이메일등으로도 보내는 것이
가능했다. 국제화 지원 및 융통성이 풍부하여 많이 사용되었다.

한때 코드는 위의 commons-logging 퍼사드로 만들고 구현체로 log4j로 설정하는것이
매우 오랫동안 자바개발의 정석이었다.

5. JCL의 문제점

JCL에서는 몇가지 문제가 존재했는데 가장 유명한 것이 String Concatenation문제다.
예를 들어서 디버깅 레벨의 로그 코드가 있다고 하자.

commons-logging의 기본 사용 방법
1
logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));

DEBUG 레벨의 로그 이기 때문에 개발과 디버깅시에만 보이고 운영시에는 보이지 않는
로그다. 문제는 코드를 이렇게 해놓으면 로그 출력과 상관없이 debug()안에 있는 문자열
처리를 하게 된다. 위에서는 i와 String.valueOf(entry[i])의 2개의 인자를 받아서
문자열을 만들게 되는데 자바에서 String 처리는 상당한 비용을 사용하기에 퍼포먼스에
지장이 생긴다. 이를 해결하기 위해서 다음과 같이 코딩하는 방법이 장려되었다.

commons-logging에서 문자열 비용을 해결하는 방법
1
2
3
4
if(logger.isDebugEnabled()) {
logger.debug("Entry number: " + i + " is " + String.valueOf(entry
[i]));
}

이렇게 해서 문자열 처리 비용은 해결했지만 다른 문제가 발생하였다.
로그 코드가 굉장히 지저분해진다는 점, 그리고 isDebugEnabled()->debug()의 두번의
메소드 호출이 일어난다는 점이었다.

또한 로거 선택시점이 런타임이라 런타임시 오버헤드 이슈도 있었고 가장 커다란
클래스 로딩 이슈도 있었다.혼자 정리중이니 한번 파볼까?

클래스 로더

자바는 동적으로 클래스를 읽어온다. 즉 런타임때 모든 코드가 JVM에 링크된다. 모든
클래스는 참조되는 그순간에 동적으로 JVM에 링크 되며 메모리에 로딩된다. 자바의
런타임 라이브러리(jre/lib/rt.jar)도 마찬가지다.

자바에는 클래스 로더라는 것이 존재하는데 자바 클래스를 JVM에 동적로드하는 JRE의 구성
요소다. 자바가 기본적으로 제공하는 클래스 로더는 java.lang.ClassLoader로 표현되며
JVM이 시작되면 다음의 순서로 3개의 클래스 로더가 사용된다.

  • 부트스트랩 :네이티브로 작성 되어있으며 부모가 없다. /jre/lib밑의 코어 lib 로딩
  • 확장 : /jre/lib/ext나 java.ext.dirs 시스템 속성에 지정된 자원을 로딩
  • 시스템 : CLASSPATH 환경변수에 매핑되어 로딩

전통적인 자바 클래스로더의 기본 동작

1.2 이후로 클래스로더는 부모 클래스 로더를 가지고 있다. 부모클래스로더가 없는
유일한 클래스로더는 JVM이 시작될때 가장 처음 읽는 부트스트랩 클래스로더 하나뿐이다.

클래스로더는 부모 클래스로더가 먼저 클래스로딩하도록 한다. 이유는 효율성이다.
클래스로더가 복수개 존재할 때 각 클래스 로더가 공통으로 사용하는 클래스,리소스를
각자 로딩한다면 중복된 로딩으로 인해 많은 낭비가 있다. 부모부터 로딩을 하도록 한다면
부모가 같은 클래스 로더들은 부모에 로드된 자원을 같이 사용하므로 자원의 낭비를 막을
수 있다. 이러한 전통적인 자바 클래스 로딩 방식을 parent-first/child-last라고 한다.

서블릿 컨테이너의 클래스 로더 동작

문제는 WAS나 서블릿 컨테이너의 클래스로더 동작방식이 다르다는 것이다. 대표적인 톰캣
인데 톰캣의 클래스로더의 계층 구조는 다음과 같다.

톰캣의 클래스로더 계층구조tomcat-doc
1
2
3
4
5
6
7
Bootstrap
|
System
|
Common
/ \
Webapp1 Webapp2 ...

이 Commons는 jre관점에서는 시스템로더 이후의 사용자 정의 클래스 로더로 볼 것이고.
우리가 봤을땐 Common까지 톰캣시스템이고 webapp부터가 사용자 정의 클래스다.
webapp1을 사용중이었다가. 이를 버전업하여 webapp2를 배포하였을때 Common 클래스로더
가 Webapp1과 같은 패키지/클래스면서 기능만 바뀐 버전업 부분을 구분하지 못한다.
이미 로딩된 클래스로 취급하고 로딩하지 않기 때문에 2.0은 제대로 작동되지 못한다.
때문에 WAS에서는 parent-first / child-last 방식의 클래스로딩 메커니즘이 아닌
parent-last / child-first 방식의 클래스로딩 메커니즘을 기준으로 사용한다.
JCL은 클래스로더에 의존적인 방법으로 구현체를 찾았기 떄문에 이슈가 터진것이다.


이런 문제점을 해결한 퍼사드가 나왔으니 SLF4J다.

6. SLF4J(Simple Logging Facade for Java)

SLF4J는 JCL과 같은 Facade 라이브러리로 구조적으로도 더 심플하고 안전해졌다.
SLF4J는 포매팅 개념을 도입하여 처리해서 문자열 문제를 해결하였다.

commons-logging VS SLF4J
1
2
commons-logging: logger.debug("The new entry is "+entry+".");
SLF4J: logger.debug("The new entry is {}.", entry);

SLF4J는 로깅시 {}를 메소드의 파라미터로 받은 값으로 교체하고 로깅하지 않을때는
문자열을 구성하지 않는다. SLF4J는 별도 파라미터 포매팅 구현을 사용해서 일반 포매팅
방법보다 10배이상 빠르다고 한다. 위의 2가지 코드는 같은 의미를 가진 코드이며
같은 로그 메세지를 남기지만 성능은 30배 차이라고 한다.

SLF4J는 로깅 라이브러리를 런타임이 아닌 컴파일 타임에 정하기 때문에
JCL에서 발생했던 클래스 로더 문제가 일어나지 않는다.
다만 런타임에 정하지 않기떄문에
다만 의존성 설정을 잘해야한다.

7. logback

logback은 log4j를 만든 개발자가 log4j를 토대로 새롭게 만든 Logging 라이브러리로
log4j를 대체해 나가고 있다.

logback의 장점

Faster implementation

log4j보다 약 10배 정도 빠르게 수행되도록 내부가 변경되었으며, 메모리 효율성도
더 좋아졌다.

Extensive battery of tests

log4j때부터 더욱 높은 레벨의 테스트를 통해 검증되었다.

logback-classic speaks SLF4J natively

logback-core, logback-classic, logback-access의 3개의 모듈로 구성

  • logback-core : 핵심 코어 컴포넌트
  • logback-classic : SLF4J에서 사용가능하게 만든 플러그인 컴포넌트(binding으로 추측)
  • logback-access : 제티,톰캣등의 컨테이너에 통합되어 HTTP-Access 로그 기능을
    강화시켜준다.
    core는 classic과 access의 공통 라이브러리다.
    일반적으로 개발시 메이븐에 classic만 추가하면 된다.
Extensive documentation

문서화가 잘 되어 있다.

Automatic reloading of configuration files

큰 특징으로는 설정 파일을 변경하여 로그 레벨을 바꾸는 경우 log4j는 서버를 내린후
재설정후 서버를 다시 올리는 절차가 필요했으나 logback은 서버 재기동 없이
자동으로 로그레벨이 갱신된다.

Graceful recovery from I/O failures

서버 중지 없이 I/O Faliure에 대한 복구를 지원한다. 로그를 파일로 저장하고 있는데
log4j는 파일서버가 장애가 나면 어플리케이션을 내렸다가 복구후 다시 올렸어야 존재했는데
logback은 서버 중지 없이 이전 지점부터 복구된다.

Automatic removal of old log archives

로그가 쌓일경우 log4j는 로그를 수동으로 삭제하거나 crontab으로 쉘 스크립트를 돌려야
했으나 logback은 RollingFileAppender를 사용할 경우 자동적으로 오래된 로그를
지워주며 Rolling 백업을 처리한다.

8. 한줄요약

JCL+log4j -> SLF4J+logback으로 넘어가고 있다.

기초 끝


II. 스프링 부트 로깅

1] 기존 스프링의 로깅

위에서 대세가 넘어갔음에도 불구하고 왜 스프링 부트가 JCL을 사용하고 있을까?

스프링 부트가 사용하는 스프링 프레임워크에서 가장 중요한 핵심이 spring-core
만들어질 때는 안타깝게도 SLF4J가 존재하지 않아서 스프링 코어 개발자들은 JCL을
사용했고 이를 중심으로 만들어진 스프링 프레임워크도 JCL을 사용하며 스프링 부트도
마찬가지다.

그래서 스프링4.x때까지의 개발이나 스프링부트 1.x때까지의 개발 프로젝트는
일단 스프링 프로젝트를 생성후 가장 처음 하는 일이 commons-logging의 의존성을
제거(exclusive)후 slf4j+@의 의존성을 추가하는 것으로 시작되었었다.

스프링에서 SLF4J 사용하기

참조 : http://whiteship.me/?p=12162

1)logback
밑에 요약정보 있으니 볼 필요없는 pom.xml
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
<dependency>
<groupId>org.springframework</groupId>
<artifactId>spring-context</artifactId>
<version>${org.springframework.version}</version>
<exclusions>
<!– Exclude Commons Logging in favor of SLF4j –>
<exclusion>
<groupId>commons-logging</groupId>
<artifactId>commons-logging</artifactId>
</exclusion>
</exclusions>
</dependency>

<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>${org.slf4j.version}</version>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>jcl-over-slf4j</artifactId>
<version>${org.slf4j.version}</version>
<scope>runtime</scope>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-log4j12</artifactId>
<version>${org.slf4j.version}</version>
<scope>runtime</scope>
</dependency>
<dependency>
<groupId>log4j</groupId>
<artifactId>log4j</artifactId>
<version>1.2.15</version>
<exclusions>
<exclusion>
<groupId>javax.mail</groupId>
<artifactId>mail</artifactId>
</exclusion>
<exclusion>
<groupId>javax.jms</groupId>
<artifactId>jms</artifactId>
</exclusion>
<exclusion>
<groupId>com.sun.jdmk</groupId>
<artifactId>jmxtools</artifactId>
</exclusion>
<exclusion>
<groupId>com.sun.jmx</groupId>
<artifactId>jmxri</artifactId>
</exclusion>
</exclusions>
<scope>runtime</scope>
</dependency>
  1. 스프링에서 참조하는 JCL 라이브러리를 빼버리기.
  2. JCL-over-SLF4J 추가하기.
  3. SLF4J API 추가.
  4. SLF4J-log4j 추가.(binding)
  5. log4j 추가.

1번: jcl을 사용하지 않기 위해 exclusive하기
2번: 스프링에서 JCL에 의존하는 클래스들이 깨지는것을 막기위해 JCL-over-SLF4J
사용해서 jcl의존 클래스들이 정상 작동하면서 실제로는 slf4J가 작동되게 해주고
3번: 실제 사용할 로깅 추상화 인터페이스 파서드인 SLF4J를 추가한 후
4번 : slf4j파서드와 log4j구현체를 바인딩해주는 SLF4J-log4j를 추가하고
5번 : 실제 로거 구현체인 log4j 를 추가한다.

2)logback

logback-classic이 코어와 slf4-api를 포함하기 때문에
logback-classic만 의존성이 추가하면 위에서 3,4,5번이 다 해결된다.

엄청나게 의존성이 줄어버린 pom.xml
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
<dependency>
<groupId>org.springframework</groupId>
<artifactId>spring-context</artifactId>
<version>${org.springframework.version}</version>
<exclusions>
<!– Exclude Commons Logging in favor of SLF4j –>
<exclusion>
<groupId>commons-logging</groupId>
<artifactId>commons-logging</artifactId>
</exclusion>
</exclusions>
</dependency>

<dependency>
<groupId>org.slf4j</groupId>
<artifactId>jcl-over-slf4j</artifactId>
<version>${org.slf4j.version}</version>
<scope>runtime</scope>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>com.springsource.ch.qos.logback.classic</artifactId>
<version>0.9.9</version>
</dependency>

2] 스프링 5의 로거 변화

스프링 5부터 새로 추가된 Spring-JCL이라는 모듈이 있다. 이 모듈은 기존 스프링에서
사용하는 JCL부분을 컴파일타임에 SLF4J와 Log4j를 선택할 수 있게 하였다. 구현체가
있으면 그 구현체를 자동으로 선택한다. (둘다 있으면 log4j 선택)
JCL-over-SLF4J과 비슷한 역할을 하지 좀더 다양한 프로바이더를 제공한다.

덕분에 이제 JCL-over-SLF4J등의 브릿지가 필요 없으며 스프링 코어 의존성에서
JCL을 exclusive안해도 된다.

1)log4j

만약 log4j를 쓰고 싶다면 log4j-core만 의존성에 추가하면 자동으로 연결된다.
SLF4J도 log4j에 연결하고 싶다면 log4j-slf4j-impl를 의존성에 추가한다.
그러면 이제 JCL,SLF4J 모두 log4j 구현체로 작동될 것이다.

2)logback

만약 logback을 쓰고 싶다면 logback-classic만 의존성에 추가한다.
이러면 JCL도 SPring-JCL을 통해 SLF4J로 갈 것이고
그이후는 동일하게 SLF4J를 거쳐서 결국 모두 logback으로 작동될 것이다.

3] 스프링 부트의 로깅

1)기본 포맷

처음 스프링 부트 시작시 나오는 메세지들이 기본 포맷이다. 다음 순서로 찍힌다.

  1. 날짜와 시간은 밀리초까지 찍혀있다.
  2. 로그레벨은 ERROR, WARN, INFO, DEBUG, TRACE 5가지
  3. 프로세스 id
  4. 사이에 ---로 구분
  5. THREAD 이름 : []로 쌓여있다.
  6. 로거 이름 : 일반적으로 스스 클래스명
  7. 로그 메세지

2)콘솔 출력

기본 로그레벨은 INFO(ERROR, WARN, INFO 레벨만 출력)이다.

어플리케이션을 디버그 모드로 할 경우
(debug=true로 application.properties하던지 –debug스위치로 시작하던지)
(임베디드 컨테이너, 하이버네이트, 스프링부트)만 상세히 출력된다.
디버그 모드가 모든 로그를 DEBUG레벨로 출력하는 것이 아님을 알아두자.

어플리케이션을 trace 모드로 할 경우
(trace=true로 application.properties하던지 –trace스위치로 시작하던지)
(임베디드 컨테이너, 하이버네이트, 스프링 전체)가 trace레벨로 출력된다.
역시 모든 로그를 trace레벨로 출력하는것이 아니다.

컬러 출력: spring.output.ansi.enabled

터미널이 ANSI를 지원하면 읽기 좋도록 자동으로 칼라 출력이 사용된다.
spring.output.ansi.enabled프로퍼티로 자동찾기에 상관없이 설정 가능하다.

파일 출력: logging.file 또는 logging.path

application.properties에 해당 프로퍼티를 설정하여 로그를 파일로 기록할 수 있다.
logging.file의 경우 파일 이름을 설정할 수 있으며 절대/상대경로 가능하다.
logging.path는 해당 경로에 spring.log로 기록한다. 역시 절대/상대 가능하다.

로그 파일은 10메가마다 로테이트 되며 나머지는 1,2등 인덱스 붙여서 보관한다.
logging.file.max-size로 저 10메가를 다른 값으로 바꿀 수 있다.
logging.file.max-history 스프링 2.0부터 새로 바뀐 rolling정책으로
기본 설정으로 로그가 일별로 남게 되는데 이 프로퍼티에 지정한 일수가 지난 로그를
자동으로 삭제해준다.

로그 레벨 조정: logging.level.패지키 = 로그 레벨

로그레벨을 바꾸는것은 application.properties
logging.level.패지키 = 로그 레벨를 기록하면 된다.

그밖에

업무에 쓸려면 사내 로그 시스템과 연동해야해서
특정 위치에 특정 포맷으로 남겨야할 필요가 있다. 이 경우 로거 설정 파일이 필요하다.

IV. 로그 커스터마이징

참조: https://docs.spring.io/spring-boot/docs/current/reference/html/howto-logging.html

위에서 처럼 사내 로그 시스템과 연동할 필요가 있거나 로그의 완전한 제어가 필요할때
로그 설정 파일을 이용할 수 있다.

1] 커스텀 로그 설정 파일

  • Logback: logback-spring.xml, logback-spring.groovy,
    logback.xml, logback.groovy
  • Log4J2: log4j2-spring.xml
  • JUL (비추): logging.properties

스프링에서 제공하는 로그백 확장(logback extension)이 있는데
logback.xml은 안된다.(너무 일찍 로딩되어서 확장을 사용할 수 없다….).
그래서 -spring이 권장된다.

logback-spring.xml
1
2
3
4
5
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<include resource="org/springframework/boot/logging/logback/base.xml"/>
<logger name="me.rkaehdaos" level="DEBUG"/>
</configuration>

application.properties에 설정했던 로그레벨 설정 지우고 해봐도
이렇게 설정 파일에 로거를 추가하면 적용되어서 나온다.

사내 로그 시스템에선 로깅 패턴도 정한다.
로그를 찍을 때 성능에 영향을 주는 메세지들 걸러내기도 하고..사내에 맞게

2] Logback Extensions

참조:https://docs.spring.io/spring-boot/docs/current/reference/htmlsingle/#boot-features-logback-extensions

1) 프로파일 : <springProfile name=”프로파일”>

특정 프로파일일때 특정 설정 적용..
예를들어서 dev프로파일일 경우 로그레벨을 debug레벨로 찍는 식의 설정이 가능하다.

1
2
3
4
5
6
7
8
9
10
11
<springProfile name="staging">
<!-- configuration to be enabled when the "staging" profile is active -->
</springProfile>

<springProfile name="dev | staging">
<!-- configuration to be enabled when the "dev" or "staging" profiles are active -->
</springProfile>

<springProfile name="!production">
<!-- configuration to be enabled when the "production" profile is not active -->
</springProfile>

2) Environment Properties

<springProperty>태그를 이용해서 스프링 Environment의 프로퍼티를 LogBack에 반영
할 수 있다.

1
2
3
4
5
6
<springProperty scope="context" name="fluentHost" source="myapp.fluentd.host"
defaultValue="localhost"/>
<appender name="FLUENT" class="ch.qos.logback.more.appenders.DataFluentAppender">
<remoteHost>${fluentHost}</remoteHost>
...
</appender>

Related POST

공유하기