jOOQ ExecuteListener로 슬로우 쿼리 감지 - 헤매다가 힘들어서 만든 개발 블로그

jOOQ의 ExecuteListener를 활용하면 애플리케이션 레벨에서 슬로우 쿼리를 실시간 슬로우 쿼리 감지할 수 있다

ExecuteListener

ExecuteListener는 jOOQ가 제공하는 라이프사이클 훅으로, SQL 실행의 각 단계에서 커스텀 로직을 실행할 수 있게 해준다

executeStart(): 쿼리 실행 직전
executeEnd(): 쿼리 실행 완료 후
fetchStart(), fetchEnd(): 결과 패칭 전후
exception(): 예외 발생 시

PerformanceListener 구현

package org.sight.jooqstart.config;

import lombok.extern.slf4j.Slf4j;
import org.jooq.ExecuteContext;
import org.jooq.ExecuteListener;
import org.jooq.Query;
import org.jooq.tools.StopWatch;

import java.time.Duration;

@Slf4j
public class PerformanceListener implements ExecuteListener {
    
    private StopWatch watch;
    private static final Duration SLOW_QUERY_LIMIT = Duration.ofSeconds(3);

    @Override
    public void executeStart(ExecuteContext ctx) {
        watch = new StopWatch();
    }

    @Override
    public void executeEnd(ExecuteContext ctx) {
        final long queryTimeNano = watch.split();
        
        if (queryTimeNano > SLOW_QUERY_LIMIT.toNanos()) {
            Query query = ctx.query();
            Duration executeTime = Duration.ofNanos(queryTimeNano);
            
            log.warn(
                String.format(
                    """
                    ### Slow SQL 탐지 >>
                    경고: jOOQ로 실행된 쿼리 중 %d초 이상 실행된 쿼리가 있습니다.
                    실행시간: %s초
                    실행쿼리: %s
                    """,
                    SLOW_QUERY_LIMIT.toSeconds(),
                    millisToSeconds(executeTime),
                    query
                )
            );
        }
    }

    private String millisToSeconds(Duration duration) {
        return String.format("%.1f", duration.toMillis() / 1000.0);
    }
}

StopWatch를 인스턴스 변수로 선언하여 쿼리별 실행 시간 측정
executeStart()에서 타이머 시작
executeEnd()에서 시간 측정 후 임계값 초과 시 경고 로그 출력
나노초 단위로 정밀하게 측정 후 초 단위로 변환

jOOQ Configuration 등록

Spring Boot 3.x에서는 DefaultConfigurationCustomizer를 통해 jOOQ 설정을 커스터마이징 한다

package org.sight.jooqstart.config;

import org.jooq.conf.ExecuteWithoutWhere;
import org.springframework.boot.autoconfigure.jooq.DefaultConfigurationCustomizer;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

@Configuration
public class JooqConfig {
    
    @Bean
    public DefaultConfigurationCustomizer jooqDefaultConfigurationCustomizer() {
        return c -> {
            // PerformanceListener 등록
            c.set(PerformanceListener::new);
            
            // 추가 안전 설정
            c.settings()
                .withExecuteDeleteWithoutWhere(ExecuteWithoutWhere.THROW)  // WHERE 없는 DELETE 방지
                .withExecuteUpdateWithoutWhere(ExecuteWithoutWhere.THROW)  // WHERE 없는 UPDATE 방지
                .withRenderSchema(false);  // 스키마명 렌더링 비활성화
        };
    }
}

ExecuteWithoutWhere.THROW: WHERE 절 없는 DELETE/UPDATE 실행 시 예외 발생
withRenderSchema(false): 쿼리에 스키마명을 포함하지 않음

테스트

package org.sight.jooqstart;

import org.jooq.DSLContext;
import org.jooq.impl.DSL;
import org.junit.jupiter.api.DisplayName;
import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.context.SpringBootTest;

import static org.jooq.impl.DSL.dual;

@SpringBootTest
public class JooqSlowQueryTest {

    @Autowired
    DSLContext dslContext;

    @Test
    @DisplayName("SLOW 쿼리 탐지 테스트")
    void 슬로우쿼리_탐지_테스트() {
        // 4초 대기하는 슬로우 쿼리 실행
        dslContext.select(DSL.field("SLEEP(4)"))
                .from(dual())
                .execute();
    }
}

실행 결과

### Slow SQL 탐지 >>
경고: jOOQ로 실행된 쿼리 중 3초 이상 실행된 쿼리가 있습니다.
실행시간: 4.1초
실행쿼리: select SLEEP(4)
from (
  select 'X' as `DUMMY`
) as `DUAL`

환경별 임계값 설정

프로덕션과 개발 환경에서 다른 임계값을 사용

@Slf4j
public class PerformanceListener implements ExecuteListener {
    
    private final Duration slowQueryLimit;
    private StopWatch watch;

    public PerformanceListener(Duration slowQueryLimit) {
        this.slowQueryLimit = slowQueryLimit;
    }

    // 나머지 코드는 동일...
}

@Configuration
public class JooqConfig {
    
    @Value("${jooq.slow-query-limit-seconds:3}")
    private long slowQueryLimitSeconds;
    
    @Bean
    public DefaultConfigurationCustomizer jooqDefaultConfigurationCustomizer() {
        return c -> {
            Duration limit = Duration.ofSeconds(slowQueryLimitSeconds);
            c.set(() -> new PerformanceListener(limit));
            // ...
        };
    }
}

모니터링 시스템 연동

실무에서는 로그만으로 부족할 수 있다. Micrometer를 통해 메트릭으로 수집할 수 있다

@Override
public void executeEnd(ExecuteContext ctx) {
    final long queryTimeNano = watch.split();
    Duration executeTime = Duration.ofNanos(queryTimeNano);
    
    // 메트릭 기록
    meterRegistry.timer("jooq.query.execution")
        .record(executeTime);
    
    // 슬로우 쿼리 감지
    if (queryTimeNano > slowQueryLimit.toNanos()) {
        meterRegistry.counter("jooq.slow.query").increment();
        // 로깅...
    }
}

쿼리 파라미터 포함

디버깅을 위해 바인딩된 파라미터 값도 함께 로깅

log.warn(
    String.format(
        """
        ### Slow SQL 탐지 >>
        실행시간: %s초
        실행쿼리: %s
        바인딩 값: %s
        """,
        millisToSeconds(executeTime),
        ctx.query(),
        ctx.query().getBindValues()  // 바인딩된 값
    )
);

주의 사항

스레드 안정성: 현재 구현은 각 쿼리 실행마다 새로운 PerformanceListener 인스턴스를 생성하므로 (PerformanceListener::new) 스레드 안전하다
성능 오버헤드: StopWatch와 로깅의 오버헤드는 매우 적지만, 초고성능이 요구되는 환경에서는 샘플링 방식 고려가 필요할 수 있다
로그 레벨: WARN 레벨로 설정했으므로 프로덕션 환경에서도 누락 없이 감지된다

ExecuteListener를 활용하면 별도의 APM(Application Performance Monitoring) 도구 없이도 애플리케이션 레벨에서 슬로우 쿼리를 효과적으로 모니터링할 수 있다. 특히 jOOQ를 사용하는 환경에서는 쿼리 실행 시점에 정확히 개입할 수 있어 유용하다

개발 단계에서 성능 문제를 조기 발견
프로덕션 환경에서 실시간 슬로우 쿼리 감지
배치 작업이나 대량 데이터 처리 시 병목 지점 파악

출처 – 실전 jOOQ! Type Safe SQL with Java