Top

sql 쿼리 로깅 삽질기 – log4jdbc-remix

새로 프로젝트 환경을 구성하면서 sql 쿼리의 로깅을 위해서 log4jdbc-remix를 사용하려고 했다.

이전에 구성한 프로젝트에서도 잘 사용했기 때문에 가볍게 생각해서 설정을 시작했는데, 이게 죽어도 되지를 않는거다.

java.sql.SQLException: No suitable driver found for jdbc:log4jdbc:mariadb

위와 같은 에러를 내면서 mariadb를 찾을 수 없다고 에러가 발생했다.

 

내가 설정한 스프링 관련 설정은 아래와 같았다.

<dependency>
            <groupId>org.mybatis</groupId>
            <artifactId>mybatis</artifactId>
            <version>3.3.1</version>
        </dependency>
        <dependency>
            <groupId>org.mybatis</groupId>
            <artifactId>mybatis-spring</artifactId>
            <version>1.2.5</version>
        </dependency>
        <dependency>
            <groupId>org.mariadb.jdbc</groupId>
            <artifactId>mariadb-java-client</artifactId>
            <version>1.4.0</version>
        </dependency>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-jdbc</artifactId>
            <version>4.2.5.RELEASE</version>
        </dependency>
        <dependency>
            <groupId>com.jolbox</groupId>
            <artifactId>bonecp</artifactId>
            <version>0.8.0.RELEASE</version>
        </dependency>

위와 같이 db 풀은 boncp를 사용하고, db는 maria  db를 사용했으며, persistent layer는 mybatis를 사용중이었다.

mariadb의 jdbc 클래스를 위해서 “mariadb-java-client”를 사용했다.

<!--0.2.6 아래 버전에서는 alias를 통한 매핑에서 에러가 발생함-->
<dependency>
    <groupId>org.lazyluke</groupId>
    <artifactId>log4jdbc-remix</artifactId>
    <version>0.2.7</version>
</dependency>

위와 같이 log4jdbc-remix를 디펜던시에 추가했다.

 

이 설정으로 전에 구성한 프로젝트에서는 정상적으로 mariadb의 쿼리가 출력되었기 때문에, 처음에는 설정 문제를 의심하고 계속해서 설정 부분을 확인해봤다.

그러다 보니 아래와 같은 글을 발견했다.

 

LOG4JDBC를 사용한 JDBC 로그 분석

 

위 글에 따르면 log4jdbc-remix에서 자체적으로 jdbc 드라이버를 지원하는 유명한 db들을 제외하고는 시스템 프로퍼티에 아래와 같은 설정을 추가해야 한다는 내용이었다.

-Dlog4jdbc.drivers=<driverclass>[,<driverclass>...]

 

생각해보니 정상적으로 동작하는 프로젝트의 DB 관련 설정 부분을 보면 아래와 같다.

    <bean id="dataSource" class="com.jolbox.bonecp.BoneCPDataSource" destroy-method="close">
        <property name="driverClass" value="net.sf.log4jdbc.DriverSpy"/>
        <property name="jdbcUrl" value="jdbc:log4jdbc:mariadb://db 주소"/>
        <property name="username" value="${jdbc.username}"/>
        <property name="password" value="${jdbc.password}"/>
        <property name="idleConnectionTestPeriodInMinutes" value="5"/>
        <property name="idleMaxAgeInSeconds" value="300"/>

        <!-- DB에 연결되는 최소 connection의 갯수는 partitionCount * minConnectionsPerPartition -->
        <property name="maxConnectionsPerPartition" value="10"/>
        <property name="minConnectionsPerPartition" value="2"/>
        <property name="partitionCount" value="2"/>

        <property name="acquireIncrement" value="1"/>
        <property name="acquireRetryAttempts" value="10"/>
        <property name="acquireRetryDelayInMs" value="5000"/>
        <!--<property name="statementsCacheSize" value="100"/>-->
        <property name="connectionTimeoutInMs" value="10000"/>
        <property name="connectionTestStatement" value="/* ping */ select 1"/>
        <property name="defaultAutoCommit" value="false"/>
        <property name="maxConnectionAgeInSeconds" value="28800"/>
    </bean>

위에서 보면 maria db는 well known db가 아닌데, db 드라이버의 클래스를 “net.sf.log4jdbc.DriverSpy” 로 지정했고

실제 jdbc.url에 “jdbc:mariadb://” 부분을 “jdbc:log4jdbc:mariadb://”로 변경했다.

위에 링크에 글에서 기술 한 것 처럼, 시스템 프로퍼티에 실제적인 db의 드라이버 클래스를 프로그램에 넘겨주어야만 log4jdbc-remix에서 해당 드라이버를 이용해서 DB에 접속하게된다.

즉 이전에 프로젝트가 정상적으로 동작한 것이 이상한 상황이었다.

jdbc.driverClassName=org.mariadb.jdbc.Driver #이 설정이 기술되어 있어야 했다.

 

물론 쉽게 sql 쿼리가 찍히게 하는 몇가지 방법이 있었다.

 

1. log4jdbc-remix는 더이상 지원하지 않는 프로젝트이기 때문에 후속 프로젝트인 “log4jdbc-log4j2″를 이용하면 된다.

그런데 이 프로젝트는 “log4jdbc.log4j2.properties” 파일에 해당 로깅에 환경 설정 파일을 저장해야 했다.

(프로퍼티 파일이 여기저기 생기면 귀찮고 싫어하므로 이 방법은 패쓰)

 

2. datasource에 log4jdbc-remix의 구현체를 Inject 하여 사용

<bean id="originDataSource" class="com.jolbox.bonecp.BoneCPDataSource" destroy-method="close">
    <property name="driverClass" value="${jdbc.driverClassName}"/>
    <property name="jdbcUrl" value="${jdbc.url}"/>
    <property name="username" value="${jdbc.username}"/>
    <property name="password" value="${jdbc.password}"/>
    <property name="idleConnectionTestPeriodInMinutes" value="5"/>
    <property name="idleMaxAgeInSeconds" value="300"/>

    <!-- DB에 연결되는 최소 connection의 갯수는 partitionCount * minConnectionsPerPartition -->
    <property name="maxConnectionsPerPartition" value="10"/>
    <property name="minConnectionsPerPartition" value="2"/>
    <property name="partitionCount" value="2"/>

    <property name="acquireIncrement" value="1"/>
    <property name="acquireRetryAttempts" value="10"/>
    <property name="acquireRetryDelayInMs" value="5000"/>
    <!--<property name="statementsCacheSize" value="100"/>-->
    <property name="connectionTimeoutInMs" value="10000"/>
    <property name="connectionTestStatement" value="/* ping */ select 1"/>
    <property name="defaultAutoCommit" value="false"/>
    <property name="maxConnectionAgeInSeconds" value="28800"/>
</bean>

<!--log4jdb-remix를 주입한 datasource를 지정-->
<bean id="dataSource" class="net.sf.log4jdbc.Log4jdbcProxyDataSource">
    <constructor-arg ref="originDataSource"/>
    <property name="logFormatter">
        <bean class="net.sf.log4jdbc.tools.Log4JdbcCustomFormatter">
            <property name="loggingType" value="MULTI_LINE"/>
            <property name="sqlPrefix" value="SQL=>"/>
        </bean>
    </property>
</bean>

<bean id="sqlSessionFactory" class="org.mybatis.spring.SqlSessionFactoryBean">
    <property name="dataSource" ref="dataSource"/>
    <property name="mapperLocations" value="classpath:sqlmap/**/*.xml"/>
</bean>

위와 같이 하면 스프링에서 원래 사용하는 datasource에 log4jdbc-remix가 inject되므로, 정상적으로 Logging 되는 것을 활용할 수 있다.

하지만 이 방법에는 치명적인 단점이 있는데, DB에 대한 pool 기능이 동작하지 않는다.

요청이 있을 때마다 DB Connection이 열리고, DB Connection이 닫힌다. ㅠ.ㅠ

개발을 편하게 하자고, 쿼리 로깅을 하고는 쉽지만 DB Pool을 사용하지 못한다면, 성능에 어마어마한 리스크를 발생하게 되므로 이 방법도 추천하지 않는다.

 

그래서 결국은 1번 방법을 선택하게 되었는데, 도대체 기존 프로젝트에서는 어째서 시스템 프로퍼티에 maria db에 대한 드라이버를 지정하지 않았는데 에러가 발생하지 않고, 정상적으로 돌아갔는지 너무나도 궁금하여, 약 4시간을 투자해 디버깅을 해보았다 -_-;;

그 결과 기존 프로젝트는 web 기반 프로젝트가 아니라 stand alone 프로그램에 스프링으로 구성한 프로젝트 였는데 아래와 같이 실제 db에 대한 요청이 있을 때 db의 드라이버를 자동으로 생성한다는 것을 알았다.

위에서 보면 DriverManager 객체가 생성될 때 세번째 줄에 org.mariadb.jdbc가 등록되며 해당 클래스는 “maria=java-client”에서 로드된다.

 

반면에 web 기반의 프로젝트에서는 아래와 같이 톰캣 기동시에 DriverManager 객체가 로딩되며, 이때는 아무런 드라이버의 register과정이 없이 객체가 생성된다.

위 사실을 기반으로 추측해 보자면, web 기반이 아닌 프로젝트에서는 스프링에 대한 context가 먼저 올라간 다음 db에 대한 객체가 생성되면서 maven 디펜던시에 설정되어 있는 jdbc 관련 클래스들이 같이 딸려가서 자동으로 드라이버 클래스가 지정된 반면, web 기반 클래스에서는 톰캣이 기동하면서 DriverManager 객체가 생성되기 때문에 스프링에 설정된 jdbc 클래스 정보가 DriverManager에 등록되지 않은 채로 실행되는 것으로 보인다.

(위에서 maria db에 대한 register를 실행해주는 부분이 DriverManager의 생성자에서 이루어진다.)

 

이상으로 간단할 수 있는 쿼리 로깅에 대한 궁금증으로 삽질한 내용을 마친다.

오늘의 결론, 꼭 되야 되는데 안되거나, 안되야 되는데 되는데어는 반드시 이유가 있다~!!

kaze

Test

No Comments

Post a Comment

This site uses Akismet to reduce spam. Learn how your comment data is processed.