Springboot Project 05 - MyBatis 로그 파라메타 결합 후 예쁘게 출력하기

Spring Boot 프로젝트에서 MyBatis를 사용하여 SQL 실행 및 로깅을 손쉽게 관리할 수 있습니다. 이 글에서는 MyBatis 설정 파일, 인터셉터 설정, Logback 설정을 통해 SQL 쿼리와 파라미터, 실행 시간을 예쁘게 출력하는 방법을 설명합니다.

1. MyBatis 설정 파일에서 쿼리 로깅 활성화

application.properties 파일을 수정하여 MyBatis의 로그 레벨을 DEBUG로 설정합니다. 이렇게 하면 MyBatis의 쿼리 로그가 디버그 모드로 출력됩니다.

# MyBatis 쿼리 로그를 디버그로 출력
logging.level.org.apache.ibatis=DEBUG
logging.level.com.zaxxer.hikari.HikariDataSource=DEBUG

 

2. MyBatis Logback 설정

MyBatis의 로깅을 Logback을 통해 출력하도록 설정합니다. src/main/resources/logback-spring.xml 파일을 만들어 아래와 같이 작성합니다.

<configuration>
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>
                %d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n
            </pattern>
        </encoder>
    </appender>

    <logger name="org.apache.ibatis" level="DEBUG" additivity="false">
        <appender-ref ref="CONSOLE" />
    </logger>

    <root level="INFO">
        <appender-ref ref="CONSOLE" />
    </root>
</configuration>

 

이제 org.apache.ibatis 패키지의 로그가 디버그 레벨로 콘솔에 출력됩니다.

3. MyBatis 인터셉터로 결합된 쿼리 출력

QueryLogInterceptor 클래스를 작성하여 SQL 실행 및 파라미터를 로깅합니다.

package com.alphonse.config.mybatis;

import org.apache.ibatis.executor.statement.StatementHandler;
import org.apache.ibatis.plugin.*;
import org.apache.ibatis.session.ResultHandler;
import org.apache.ibatis.reflection.MetaObject;
import org.apache.ibatis.reflection.SystemMetaObject;

import java.sql.Connection;
import java.sql.Statement;
import java.util.Map;
import java.util.Properties;
import java.util.regex.Matcher;
import java.util.regex.Pattern;

@Intercepts({
    @Signature(type = StatementHandler.class, method = "prepare", args = {Connection.class, Integer.class}),
    @Signature(type = StatementHandler.class, method = "query", args = {Statement.class, ResultHandler.class}),
    @Signature(type = StatementHandler.class, method = "update", args = {Statement.class})
})
public class QueryLogInterceptor implements Interceptor {

    private static final Pattern PARAM_PATTERN = Pattern.compile("\\?");
    private static final ThreadLocal<Boolean> isLogging = ThreadLocal.withInitial(() -> false);

    @Override
    public Object intercept(Invocation invocation) throws Throwable {
        StatementHandler statementHandler = (StatementHandler) invocation.getTarget();
        MetaObject metaObject = SystemMetaObject.forObject(statementHandler);
        String originalSql = statementHandler.getBoundSql().getSql();

        // 파라미터 객체 가져오기
        Object parameterObject = statementHandler.getBoundSql().getParameterObject();
        Map<String, Object> parameterMap = extractParameters(parameterObject);

        // `prepare` 메서드에서만 로그를 찍도록 처리
        if (invocation.getMethod().getName().equals("prepare") && !isLogging.get()) {
            isLogging.set(true);

            // SQL 포맷
            String type2Sql = formatSqlWithNamedParams(originalSql, parameterMap);
            String type3Sql = replaceParamsWithValues(originalSql, parameterMap);
            String parameterDetails = formatParameterDetails(parameterMap);

            // 로그 출력
            System.out.println("\n====================================\n");
            System.out.println(type2Sql);
            System.out.println("\n---------------------------------\n");
            System.out.println(type3Sql);
            System.out.println("\n---------------------------------\n");
            System.out.println("넘어온 파라미터:\n" + parameterDetails);
            System.out.println("\n====================================\n");

            // SQL 실행 및 시간 측정
            long startTime = System.nanoTime();
            Object result = invocation.proceed();
            long endTime = System.nanoTime();
            long executionTime = (endTime - startTime) / 1_000_000; // 나노초를 밀리초로 변환

            // 실행 시간 출력
            System.out.println("실행 시간: " + executionTime + " ms");
            isLogging.remove(); // 로그 출력 후 상태 초기화
            return result;
        } else {
            // `query` 또는 `update` 메서드에서는 로깅을 하지 않음
            return invocation.proceed();
        }
    }

    private Map<String, Object> extractParameters(Object parameterObject) {
        if (parameterObject instanceof Map) {
            return (Map<String, Object>) parameterObject;
        } else if (parameterObject != null) {
            MetaObject metaObject = SystemMetaObject.forObject(parameterObject);
            Map<String, Object> paramMap = new java.util.HashMap<>();
            for (String getterName : metaObject.getGetterNames()) {
                paramMap.put(getterName, metaObject.getValue(getterName));
            }
            return paramMap;
        }
        return new java.util.HashMap<>();
    }

    private String formatSqlWithNamedParams(String sql, Map<String, Object> params) {
        Matcher matcher = PARAM_PATTERN.matcher(sql);
        StringBuffer formattedSql = new StringBuffer();
        int index = 0;

        while (matcher.find() && index < params.size()) {
            String paramName = (String) params.keySet().toArray()[index];
            String paramValue = params.get(paramName) == null ? "NULL" : "'" + params.get(paramName).toString().replace("'", "''") + "'";
            matcher.appendReplacement(formattedSql, "{" + paramName + "=" + paramValue + "}");
            index++;
        }
        matcher.appendTail(formattedSql);

        return formattedSql.toString().replaceAll("\\s+", " ")
                                        .replaceAll("(?i)(select|from|where|insert|update|delete|group by|order by)", "\n$1");
    }

    private String replaceParamsWithValues(String sql, Map<String, Object> params) {
        Matcher matcher = PARAM_PATTERN.matcher(sql);
        StringBuffer actualSql = new StringBuffer();
        int index = 0;

        while (matcher.find() && index < params.size()) {
            String paramValue = params.values().toArray()[index] == null ? "NULL" : "'" + params.values().toArray()[index].toString().replace("'", "''") + "'";
            matcher.appendReplacement(actualSql, paramValue);
            index++;
        }
        matcher.appendTail(actualSql);

        return actualSql.toString().replaceAll("\\s+", " ")
                                   .replaceAll("(?i)(select|from|where|insert|update|delete|group by|order by)", "\n$1");
    }

    private String formatParameterDetails(Map<String, Object> params) {
        StringBuilder paramDetails = new StringBuilder();
        for (Map.Entry<String, Object> entry : params.entrySet()) {
            String key = entry.getKey();
            String value = entry.getValue() == null ? "NULL" : "'" + entry.getValue().toString().replace("'", "''") + "'";
            paramDetails.append(key).append("=").append(value).append("\n");
        }
        return paramDetails.toString();
    }

    @Override
    public Object plugin(Object target) {
        return Plugin.wrap(target, this);
    }

    @Override
    public void setProperties(Properties properties) {
        // 설정 필요 시 추가
    }
}

 

4. MyBatis 인터셉터 설정

MyBatisConfig.java 파일을 작성하여 QueryLogInterceptor를 MyBatis 설정에 추가합니다.

package com.alphonse.config.mybatis;

import org.apache.ibatis.session.Configuration;
import org.mybatis.spring.boot.autoconfigure.ConfigurationCustomizer;
import org.springframework.context.annotation.Bean;

@org.springframework.context.annotation.Configuration
public class MyBatisConfig {

    @Bean
    public ConfigurationCustomizer configurationCustomizer() {
        return configuration -> configuration.addInterceptor(new QueryLogInterceptor());
    }
}

 

결론

이제 위의 설정을 통해 Spring Boot 프로젝트에서 MyBatis 쿼리 로그를 예쁘게 출력하고, SQL 실행 시간과 파라미터를 확인할 수 있습니다. application.properties, logback-spring.xml, QueryLogInterceptor, MyBatisConfig를 모두 적용하면 콘솔에서 디버그 정보를 손쉽게 확인할 수 있습니다.