[SpringBoot] 게시판 구현하기 7 (스프링의 다양한 기능 살펴보기 - 로그)

들어가기 전에

하기 포스팅은 "스프링부트 시작하기(김인우 저)" 책을 공부하며 적은 포스팅입니다. 이번 포스팅에서는 로그에 대해 살펴보도록 하겠습니다.

Log(로그)

개발 시 발생할 수 있는 에러 확인 및 유지보수 등을 위해 로그를 분석해야할 필요성이 있습니다. 이에 따라 사용자가 보기 쉽도록 로그를 남겨야합니다.

Logback이란?

오랫동안 널리 사용되고 검즈된 Log4j를 기반으로 작성된 로그 라이브러리입니다. Log4j와 비교해서 성능이 10배정도 빠르고 메모리 사용량이 적습니다. Logback을 사용한 로그 설정 변경의 경우, 서버를 따로 재시작하지 않아도 바로 반영된다는 장점을 가지고 있습니다(Logback은 로그 설정이 변경될 경우 내부의 설정 변화 감지 스레드가 이를 감지하여 반영하기 때문, 이 스레드는 어플리케이션 성능에 큰 영향 X).

Logback은 로깅 구현체 중 하나로 slf4j(Simple Logging Facade for Java)를 함께 사용합니다. slf4j는 자바의 다양한 로그 모듈들의 추상체라고 할 수 있습니다. 어찌보면 자바의 인터페이스와 비슷한 역할을 한다고 할 수 있습니다. slf4j의 API를 이용할 경우 실제 로깅을 담당하는 로깅 구현체의 종류와 상관없이 일관된 로그 코드를 작성할 수 있습니다. 로그 출력 등 로깅 코드는 slf4j를 이용하면 내부적으로는 Logback이나 log4j2와 같은 로깅 구현체가 그 기능을 구현합니다.

SpringBoot는 프로젝트를 생성하면 Logback을 기본으로 사용합니다. 따라서, 로그를 사용할 코드에서는 로깅 구현체만 추가해서 쓰면 됩니다.

Logback 설정하기

먼저 src/main/resources 폴더 밑에 logback-spring.xml 파일을 생성하고 하기 내용을 작성합니다.

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="true">
    <!--  Appenders -->
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <Pattern>%d %5p [%c] %m%n</Pattern>
        </encoder>
    </appender>

    <appender name="console-infolog" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <Pattern>%d %5p %m%n</Pattern>
        </encoder>
    </appender>

    <!-- 로거 -->
    <logger name="board" level="DEBUG" appender-ref="console"/>

    <!-- 루트 로거 -->
    <root level="off">
        <appender-ref ref="console"/>
    </root>
</configuration>

Logback의 주요 구성 요소는 다음과 같습니다.

• <appender>: 로그를 어디에 출력할지(콘솔, 파일 기록, DB 저장 등) 결정하는 역할을 합니다.
• <encoder>: <appender>에 포함되는 태그로, 출력될 로그의 형식을 지정합니다.
• <logger>: 로그를 출력하는 요소로 Level 속성을 통해 출력할 로그의 레벨을 조절하여 appender에 전달합니다. debug 레벨의 로그를 출력하는 형식은 appender-ref 속성에 적힌 console이라는 이름을 가진 appender를 사용합니다.

Logback에서 사용하는 로그 레벨

로그 레벨	설명
trace	모든 로그를 출력합니다.
debug	개발할 때 디버그 용도로 사용합니다.
info	상태 변경 등과 같은 정보성 메시지를 나타냅니다.
warn	프로그램의 실행에는 문제가 없지만, 추후 시스템 에러의 원인이 될 수 있다는 경고성 메시지를 의미합니다.
error	요청을 처리하던 중 문제가 발생한 것을 의미합니다.

표에서 가장 윗줄이 가장 낮은 레벨입니다. 아래로 갈수록 레벨이 높아지며 설정한 로그 레벨 이상 로그만 출력됩니다. 예를 들어, 레벨을 info로 지정하면 info 레벨과 warn, error 로그가 출력됩니다.

Logback 사용하기

Logback을 사용하기 위해서는 로그를 사용하려는 클래스에서 아래와 같이 로거를 생성해야 합니다.

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

Logger log = LoggerFactory.getLogger(this.getClass());

• import org.slf4j.Logger, import org.slf4j.LoggerFactory: 로그를 사용하는 코드에서는 특정 로깅 구현체의 패키지를 사용하지 않습니다(slf4j를 사용할 경우, 로깅 구현체의 종류와 상관없이 일관된 코드 작성 가능). 코드에 사용되는 로거는 slf4j 패키지입니다. 즉, 로거로 Logback을 사용하더라도 코드 내에서는 slf4j의 의존성만 사용합니다. 따라서, 로깅 구현체를 Logback이 아닌 다른 라이브러리(예: log4j2)로 쉽게 변경이 가능합니다.
  • Logback의 의존성 X
• Logger log = LoggerFactory.getLogger(this.getClass()): getLogger() 메소드의 파라미터는 로거의 이름입니다. 모든 로거는 이름을 기반으로 생성됩니다. 만약, getLogger("NAME")으로 생성하면 NAME이라는 이름을 가진 로거 인스턴스 하나를 반환합니다. 일반적으로는, 특별한 이름을 쓰지 않고 클래스 객체를 넘겨 주는 방식을 사용합니다.
  • 클래스 객체를 이름으로 넘겨주면, 로거의 이름은 "패키지 이름 + 클래스 이름"으로 구성됩니다.

로그를 출력하는 메소드는 아래와 같이 사용하면 됩니다. 로그를 출력할 때는 원하는 레벨의 로그를 호출하면 됩니다.

log.trace("trace level log");
log.debug("debug level log");
log.info("info level log");
log.warn("warm level log");
log.error("error level log");

BoardController 클래스에 로거를 적용해보도록 하겠습니다. BoardController 클래스에 하기 내용을 추가합니다.

package board.board.controller;

...

// ADD START
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
// ADD END

@Controller
public class BoardController {

        // ADD START
        private Logger log = LoggerFactory.getLogger(this.getClass());
        // ADD END

        @Autowired
        private BoardService boardService;

        @RequestMapping("/board/openBoardList.do")
        public ModelAndView openBoardList() throws Exception {
            // ADD START
            log.debug("openBoardList");
            // ADD END

            ModelAndView mv = new ModelAndView("/board/boardList");

            List<BoardDto> list = boardService.selectBoardList();
            mv.addObject("list", list);

            return mv;
        }
...

• private Logger log = LoggerFactory.getLogger(this.getClass()): 로거를 생성합니다. 로거의 이름으로는, 앞서 설명했던 것과 같이 클래스 객체를 넘겨주어 패키지 이름 + 클래스 이름으로 생성되도록 했습니다.
• log.debug("openBoardList"): debug 레벨의 로그를 출력합니다. 여기서는 테스트를 위해 openBoardList 문자열을 출력합니다.

스프링부트 어플리케이션을 실행하여 localhost:8080/board/openBoardList.do를 호출하면 하기와 같이 로그가 로거 이름과 함께 나타남을 알 수 있습니다.

로그 확인

Logger(로거) 사용 팁

lombok을 사용할 경우 @Slf4j 어노테이션을 사용하면 로거를 따로 생성할 필요 없습니다.

import lombok.extern.slf4j.Slf4j;

@Slf4j
public class BoardController { ... 중략 ...

Log4JDBC로 쿼리 로그 정렬하기

SpringBoot는 자체적으로 log4j2나 Logback 등의 로깅 API를 제공합니다. 따라서, 특별한 설정을 하지 않더라도 기본적으로 여러 로그가 출력됩니다. 쿼리 로그 역시 마찬가지입니다.

하지만, 이렇게 출력되는 로그에는 특별히 필요하지 않은 정보가 많습니다. 그리고 정렬이 되어 있지 않아 한 눈에 로그 확인이 어렵습니다. 예를 들어 게시판 상세 화면(/board/openBoardDetail.do) 호출 시, 아래와 같이 정렬되지 않은 채 한 줄로 쿼리문이 작성됩니다. 특히, 파라미터의 경우 ?로 표시되어 어떤 값이 바인드되어 쿼리가 수행되었는지 알 수 없습니다.

정렬되지 않은 쿼리 로그

이러한 문제들을 해결하기 위해 로그가 정렬되어 출력되고 쿼리에 대한 추가적인 정보도 제공하는 Log4JDBC 라이브러리를 사용해보도록 하겠습니다.

라이브러리 추가하기

먼저 build.gradle 파일에 아래와 같이 라이브러리를 추가합니다.

dependencies {
...
    implementation 'org.bgee.log4jdbc-log4j2:log4jdbc-log4j2-jdbc4.1:1.16'
...
}

라이브러리 추가 후에는 반드시 gradle를 refresh하여 해당 라이브러리를 다운받아야 합니다.

Refresh Gradle Project

log4jdbc 설정하기

log4jdbc.log4j2.properties 설정

src/main/resources 폴더 밑에 log4jdbc.log4j2.properties 파일을 생성하고 다음 내용을 작성합니다. *.properties 파일은 이클립스 내 미리 정의되어 있는 확장자가 아니므로 New > File을 이용해서 파일 이름 및 확장자까지 모두 입력해서 만들어야 합니다.

properties 파일 생성

생성한 파일에 아래와 같이 작성합니다.

log4jdbc.spylogdelegator.name = net.sf.log4jdbc.log.slf4j.Slf4jSpyLogDelegator
log4jdbc.dump.sql.maxlinelength = 0

application.properties 설정

application.properties 파일의 설정을 변경해야 합니다. driver-class-name과 URL을 변경합니다.

// AS-IS
spring.datasource.hikari.driver-class-name=com.mysql.cj.jdbc.Driver
spring.datasource.hikari.jdbc-url=jdbc:mysql://localhost:3306/example?useUnicode=true&characterEncoding=utf-8&serverTimezone=UTC&allowPublicKeyRetrieval=true&useSSL=false
// TO-BE
spring.datasource.hikari.driver-class-name=net.sf.log4jdbc.sql.jdbcapi.DriverSpy
spring.datasource.hikari.jdbc-url=jdbc:log4jdbc:mysql://localhost:3306/example?useUnicode=true&characterEncoding=utf-8&serverTimezone=UTC&allowPublicKeyRetrieval=true&useSSL=false

logback-spring.xml 설정

마지막으로 logback-spring.xml 파일을 설정을 추가합니다. 하기 내용을 추가하면, 쿼리 및 실행 결과를 보여 주는 로거가 추가되는 것입니다.

...
    <!-- 로거 -->
    <logger name="board" level="DEBUG" appender-ref="console"/>
    <!-- ADD START -->
    <logger name="jdbc.sqlonly" level="INFO" appender-ref="console-infolog"/>
    <logger name="jdbc.resultsettable" level="INFO" appender-ref="console-infolog"/>
    <!-- ADD END -->
...

log4jdbc가 제공하는 로거 종류

로거	설명
jdbc.sqlonly	SQL을 보여줍니다. Prepared statement의 경우 관련 파라미터는 자동으로 변경되어 출력됩니다.
jdbc.sqltiming	SQL문과 해당 SQL 문의 실행 시간을 밀리초 단위로 보여줍니다.
jdbc.audit	ResultSets을 제외한 모든 JDBC 호출 정보를 보여줍니다. 매우 많은 로그가 발생되므로, JDBC 관련 문제를 추적하기 위한 것이 아니라면 일반적으로 사용하지 않습니다.
jdbc.resultset	ResultSets를 포함한 모든 JDBC 호출 정보를 보여주므로 jdbc.audit보다 더 많은 로그가 생성됩니다.
jdbc.resulttable	SQL의 조회 결과를 테이블로 보여줍니다.
jdbc.connection	Connection의 연결과 종료에 관련된 로그를 보여줍니다. Connection 누수(leak) 문제를 해결하는 데 도움이 됩니다.

log4jdbc 설정 결과 확인하기

게시글 조회(/board/openBoardList.do) 시, 아래와 같이 콘솔에 로그가 남는 것을 확인할 수 있습니다. jdbc.sqlonly를 통해 SQL문을 보여주고, jdbc.resulttable을 통해 select 결과를 콘솔에 보여줍니다.

log4jdbc 설정 결과

log4jdbc 설정 후 발생할 수 있는 문제(Loading class 'com.mysql.jdbc.Driver'. This is deprecated.) 및 해결 방법

기존에는 mySQL driver를 com.mysql.cj.jdbc.Driver로 사용해 문제가 없었지만, log4jbdc를 사용하는 드라이버로 변경한 후 아래와 같은 로그가 발생합니다.

아래 사진 및 페이지에서 확인할 수 있듯이, MySQL의 버전이 5.1에서 8.0으로 올라감에따라 driver 명칭이 변경되었습니다.

MySQL 문서

dev.mysql.com/doc/connector-j/8.0/en/connector-j-api-changes.html

MySQL :: MySQL Connector/J 8.0 Developer Guide :: 4.4.1.3 Changes in the Connector/J API

기존에 log4jdbc를 사용하지 않을 때에는 application.properties에 com.mysql.cj.jdbc.Driver로 작성함에 따라 특별한 이슈가 없었습니다. 하지만, 쿼리 로그를 위해 log4jdbc 드라이버로 변경을 했고, log4jdbc 드라이버가 mySQL의 기본 드라이버로 com.mysql.jdbc.Driver를 사용하여 deprecated 경고를 보여주게 되었습니다.

위 deprecated 경고를 없애기 위해서는, log4jdbc가 채택한 mySQL 드라이버를 변경해줄 필요가 있습니다. 먼저, log4jdbc.log4j2.properties 파일을 열고 아래 내용을 추가해줍니다.

...
log4jdbc.drivers=com.mysql.cj.jdbc.Driver
log4jdbc.auto.load.popular.drivers=false

• log4jdbc.drivers: log4jdbc가 로그할 JDBC drivers의 class name을 작성합니다. 여러 JDBC drivers가 필요할 경우 ','로 구분하여 작성하되, 띄어쓰기 없이 작성해야 합니다. log4jdbc는 기본적으로 popular JDBC를 로드해주나, 원하는 드라이버가 따로 있을 경우 작성해주어야 합니다.
• log4jdbc.auto.load.popular.drivers: 기본적으로 true값을 가지나, false로 설정할 경우 log4jdbc는 polular drivers를 자동으로 로그하지 않습니다. 따라서, false로 할 경우 반드시 log4jdbc.drivers를 설정하여 드라이버가 로드될 수 있도록 해야 합니다.

log4jdbc 설정파일에 들어갈 수 있는 항목들은 아래 주소에 접속하면 확인해볼 수 있습니다(위에는 여기서 필요한 항목들만 정리해둔 것입니다).

github.com/candrews/log4jdbc-spring-boot-starter

GitHub - candrews/log4jdbc-spring-boot-starter: Starter for using Log4jdbc with Spring Boot