Springboot에서 P6Spy 통해 쿼리 로깅

1. 문제 & 도입 배경

Springboot + JPA를 사용하여 피처를 개발하다보면

실제 DB에 어떤 쿼리가 실행되는지 표시하고 싶을 때가 있습니다.

JPA 사용 시 아래와 같이 옵션을 주면 쿼리가 표시됩니다.

## application.yml
spring:  
  jpa:
    properties:
      hibernate:
        show_sql: true

 

아래와 같이 Hibernate: {SQL} 형식으로 표시됨을 확인 할 수 있습니다.

2024-02-03T10:11:16,918 INFO  [http-nio-8080-exec-1] o.s.w.s.FrameworkServlet: Completed initialization in 1 ms
Hibernate: select tblmember0_.id as id1_1_0_, tblmember0_.email as email3_1_0_ from tbl_member tblmember0_ where tblmember0_.id=?

 

추가로 format_sql: true를 주게되면

## application.yml
spring:  
  jpa:
    properties:
      hibernate:
        show_sql: true
        format_sql: true

 

아래와 같이 읽기 편하게 출력됨을 확인 할 수 있습니다.

 

2024-02-03T10:20:49,778 INFO  [http-nio-8080-exec-1] o.s.w.s.FrameworkServlet: Completed initialization in 1 ms
Hibernate: 
    select
        tblmember0_.id as id1_1_0_,
        tblmember0_.category as category2_1_0_,
        tblmember0_.email as email3_1_0_,
        tblmember0_.name as name4_1_0_ 
    from
        tbl_member tblmember0_ 
    where
        tblmember0_.id=?

 

하지만 where 절에 쓰인 파라미터는 ?로 표시되는데요.

SQL도구로 쿼리를 실행 해보고자 할 때, ?은 개발자가 직접 채워줘야하는 번거로움이 있습니다.

 

이것까지 모두 출력해주는 써드파티 라이브러리가 있습니다.

바로

P6Spy

입니다.

P6Spy는 자바 애플리케이션에서 JDBC(Java Database Connectivity)를 모니터링하고 디버깅하는 데 사용되는 툴입니다. 주로 데이터베이스 쿼리의 실행 시간, 호출된 스토어드 프로시저, 연결 및 트랜잭션 정보를 기록하는 데 사용됩니다.

일반적으로 P6Spy는 JDBC 드라이버를 래핑하여 애플리케이션이 데이터베이스와 상호 작용할 때의 성능 및 동작을 추적할 수 있도록 도와줍니다. 이는 개발자가 애플리케이션의 데이터베이스 상호 작용을 디버깅하거나 최적화하는 데 도움이 됩니다.

 

이번 포스팅에서는 P6Spy를 사용하여 쿼리를 로깅해봅니다.

 

2. 의존성 추가

포스팅 기준 로컬 환경은 아래와 같습니다.

• Windows 10
• Java 11
• Springboot 2.5.8

# build.gradle
dependencies {
	...(중략)
	/** p6spy **/
	implementation 'com.github.gavlyukovskiy:p6spy-spring-boot-starter:1.8.1'
}

 

 

3. application.yml에 설정 추가

아래와 같이 application.yml에 p6spy 관련 옵션을 추가해줍니다.

# application.yml
spring:
  datasource:
    p6spy:
      enabled: true
      appender: com.p6spy.engine.spy.appender.Slf4JLogger
      logMessageFormat:
        p6spy: "%(currentTime)|%(executionTime)|%(category)|%(sqlSingleLine)"

• enabled 활성화 해줍니다.
• appender는 Slf4JLogger로 설정해줍니다.
• messageFormat을 설정합니다.
  • currentTime: 현재시각
  • executionTime: 쿼리 수행 시간
  • category: jdbc driver 정보 표시
  • sqlSingleLine: SQL 표시

 

4. 실행 결과

로컬에 서비스 띄우고 특정 API를 호출해봤습니다.

2024-02-03T10:42:46,191 INFO  [http-nio-8080-exec-1] c.p.e.s.a.Slf4JLogger: #1706924566191 | took 1ms | statement | connection 16| url jdbc:mysql://localhost:3306/test
SELECT m.* FROM tbl_member m INNER JOIN tbl_category c ON c.category_id = m.category WHERE m.name LIKE CONCAT(?, '%')
SELECT m.* FROM tbl_member m INNER JOIN tbl_category c ON c.category_id = m.category WHERE m.name LIKE CONCAT('톰', '%');

 

위처럼 실행 쿼리 로깅 이외에도 실행 시간(executionTime) 등을 추가로 표시해주는 것을 확인 할 수 있습니다.

 

 

5. 끝으로

일반적으로 쿼리 로깅은 업무 단계(로컬 환경) 또는 개발 환경에서만 수행합니다.

그러므로 P6Spy 설정은 프로덕션 환경에서는 주의해야 합니다.

프로덕션 환경에는 enabled=false 해줍시다.