P6Spy를 이용하여 로그 출력하기

프로젝트를 하다보면 성능 개선을 위해 어느 쿼리가 얼마나 걸리고, 어떻게 쿼리를 호출하는지 확인해야 할 경우가 있습니다.

JPA QueryDSL을 이용할 때 여러 조인과 entity의 관계를 정의하다 보면 생각하지 못한 부분에서 속도가 매우 느린 경우도 있고, 대용량으로 데이터가 들어오면 잘 되던 쿼리가 느려질 때도 있습니다.

이럴때 p6spy를 이용하여 쿼리를 보기 좋고, 얼마나 걸리는지 확인할 수 있는 방법에 대해 정리했습니다.

위의 저장소 에서 쿼리를 로그에 출력할 수 있는 간단한 h2 CRUD 예제 코드를 작성했습니다.

위의 예제를 실행하면 아래와 같이 쿼리를 수행함을 확인할 수 있습니다.

p6Spy는 기존 코드의 변경 없이 SQL 로그를 출력해주는 프레임워크 입니다.

주요 포인트는 p6Spy에서 제공하는 인터페이스 중 MessageFormattingStrategy 파일을 상속 받아 해당 메서드를 override 하여 사용합니다.

아래의 사진과 같이 전략 패턴(Strategy Pattern)을 이용하여 프로그램 런타임 시 기존의 @PostConstruct를 사용하여 미리 정의된 formatMessage를 이용합니다.

공식 문서 에서 제공하는 많은 기능 중 필요한 기능만 spy.properties에 정의합니다.

1
2
3
appender=com.p6spy.engine.spy.appender.Slf4JLogger
logMessageFormat=com.p6spy.engine.spy.appender.CustomLineFormat
customLogMessageFormat=| %(executionTime) ms | %(sql)

기본적으로 application.yml에서 쿼리 로그를 ON/OFF 할 수 있습니다.

1
2
3
4
decorator:
  datasource:
    p6spy:
      enable-logging: true

위와 같이 설정을 하고 P6SpySqlFormatterConfig 클래스 파일에서 시간 초과 기준을 정하면 쿼리의 실행 속도 및 수행한 쿼리를 쉽게 확인할 수 있으며, 어디에서 문제가 발생했는지 쉽게 확인할 수 있으니, 쿼리 성능 개선을 조금 더 편하게 할 수 있을 것이라 생각합니다.

참고#

참고