log4jdbc-remix의 Custom SQL Formatter 만들기(SQL log 줄 바꿈)

SQL Query 로그의 줄을 바꿔서 어느정도 예쁘게 출력하는 방법을 알아보겠습니다. log4jdbc-remix 를 사용해서 쿼리 로그를 만들게 됩니다. 테스트는 전자정부표준프레임워크 비즈니스 템플릿을 MySQL(실제는 MariaDB)와 연동한 소스에서 하였습니다.

전자정부표준프레임워크는 SQL 쿼리를 로그로 출력하기 위해서 log4jdbc를 사용하고 있습니다. log4jdbc-remix는 log4jdbc의 또다른 실험적인 분기로써 SQL 포맷뿐만 아니라 DB로부터 가져오는 값들을 추적할 수 있는 다양한 기능을 제공합니다. 실제 적용해본 결과로는 두가지 문제점이 있었습니다.

첫 번째는 쿼리 왼쪽에 여백을 주는 margin 프로퍼티를 사용하면 오류가 발생합니다.

java.util.FormatFlagsConversionMismatchException: Conversion = s, Flags = #

오류의 원인은 주어진 margin의 숫자만큼 공백 문자열을 만드는 포맷문자 #이 JDK 버전이 올라가면서 오류를 내는 것입니다.

margin = String.format("%1$#" + n + "s", "");

두 번째는 줄 바꿈을 하는 loggingType 프로퍼티를 MULTI_LINE으로 주더라도 줄 바꿈이 되지 않는 문제였습니다.

<property name="loggingType" value="MULTI_LINE" />

이 문제의 원인은 select, from 등 줄 바꿈을 하는 위치를 찾는 코드에서 소문자인 경우만 처리를 하고 있어서 였습니다.

이 문제들은 기본 Formatter인 net.sf.log4jdbc.tools.Log4JdbcCustomFormatter를 문제를 수정한 포맷터로 교체하여 해결하였습니다.

1. 다음 의존성을 pom.xml 파일에 추가하여 log4jdbc-remix를 사용할 수 있도록 합니다.

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

2. net.sf.log4jdbc.Slf4jSpyLogDelegator를 구현한 커스텀 포맷터를 만듭니다.  com.tistory.pentode.log.Log4JdbcCustomFormatter.java 파일 입니다.

이 코드는 기존의 코드를 기본으로 에러가 나는곳만 수정한 코드입니다. 전체소스는 글 하단에 첨부 하였습니다. 이 소스는 원래 소스와 같은 Apache 2.0 라이센스를 따르며 이 소스를 사용함에 있어서 발생하는 어떤 문제도 책임을 지지 않습니다.

public void setMargin(int n) {
    // 문제를 일으키는 포맷문자 # 을 제거합니다.
    margin = String.format("%1$" + n + "s", "");
}

@Override
public String sqlOccured(Spy spy, String methodCall, String rawSql) {

    if (loggingType == LoggingType.DISABLED) {
        return "";
    }

    // Remove all existing cr lf, unless MULTI_LINE
    if (loggingType != LoggingType.MULTI_LINE) {
        rawSql = rawSql.replaceAll("\r", "");
        rawSql = rawSql.replaceAll("\n", "");
    }

    // 쿼리를 트림하고, 여러개의 공백은 하나로 변경합니다.
    rawSql = rawSql.trim();
    rawSql = rawSql.replaceAll("\\s+", " ");

    final String fromClause = " FROM ";

    String sql = rawSql;
    if (loggingType == LoggingType.MULTI_LINE) {

        final String whereClause = " WHERE ";
        final String andClause = " AND ";
        final String orderByClause = " ORDER BY ";
        final String groupByClause = " GROUP BY ";
        final String subSelectClauseS = "\\(SELECT";
        final String subSelectClauseR = " (SELECT";

        // 개행을 하는 정규식에서 대소문자를 구분하지 않도록 수정합니다.
        sql = sql.replaceAll("(?i)" + fromClause, "\n " + margin + fromClause);
        sql = sql.replaceAll("(?i)" + whereClause, "\n" + margin + whereClause);
        sql = sql.replaceAll("(?i)" + andClause, "\n  " + margin + andClause);
        sql = sql.replaceAll("(?i)" + orderByClause, "\n" + margin + orderByClause);
        sql = sql.replaceAll("(?i)" + groupByClause, "\n" + margin + groupByClause);
        sql = sql.replaceAll("(?i)" + subSelectClauseS, "\n      " + margin + subSelectClauseR);
    }

    if (loggingType == LoggingType.SINGLE_LINE_TWO_COLUMNS) {
        if (sql.startsWith("select")) {
            String from = sql.substring(sql.indexOf(fromClause) + fromClause.length());
            sql = from + "\t" + sql;
        }
    }

    getSqlOnlyLogger().info(sqlPrefix + "\n" + margin + sql);

    return sql;
}

3. globals.properties 파일을 수정합니다.

기존의 log4jdbc를 사용하던것을 주석 처리하고, com.mysql.jdbc.Driver 을 사용하도록 수정합니다.

# mysql
Globals.DriverClassName=com.mysql.jdbc.Driver
Globals.Url=jdbc:mysql://127.0.0.1:3306/businessdb

#Globals.DriverClassName=net.sf.log4jdbc.DriverSpy
#Globals.Url=jdbc:log4jdbc:mysql://127.0.0.1:3306/businessdb

4. context-datasource.xml 파일을 수정합니다.

기존의 dataSource-mysql은 dataSource-mysql-spied 로 id 를 수정하고, dataSource-mysql 은 remix를 사용하도록 수정합니다.

- logFormatter로 새로만든 com.tistory.pentode.log.Log4JdbcCustomFormatter를 지정합니다. 원래 포맷터를 사용하려면 net.sf.log4jdbc.tools.Log4JdbcCustomFormatter를 입력합니다.

- loggingType은 줄 바꿈을 하도록 MULTI_LINE 으로 지정합니다.

- margin은 쿼리의 왼쪽에 여백을 가지도록 적당한 값을 지정합니다.

- sqlPrefix는 쿼리 앞부분에 구분자 처럼 추가할 수 있는 문자열 입니다.

<!-- mysql -->
<bean id="dataSource-mysql" class="net.sf.log4jdbc.Log4jdbcProxyDataSource">
    <constructor-arg ref="dataSource-mysql-spied" />
    <property name="logFormatter">
        <bean class="com.tistory.pentode.log.Log4JdbcCustomFormatter">
            <property name="loggingType" value="MULTI_LINE" />
            <property name="margin" value="8" />
            <property name="sqlPrefix" value="SQL:" />
        </bean>
    </property>
</bean>

<bean id="dataSource-mysql-spied" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
    <property name="driverClassName" value="${Globals.DriverClassName}"/>
    <property name="url" value="${Globals.Url}" />
    <property name="username" value="${Globals.UserName}"/>
    <property name="password" value="${Globals.Password}"/>
</bean>

5. log4j2.xml 파일에 로거를 추가합니다.

<Logger name="jdbc.sqlonly" level="INFO" additivity="false">
    <AppenderRef ref="console" />
</Logger>

이외에도 다양한 기능을 하는 로거 들이 있습니다.

- jdbc.sqltiming : SQL 실행 소요 시간에 대한 타이밍 통계를 포함하여 실행 후 SQL을 기록합니다.

- jdbc.resultset : ResultSet 객체에 대한 모든 메소드 호출이 기록되기 때문에 훨씬 더 방대한 양의 로그가 나옵니다.

- jdbc.resultsettable : 데이터베이스 조회 결과를 테이블 형식으로 보여줍니다.

- jdbc.audit : ResultSet 을 제외한 모든 jdbc 호출을 출력합니다.

6. 실행 결과  입니다.

※ 참고사항

log4jdbc-remix가 2013-11-06일 죽었다고(개발중지) 합니다(https://code.google.com/archive/p/log4jdbc-remix/). 이제는 log4jdbc-remix와 log4jdbc의 다른 분기(fork)인 log4jdbc-log4j2를 사용하라고 하고 있습니다.(https://code.google.com/p/log4jdbc-log4j2/)

※ 포맷터 소스

src.zip