Spring 로그 찍기

개요

로그가 안나온다...
열심히 생각하고 코드를 쳐도 오류는 터지기 마련이다. 그럴때 로그가 뙇 하고 나오면 대충 여기가 문제겠구나 예상하고 빠르게 수정할 수 있는데 그놈의 로그가 안나온다.
예전에 내가 만들었던 포트폴리오는 Boot 기반이여서 log4jdbc properties와 application.properties를 사용하고 있다. 즉, 여기서는 별 도움이 안된다는 거다.
그냥 맨땅에 헤딩하기 정신으로 처음부터 로그를 어떻게 찍나 한번 해보자.

시도

1. 기본 실행

16:42:19.662 [http-nio-0.0.0.0-8080-exec-3] DEBUG org.springframework.web.servlet.view.JstlView - Forwarding to resource [dbTest.jsp] in InternalResourceView 'dbTest.jsp'

아무것도 없이 실행시켰더니 컨트롤러 과정에서 로그스러운 무언가가 뜬다. 디스패처가 뭐시기 핸들러가 뭐시기 하는 정보가 나온다.
그런데 DB 쿼리문은 나오지 않는다. 기본 제공 (?) 로그는 DB와는 관련이 없나보다.

2. logback xml 파일 추가

src/main/resources 폴더에 logback xml 파일을 넣었다. logback의 코드는 이렇다.

<?xml version="1.0" encoding="UTF-8"?>

<configuration>
	<appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">
		<encoder>
			<pattern>%d %5p %c{2} - %m%n</pattern>
		</encoder>
	</appender>
	<root level="INFO">
		<appender-ref ref="stdout" />
	</root>

	<logger name="org.springframework.web.servlet" level="DEBUG" />
</configuration>

그리고 컨트롤러를 실행시키니

2021-04-26 16:44:29,444 DEBUG o.s.w.s.v.JstlView - Forwarding to resource [dbTest.jsp] in InternalResourceView 'dbTest.jsp'

이런 코드가 나왔다. 아까랑은 뭔가 다른데 자세히 보니 내용은 같다. 그냥 시간 표시 형식만 다르고 메세지 내용은 같은것 같다.
그리고 여기서도 DB 쿼리문은 나오지 않는다. 저 코드는 아마 기본 제공 로그와 같고 형식만 다른것 같다.

3. log4j xml 사용

뭔가 단단히 잘못된것 같다. 다른 곳을 찾아보니 logback이 아닌 log4j를 사용하고 있었다. 심지어 이 경우에는 DB 연결에 사용하는 드라이버 클래스명까지 달랐다. 그래서 처음부터 한번 따라해보기로 결심하고 다 고쳐봤다.
처음엔 pom xml 파일에 의존성 추가

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

src/main/resources 폴더에 log4j xml 파일을 만든다. 기존에 있던 logback xml 파일은 지웠다. 내부 코드는 아래에

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration PUBLIC "-//APACHE//DTD LOG4J 1.2//EN" "log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
	<!-- Appenders -->
	<appender name="console" class="org.apache.log4j.ConsoleAppender">
		<param name="Target" value="System.out" />
		<layout class="org.apache.log4j.PatternLayout">
			<param name="ConversionPattern" value="%-5p: %c - %m%n" />
		</layout>
	</appender>
	<!-- Application Loggers -->
	<logger name="com.freehoon.web">
		<level value="info" />
	</logger>
	<!-- 3rdparty Loggers -->
	<logger name="org.springframework.core">
		<level value="info" />
	</logger>
	<logger name="org.springframework.beans">
		<level value="info" />
	</logger>
	<logger name="org.springframework.context">
		<level value="info" />
	</logger>
	<logger name="org.springframework.web">
		<level value="info" />
	</logger>
	<!-- SQL Logger -->
	<logger name="jdbc.sqltiming" additivity="false">
		<level value="warn" />
		<appender-ref ref="console"/> 
	</logger>
	<logger name="jdbc.sqlonly" additivity="false"> 
		<level value="info"/> 
		<appender-ref ref="console"/> 
	</logger>
	<logger name="jdbc.audit" additivity="false"> 
		<level value="warn"/>  
		<appender-ref ref="console"/> 
	</logger> 
	<logger name="jdbc.resultset" additivity="false">
		<level value="warn" />
		<appender-ref ref="console"/> 
	</logger>
	<logger name="jdbc.resultsettable" additivity="false"> 
		<level value="info"/>  
		<appender-ref ref="console"/> 
	</logger> 
	<!-- Root Logger -->
	<root>
		<priority value="warn" />
		<appender-ref ref="console" />
	</root>
</log4j:configuration>

같은 폴더에 log4jdbc.log4j2.properties 파일을 만든다. 파일 내용은 아래와 같다.

log4jdbc.spylogdelegator.name=net.sf.log4jdbc.log.slf4j.Slf4jSpyLogDelegator

그리고 난 뒤에 DbConfig 파일을 수정한다. 바꾼건 단 2줄.

ds.setDriverClassName("com.mysql.jdbc.Driver");
ds.setUrl("jdbc:mysql://localhost/test?characterEncoding=utf8");

에서

ds.setDriverClassName("net.sf.log4jdbc.sql.jdbcapi.DriverSpy");
ds.setUrl("jdbc:log4jdbc:mysql://localhost/test?characterEncoding=utf8");

으로 바꿨다. 그랬더니

2. insert into number1 values ('19', 'ssss') 

으로 로그가 찍힌다! 깔끔하진 않아보이고 log4j xml 파일은 빨간색으로 오류 표시가 나긴 하지만 작동은 한다. 마음에 들지는 않지만 로그를 찍는다는 본래 목적은 달성했으니 됐다고 치자.