Spring Boot and Logging - 1. SLF4J

SungBum Park·2020년 11월 9일
JCLSlf4jSpringbootlogging
1

Spring Framework

목록 보기
1/2
post-thumbnail

스프링 부트로 웹 애플리케이션을 개발한 후 이를 실행하면 다음과 같은 콘솔 내용을 쉽게 볼 수 있다. 지금부터 이러한 내용이 어떻게 동작할 수 있었는지 살펴보자.

.   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.3.5.RELEASE)

2020-11-06 21:12:08.036  INFO 10872 --- [           main] c.c.s.SpringBootLoggingSystemApplication : Starting SpringBootLoggingSystemApplication on User.local with PID 10872 (/Users/Documents/spring-project/spring-boot-logging-system/build/classes/java/main started by we in /Users/Documents/spring-project/spring-boot-logging-system)
2020-11-06 21:12:08.039  INFO 10872 --- [           main] c.c.s.SpringBootLoggingSystemApplication : No active profile set, falling back to default profiles: default
2020-11-06 21:12:09.295  INFO 10872 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2020-11-06 21:12:09.311  INFO 10872 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2020-11-06 21:12:09.311  INFO 10872 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.39]
2020-11-06 21:12:09.409  INFO 10872 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2020-11-06 21:12:09.410  INFO 10872 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1300 ms
2020-11-06 21:12:09.720  INFO 10872 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2020-11-06 21:12:09.999  INFO 10872 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2020-11-06 21:12:10.016  INFO 10872 --- [           main] c.c.s.SpringBootLoggingSystemApplication : Started SpringBootLoggingSystemApplication in 2.456 seconds (JVM running for 3.155)

위 콘솔창의 내용은 스프링 부트를 실행하는 도중 발생하는 정보를 보여준다. 이처럼 애플리케이션의 상태를 관찰할 수 있도록 애플리케이션 자체에서 제공하는 정보를 로그(log)라고 한다.

애플리케이션의 현재 상태, 에러가 발생했을 때 등 애플리케이션에 대해 정보가 필요할 때 로그는 굉장히 중요한 정보가 된다. 따라서 개발자는 이미 만들어진 프레임워크, 툴 등의 로그를 잘 읽을 수 있어야 할 뿐 아니라 자신이 만드는 애플리케이션의 어떤 정보를 로그로 남겨야할 지가 중요하다.

먼저 자바 또는 스프링 프레임워크 환경에서 어떤 로그를 사용하고 있는지 살펴보자.

1. JCL(Jakarta Commons Logging)

JCL는 Apache Commons Logging이라고도 불리며, 초기에 주로 사용했던 로그 인터페이스이다. 이는 인터페이스이므로 구현체가 있는 것이 아닌 사용법을 명시한 추상화 라이브러리이며, 여러 구현체를 사용할 수 있다.

주로 사용하는 로그 구현체는 다음과 같다.

  • log4j
  • JDK 1.4 Logging
  • LogKit
  • SimpleLog
  • ...

JCL을 사용한 모습은 다음과 같다.

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;

class Test {
	private final Log log = LogFactory.getLog(this.getClass());

	// ...

	public void printLog() {
		if (this.log.isDebugEnabled()) {
			this.log.debug("Loading source " + StringUtils.arrayToCommadelimitedString(sources));
		}
	}
}
  • org.apache.commons.logging: JCL을 사용하기 위한 패키지
  • Log: 기본 Logger 인터페이스
  • LogFactory: Log 객체를 생성하는 방법을 알고 있는 추상 클래스
  • if 문으로 검사하는 이유는 JCL이 명시한 베스트 프랙티스다. log를 출력하는 코드를 보면 문자열 연산을 수행해야 한다. 하지만 로그 레벨이 debug가 아닐 때는 이 문자열 연산을 할 필요가 없으므로 if 문으로 이 연산 수행 자체를 막는다.

JCL은 현재 거의 사용하지 않는 로깅 방법이다. 왜냐하면 JCL의 동작 방식은 자바의 클래스로더에 의존적인 방법으로 구현체를 갖기 때문이다. 따라서 다음과 같은 문제점이 발생했다.

2. SLF4J(Simple Logging Facade For Java)

JCL의 위와 같은 문제점을 해결하여 나온 것이 SLF4J이다. SLF4J는 Facade라는 이름에서 알 수 있듯이 여러 로깅 구현체를 추상화한 인터페이스이다. JCL과 같이 SLF4J 역시 인터페이스만을 제공하며, 여러 구현체를 사용할 수 있다. 하지만 JCL과는 다르게 구현체를 런타임이 아닌 컴파일 시간에 정하기 때문에 기존 JCL에서 발생한 문제점을 해결하였다.

SLF4J는 기본적으로 세 가지 모듈을 바탕으로 동작한다.

  • SLF4J API: 로깅 인터페이스
    • slf4j-api-{version}.jar
    • org.slf4j.Logger
    • org.slf4j.LoggerFactory
  • SLF4J Binding: SLF4J 인터페이스를 로깅 구현체와 연결하는 어댑터 역할을 하는 라이브러리(실제 사용할 구현체로 볼 수 있다.)
    • 바인딩 종류
      • slf4j-log4j12-{version}.jar
      • slf4j-jdk14-{version}.jar
      • slf4j-nop-{verson}.jar
      • slf4j-jcl-{version}.jar
      • logback-classic-{logback-version}.jar
    • 바인딩은 반드시 한개만 사용해야한다. (여러 바인딩을 사용하면 사용자체를 못하는 것은 아니지만 어떤 바인딩을 사용할 지 예상할 수 없다.)
  • SLF4J Bridge: 다른 로깅 API의 logger 호출을 SLF4J 인터페이스로 연결하여 결과적으로 SLF4J가 바인딩하는 로깅 라이브러리를 사용하도록 하는 역할을 한다.
    • 일반적으로 레거시 logger를 SLF4J의 logger로 사용하기 위해 사용한다.
    • 주의할 점은 Binding과 Bridge가 같은 종류의 logger일 경우에는 무한 루프가 발생할 수 있다.(아래 그림)

출처: https://www.slideshare.net/whiteship/ss-47273947

만약 모든 로깅을 SLF4J의 Logback으로 사용하고 싶다면 API, Binding, Bridge는 다음과 같은 형태가 될 것이다.

출처: https://www.slideshare.net/whiteship/ss-47273947

2.1. Spring boot + SLF4J

먼저 스프링 부트의 로깅 시스템은 JCL을 사용하여 로깅 코드가 작성되었으며, SLF4J와 Logback을 사용한다. 물론 다른 logger로 얼마든지 바꿀 수 있다.

스프링 부트의 로깅 시스템이 정말로 위처럼 사용하고 있는지, Spring boot 2.3.5 버전을 기준으로 의존성을 살펴보자.

스프링 부트를 처음 만들면 다음의 의존성이 기본적으로 추가되어 있다.

implementation 'org.springframework.boot:spring-boot-starter-web'

이 의존성의 내부를 살펴보면 다음과 같다.

  • SLF4J API
    • org.slf4j:slf4j-api:1.7.30
  • SLF4J Binding
    • ch.qos.logback:logback-classic:1.2.3
    • ch.qos.logback:logback-core:1.2.3
  • SLF4J Bridge
  • 스프링 프레임워크는 기본적으로 JCL로 작성되어 있다.
    • org.springframework:spring-jcl:5.2.10

스프링 부트는 starter 의존성에 SLF4J 관련 의존성을 이미 추가하였기 때문에, 아래와 같은 콘솔 내용이 출력될 수 있었다.

.   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.3.5.RELEASE)

2020-11-06 21:12:08.036  INFO 10872 --- [           main] c.c.s.SpringBootLoggingSystemApplication : Starting SpringBootLoggingSystemApplication on User.local with PID 10872 (/Users/Documents/spring-project/spring-boot-logging-system/build/classes/java/main started by we in /Users/Documents/spring-project/spring-boot-logging-system)
2020-11-06 21:12:08.039  INFO 10872 --- [           main] c.c.s.SpringBootLoggingSystemApplication : No active profile set, falling back to default profiles: default
2020-11-06 21:12:09.295  INFO 10872 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2020-11-06 21:12:09.311  INFO 10872 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2020-11-06 21:12:09.311  INFO 10872 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.39]
2020-11-06 21:12:09.409  INFO 10872 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2020-11-06 21:12:09.410  INFO 10872 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1300 ms
2020-11-06 21:12:09.720  INFO 10872 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2020-11-06 21:12:09.999  INFO 10872 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2020-11-06 21:12:10.016  INFO 10872 --- [           main] c.c.s.SpringBootLoggingSystemApplication : Started SpringBootLoggingSystemApplication in 2.456 seconds (JVM running for 3.155)

다음 글에는 스프링부트에서 logback을 어떻게 사용하는지 살펴볼 것이다.

참고자료

profile
SungBum Park
https://parker1609.github.io/ 블로그 이전
다음 포스트

Spring Data JPA 사용하기

4개의 댓글

comment-user-thumbnail
hax0r
2020년 11월 9일

로그 넘나 아름다운 것 :p ㅎㅎ

1개의 답글
comment-user-thumbnail
kicksubway
2023년 11월 13일

I have been checking out some of your stories and i can state pretty nice stuff. I will surely bookmark your site. capybara clicker

답글 달기
comment-user-thumbnail
Larry Mia
2023년 12월 18일

Logs are exceptionally beautiful, aren't they? :p cotton candy t shirt full sleeve

답글 달기