Spring MVC Database 연동 시 log4jdbc 를 사용하여 Query 로그 찍기

Spring MVC 를 사용하여 Web Application 을 개발 할 때에, 통상 Database 와 연동을 해서 개발 한다. 데이터의 시발점이기도 하기 때문에, 문제가 발생 하는 경우 다른 무엇보다 최우선으로 확인 한다. 이 때 필요한 것은 로그 이다. 개발자의 생명줄 이나 다름없다.

log4jdbc 는 로그를 상세하게 출력 한다. 라이브러리를 추가 하자. 0.2.7 이 stable 버전 이다.

<dependency>
    <groupId>org.lazyluke</groupId>
    <artifactId>log4jdbc-remix</artifactId>
    <version>0.2.7</version>
</dependency>

그 다음은 DataSource 이다. driverClassName 을 변경 하면 지원 하는 Database 가 제한적 이기 때문에, 보존 하면서 설정 하는 방법 이다.

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xmlns:beans="http://www.springframework.org/schema/beans"
    xmlns:aop="http://www.springframework.org/schema/aop"
    xmlns:tx="http://www.springframework.org/schema/tx"
    xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-3.2.xsd
    http://www.springframework.org/schema/tx http://www.springframework.org/schema/tx/spring-tx-3.2.xsd
    http://www.springframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop-3.2.xsd">

    <!-- ConnectionPool Information -->
    <beans:bean id="dataSourceSpied" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
        <beans:property name="driverClassName" value="#{config['jdbc.driver']}" />
        <beans:property name="url" value="#{config['jdbc.url']}" />
        <beans:property name="username" value="#{config['jdbc.username']}" />
        <beans:property name="password" value="#{config['jdbc.password']}" />

        <beans:property name="defaultAutoCommit" value="false"/>

        <beans:property name="initialSize" value="1"/>
        <beans:property name="maxActive" value="1"/>
        <beans:property name="maxIdle" value="1"/>
        <beans:property name="maxWait" value="20000"/>
        <beans:property name="logAbandoned" value="true"/>
        <beans:property name="removeAbandoned" value="true"/>
        <beans:property name="removeAbandonedTimeout" value="60"/>
        <beans:property name="validationQuery" value="SELECT 1 FROM DUAL" />
        <beans:property name="testOnBorrow" value="true" />
        <beans:property name="testOnReturn" value="true" />
    </beans:bean>

    <beans:bean id="dataSource" class="net.sf.log4jdbc.Log4jdbcProxyDataSource">
        <beans:constructor-arg ref="dataSourceSpied" />
        <beans:property name="logFormatter">
            <beans:bean class="net.sf.log4jdbc.tools.Log4JdbcCustomFormatter">
                <beans:property name="loggingType" value="MULTI_LINE" />
                <beans:property name="margin" value="19" />
                <beans:property name="sqlPrefix" value="SQL:::" />
            </beans:bean>
        </beans:property>
    </beans:bean>
</beans>

Database 연결 정보를 가지고 있는 dataSource 는 Proxy 클래스를 생성하여 추가적으로 로그를 처리하는 부분이 구현 되어 있으며, Log4jdbcProxyDataSource 는 DataSource 를 상속 형태로 구현하여 확장되어 있다. CGLIB Proxy 라고 불 수 있다.

<logger name="jdbc.connection">
    <level value="info" />
</logger>
<logger name="jdbc.sqltiming">
    <level value="debug" />
</logger>
<logger name="jdbc.resultsettable">
    <level value="info" />
</logger>

log4j.xml 에 위 내용을 추가 하자. 접속 정보, Query, 응답 데이터에 대한 상세 로그가 출력 된다.

2014-10-23 04:19:39,130  INFO connection - 17. Connection opened
2014-10-23 04:19:39,130 DEBUG getBoardList - ooo Using Connection [net.sf.log4jdbc.ConnectionSpy@378c3efb]
2014-10-23 04:19:39,130 DEBUG getBoardList - ==>  Preparing: select no, title, content, create_dt from tb_board
2014-10-23 04:19:39,130 DEBUG getBoardList - ==> Parameters: 
2014-10-23 04:19:39,132 DEBUG sqltiming -  sun.reflect.GeneratedMethodAccessor36.invoke(null:-1)
17. select no, title, content, create_dt from tb_board  {executed in 1 msec}
2014-10-23 04:19:39,135  INFO resultsettable - |-------|--------|---------|----------------------|
2014-10-23 04:19:39,135  INFO resultsettable - |NO     |TITLE   |CONTENT  |CREATE_DT             |
2014-10-23 04:19:39,135  INFO resultsettable - |-------|--------|---------|----------------------|
2014-10-23 04:19:39,135  INFO resultsettable - |1      |title1  |ko       |2014-10-07 12:04:16.0 |
2014-10-23 04:19:39,136  INFO resultsettable - |2      |title2  |en       |2014-10-07 12:04:24.0 |
2014-10-23 04:19:39,136  INFO resultsettable - |3      |title3  |cn       |2014-10-07 12:04:31.0 |
2014-10-23 04:19:39,136  INFO resultsettable - |-------|--------|---------|----------------------|
2014-10-23 04:19:39,138  INFO connection - 17. Connection closed

Database 와 연결 되는 시나리오가 상세하게 로그로 출력 되고 있어 개발, 검증 단계에서 편리하게 사용할 수 있다.

실 서버 적용 에는 sqltiming 부분만 사용하면 장애 대응이나 데이터에 대한 문의도 편리하게 대응이 가능 하다.

log4jdbc 를 사용할 수 있는 환경이라면, 주저 말고 사용 해 보자.

참고 사이트

• https://code.google.com/p/log4jdbc-remix/
• https://code.google.com/p/log4jdbc/
• http://knight76.tistory.com/1674