[SpringBoot] JPA 개발 시 p6spy를 이용해서 쿼리 로그 남기기

JPA를 공부하다보니, JPA에서는 Logging 시 p6spy 이라는 걸 사용하는 방법도 있다고 합니다.

SpringBoot 만을 사용할때에는  log4jdbc-log4j2를 주로 사용했는데, JPA를 보다보니 p6spy라는 것도 있네요.

참조가 필요합니다.

// jpa query logging
implementation 'com.github.gavlyukovskiy:p6spy-spring-boot-starter:1.8.1'

src/main/resources/spy.properties

driverlist=org.h2.Driver
appender=com.p6spy.engine.spy.appender.Slf4JLogger
logMessageFormat=com.p6spy.engine.spy.appender.MultiLineFormat

application.yml

spring:
  jpa:
    open-in-view: false
    #show-sql: true       # System.out 으로 출력. logging.level.org.hibernate.SQL=debug 로 대체합니다. 
    hibernate:
      # create : entity를 drop cascade 하고 다시 생성
      # update : entity가 수정되면 수정된 내용만 반영
      # create-drop,validate, none
      # 하이버네이트가 자동으로 생성해주는 DDL은 신뢰성이 떨어지기 때문에 
      # 절대로! 운영DB 환경에서 그대로 사용하면 안되고, 직접 DDL을 작성하는 것을 권장
      ddl-auto: none
    #generate-ddl: true
    #properties:           # Additional native properties to set on the JPA provider.
      #hibernate:
        #show-sql: true                  # System.out 으로 출력
        #format_sql: true                # 로그, 콘솔의 SQL을 좀 더 이쁘게 출력합니다.
        #highlight_sql: true             # SQL 출력을 ANSI escape codes를 사용하여 색을 부여합니다.
        #use_sql_comments: true          # 보다 쉬운 디버깅을 위해 SQL 내부에 /* */의 주석을 추가합니다.
        
# Logging
logging:
  level:  # 각 package 별로 로깅 레벨을 지정할 수 있다.
    root : info
    octopus: debug
    org.springframework: WARN
    #org.hibernate.SQL: debug                    # logger를 통해 하이버네이트 실행 SQL
    #org.hibernate.type.descriptor.sql: trace    # sql의 ? 값을 Parameter로 보여줌.
    
# p6spy 를 위한 설정
decorator.datasource.p6spy.enable-logging: true     # false : Disable p6spy
#decorator.datasource.enable: true

---

INFO  23-03-10 23:27:794[http-nio-9090-exec-1] p6spy.logSQL[60]: - #1678458432794 | took 6ms | statement | connection 4| url jdbc:h2:tcp://localhost/~/test
select tcodem0_.p_cd as p_cd1_3_, tcodem0_.p_cd_nm as p_cd_nm11_3_, tcodem0_.rmk as rmk12_3_, tcodem0_.use_yn as use_yn13_3_ from t_code_m tcodem0_ where tcodem0_.p_cd=?
select tcodem0_.p_cd as p_cd1_3_, tcodem0_.p_cd_nm as p_cd_nm11_3_, tcodem0_.rmk as rmk12_3_, tcodem0_.use_yn as use_yn13_3_ from t_code_m tcodem0_ where tcodem0_.p_cd='USE_YN';
INFO  23-03-10 23:27:806[http-nio-9090-exec-1] p6spy.logSQL[60]: - #1678458432806 | took 0ms | commit | connection 4| url jdbc:h2:tcp://localhost/~/test

한줄로 찍힘니다. 아래와 같이 변경할 수 있습니다.

INFO  23-03-10 23:30:378[http-nio-9090-exec-1] p6spy.logSQL[60]: - [statement] | 0 ms | 
    select
        tcodem0_.p_cd as p_cd1_3_,
        tcodem0_.p_cd_nm as p_cd_nm11_3_,
        tcodem0_.rmk as rmk12_3_,
        tcodem0_.use_yn as use_yn13_3_,    
    from
        t_code_m tcodem0_       
    where
        tcodem0_.p_cd='USE_YN'
INFO  23-03-10 23:30:380[http-nio-9090-exec-1] p6spy.logSQL[60]: - [commit] | 0 ms |

P6SpySqlFormatter.java

package octopus.config;

import java.util.Locale;
import java.util.Stack;

import javax.annotation.PostConstruct;

import org.hibernate.engine.jdbc.internal.FormatStyle;
import org.springframework.context.annotation.Configuration;

import com.p6spy.engine.logging.Category;
import com.p6spy.engine.spy.P6SpyOptions;
import com.p6spy.engine.spy.appender.MessageFormattingStrategy;

@Configuration
public class P6SpySqlFormatter implements MessageFormattingStrategy {
    
    @PostConstruct
    public void setLogMessageFormat() {
        P6SpyOptions.getActiveInstance().setLogMessageFormat(this.getClass().getName());
    }
    
    @Override
    public String formatMessage(int connectionId, String now, long elapsed, String category, String prepared,
            String sql, String url) {
        sql = formatSql(category, sql);
        
        // sql 이 없다면 출력하지 않아도 됨
        if (sql.trim().isEmpty()) {
            return "";
        }
        
        //return String.format("[%s] | %d ms | %s", category, elapsed, formatSql(category, sql));
        return String.format("[%s] | %d ms | %s", category, elapsed, sql + createStack(connectionId, elapsed));
    }
    
    private String formatSql(String category, String sql) {
        if (sql != null && !sql.trim().isEmpty() && Category.STATEMENT.getName().equals(category)) {
            String trimmedSQL = sql.trim().toLowerCase(Locale.ROOT);
            if (trimmedSQL.startsWith("create") || trimmedSQL.startsWith("alter") || trimmedSQL.startsWith("comment")) {
                sql = FormatStyle.DDL.getFormatter().format(sql);
            } else {
                sql = FormatStyle.BASIC.getFormatter().format(sql);
            }
            return sql;
        }
        
        return sql;
    }
    
    // stack 콘솔 표기
    private String createStack(int connectionId, long elapsed) {
        Stack<String>       callStack  = new Stack<>();
        StackTraceElement[] stackTrace = new Throwable().getStackTrace();
        
        for (StackTraceElement stackTraceElement : stackTrace) {
            String trace = stackTraceElement.toString();
            
            // trace 항목을 보고 내게 맞는 것만 필터
            if(trace.startsWith("octopus.backend")) {
                callStack.push(trace);
            }
        }
        
        StringBuffer sb    = new StringBuffer();
        int          order = 1;
        while (callStack.size() != 0) {
            sb.append("\n\t\t" + (order++) + "." + callStack.pop());
        }
        
        return new StringBuffer().append("\n\n\tConnection ID:").append(connectionId).append(" | Excution Time:")
                .append(elapsed).append(" ms\n").append("\n\tExcution Time:").append(elapsed).append(" ms\n")
                .append("\n\tCall Stack :").append(sb).append("\n").append("\n--------------------------------------")
                .toString();
    }
}

 

---

https://github.com/gavlyukovskiy/spring-boot-data-source-decorator

GitHub - gavlyukovskiy/spring-boot-data-source-decorator: Spring Boot integration with p6spy, datasource-proxy, flexy-pool and s

https://hch4102.tistory.com/147

쿼리 튜닝을 편하게! p6spy 개조하기

https://p6spy.readthedocs.io/en/latest/configandusage.html

Configuration and Usage — p6spy 3.9.2-SNAPSHOT documentation

https://shanepark.tistory.com/415

[Spring Boot JPA] P6Spy 활용해 쿼리 로그 확인하기

https://www.inflearn.com/questions/501492/p6spy-%EB%A1%9C%EA%B7%B8-%EB%91%90-%EB%B2%88-%EC%B0%8D%ED%9E%88%EB%8A%94-%EC%9D%B4%EC%9C%A0

p6spy 로그 두 번 찍히는 이유 - 인프런