9. Log4jdbc로 DB 로그 저장하기

코드 확인을 위해, 관련 PR 링크를 첨부한다.

#17 Logback을 통해 DB 로그 남기기 by include42 · Pull Request #18 · include42/spring-books-diary

간만에 돌아온 포스팅. 오늘은 다음의 목표를 이루기 위해 어떤 작업을 했는지 적어보려고 한다.

• Log4jdbc를 사용하여 DB 관련 로그를 수집한다.
• 수집한 로그를 필터링하여 필요한 로그만 출력한다.
• 로그를 파일로 남겨 문제 시 확인할 수 있도록 한다.

---

1. Log4jdbc

Log4jdbc는 Log4j를 JDBC와 연결하여 사용하기 위해 만들어진 오픈소스 프로젝트이다.

Log4jdbc의 깃헙 링크이다.

arthurblake/log4jdbc

다만, 이 프로젝트는 매우 예전에 진행된지라, 최근의 코드에 적용하기는 무리가 있다.

다행히 Log4j2와 Slf4j와 연동되는 최신 버전이 개발된 모양이다.

Log4jdbc-log4j2 프로젝트의 깃헙 링크 이다.

brunorozendo/log4jdbc-log4j2

나름 커밋 로그를 보고 원본 개발자의 저장소를 찾고자 했는데,

혹시 링크가 잘못됐다면 지적 부탁드립니다.

---

2. Log4jdbc-log4j2 적용법

 

나는 gradle을 사용하므로, 일단 gradle 기준으로 설명한다.

만약 설명을 따라오다가 문제가 생긴다면, 개발자의 공식 페이지를 참고하기를 바란다.

build.gradle 파일에, 다음 의존성 한 줄을 추가해 준다.

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

만약에 당신이 maven을 사용한다면, 다음 코드를 추가해 준다.

 

<dependency>
  <groupId>org.bgee.log4jdbc-log4j2</groupId>
  <artifactId>log4jdbc-log4j2-jdbcXX</artifactId>
  <version>1.16</version>
</dependency>

---

이제 log4jdbc.log4j2.properties 파일을 추가해줘야 한다.

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

log4jdbc.spylogdelegator.name = net.sf.log4jdbc.log.slf4j.Slf4jSpyLogDelegator 옵션은, log4j2 대신 slf4j를 쓰고 싶을때 사용되는 옵션이다. 일단 공식 페이지에서는 다음과 같이 언급하고 있다.

First, you need to tell log4jdbc-log4j2 that you want to use the SLF4J logger. You need to configure the option log4jdbc.spylogdelegator.name to the value net.sf.log4jdbc.log.slf4j.Slf4jSpyLogDelegator . This is done either via the log4jdbc.log4j2.properties file stored in your classpath, or via system properties.

이게 왜 중요한가 하면...log4j2로만 쓰거나 log4j2/slf4j를 같이 쓰면, 로그가 복잡해진다!

log4j2로 찍히는 로그는 분류도 제대로 안되어있고, 양도 엄청 많아서 정 쓰고싶으면 설정을 좀 해줘야한다.

공식 페이지에서도 log4j2로 쓰는 로그는 error 이상만, additivity는 false로 해서 콘솔에 찍히지 않도록 하라고 권하고 있다.

일단 나는 위의 설정을 해 줘서, slf4j로만 로그가 나오도록 했다.

 

log4jdbc.dump.sql.maxlinelength는 최대 sql 출력 길이. 0으로 하면 설정 없이 다 나오고, 그외엔 설정한 길이까지만 출력한다.

default 값은 90L이다.

 

참고로, properties 대신 yml 파일로 해보고 싶어서 고민해 봤는데,

하려면 별도로 yml 파일을 import해주고 복잡해진다....이 부분은 해보고 추후 포스팅하기로!!

이와 별도로 yaml 파일로 properties 바꾸기 글도 조만간 포스팅하겠다. 할게 참 많어...

---

이제 DB 관련 정보를 수정해줘야 한다.

DB 관련 설정을 넣어놓은 application.properties로 간다.

application.properties의 spring.datasource.driver-class-name 속성을 net.sf.log4jdbc.sql.jdbcapi.DriverSpy로 설정해준다.

그리고 spring.datasource.url이란 속성이 있을 텐데,

jdbc:[mariaDB 혹은 h2 혹은 mysql] :// 주소~~~ 이렇게 되어있을 것이다.

여기서 jdbc와 db명 사이에, :log4jbdc: 를 넣어주면 된다.

 

즉, 결과물은 아래처럼 나올 것이다.

#application.properties
#spring.datasource.driverClassName=org.h2.jdbc.Driver 
#spring.datasource.url=jdbc:mariadb://localhost:3306/test?characterEncoding=UTF-8&serverTimezone=UTC 

spring.datasource.driverClassName=net.sf.log4jdbc.sql.jdbcapi.DriverSpy 
spring.datasource.url=jdbc:jdbc:log4jdbc:h2:mem:testdb

위의 주석 처리된 부분이 기존 코드, 아래쪽이 최근 코드.

 

나는 요새 yaml 파일로 바꿔서 코드를 좀 정리중인데, yaml에서 h2를 쓰는 경우 아래처럼 변경된다.

#application.yml
spring:
  h2:
    console:
      path: /h2-console
      enabled: true
  datasource:
    driver-class-name: net.sf.log4jdbc.sql.jdbcapi.DriverSpy
    url: jdbc:log4jdbc:h2:mem:testdb

---

3. 실행 및 로그 설정하기

자, 이제 실행해 보면 어떻게 로그가 나올까?

너무 많길래 대충 스샷찍은거. 저런 로그 수십개가 줄줄이 찍힌다.

이제 jdbc.xxx 라는 이름으로 로그들이 나온다!!

그런데 문제는, 로그가 너무 많다는 것. 그래서 로그 분류를 알아보고, 그에 맞게 로그들을 정리하려고 한다.

Slf4j로 찍히는 log4jdbc 로그는 다음과 같다.

logger	description
jdbc.sqlonly	Logs only SQL. SQL executed within a prepared statement is automatically shown with it's bind arguments replaced with the data bound at that position, for greatly increased readability. SQL문만을 로그로 남긴다. 가독성을 위해, preparedStatement는 관련된 arguments 값으로 대체된다.
jdbc.sqltiming	Logs the SQL, post-execution, including timing statistics on how long the SQL took to execute. SQL문과 해당 SQL을 실행하는데 걸린 시간을 포함한다. (참고로 시간 정보는 millisecond로 나온다)
jdbc.audit	Logs ALL JDBC calls except for ResultSets. This is a very voluminous output, and is not normally needed unless tracking down a specific JDBC problem. ResultSets를 제외한 모든 JBDC 호출 정보를 로그로 남긴다. 이는 매우 큰 볼륨을 가지는 결과물이므로, 특별히 JDBC 문제를 추적할 때 외엔 권하지 않는다.
jdbc.resultset	Even more voluminous, because all calls to ResultSet objects are logged. JDBC 결과를 포함합니다. ResultSet 오브젝트에 대한 모든 호출이 로깅되므로 매우 방대합니다.
jdbc.resultsettable	Log the jdbc results as a table. Level debug will fill in unread values in the result set. JDBC 결과를 테이블로 기록합니다.
jdbc.connection	Logs connection open and close events as well as dumping all open connection numbers. This is very useful for hunting down connection leak problems. 수행 도중 열리고 닫히는 연결 내용을 포함합니다. 연결 누수 문제를 찾는데에 유용합니다.

(앞서 log4j2를 쓰기로 설정하고 slf4j 설정 안해줬으면 다를 수 있다. 그리고 번역은 의역이니 주의하시길...)

---

그런데, 생각해보니 Slf4j 로깅이면 이전에 다뤘던 logback으로 로그가 출력되는거 아닌가?

그래서 바로 해봤다. 우리가 위에 적어둔 로그 타입들을, logback-spring.xml에 적어준다.

<!--Log4jdbc-->
<logger name="jdbc" level="OFF"/>
<logger name="jdbc.connection" level="OFF"/>
<logger name="jdbc.sqlonly" level="OFF"/>
<logger name="jdbc.sqltiming" level="DEBUG" additivity="false">
	<appender-ref ref="DATABASE_FILE_APPENDER"/>
</logger>
<logger name="jdbc.audit" level="OFF"/>
<logger name="jdbc.resultset" level="OFF"/>
<logger name="jdbc.resultsettable" level="OFF"/>

위의 옵션들을 봤을 때, 필요하다고 생각하는 로그를 켜주면 된다.

나는 당장 필요한건 sqltiming이어서, 이외엔 다 OFF로 처리해줬다.

또한, DATABASE_FILE_APPENDER라는 어펜더를 만들어 로그가 파일로 출력되도록 하였다!!

(내용이 궁금하다면, 이전 글을 참고하시길 바란다.)

짜잔!! 로그가 파일로 저장됐다.

---

오늘 간략하게 log4jdbc 사용법과 응용을 적어봤다.

본격적인 개발을 빨리 들어가야 하는데...학교 일정이며 개인 사정이며 참 정신이 없다.

그래도 틈틈히 블로그에 들를 수 있는 여유가 있어서 다행이다.