JPA 사용 중 쿼리 가로채기, 모든 컨트롤러 메소드 중 발생하는 쿼리 검사

영슈·2024년 8월 18일
2

더 나은 개발자 되기

목록 보기
14/21
post-thumbnail

이 글은 그 전 글인 자바 리플렉션 어디 까지 가능할까에 대한 추가적인 내용이다.

매우 간단한 내용이므로, 쿼리 가로채기를 어떻게 구현했는지 + 최종적으로 내가 만든 결과서에 대해서 보여주고 마무리 할 예정이다.

사실상, 하나의 요청에 나가는 쿼리 개수를 효율적으로 세어보자 (Hibernate StatementInspector, Spring AOP)
이분의 글을 참고해 만든게 다이다.

쿼리 가로채기

QueryInfo

public interface QueryInfo {  
  
    void increaseQueryCount(String query);  
  
    String toFormatString();  
  
    boolean isExceedQuery();  
  
    int getCount();  
  
    void clear();  
}

우선, 쿼리의 정보를 가지고 값들을 담당하는 QueryInfo 라는 인터페이스를 만들었다.

왜 인터페이스인가요?
나는, 이 QueryInfo 를 앞 게시글인 쿼리 실행 결과 보고서를 위해서도 사용할 예정이라 분리를 했다.
즉, 테스트나 검사(Inspect) 상황에서도 쓰고 싶어서 만든것

import corea.global.aspect.query.QueryInfo;  
import lombok.Getter;  
import lombok.RequiredArgsConstructor;  
import org.springframework.context.annotation.Profile;  
import org.springframework.stereotype.Component;  
import org.springframework.web.context.annotation.RequestScope;  
  
import java.util.HashMap;  
import java.util.Map;  
  
@Component  
@RequiredArgsConstructor  
@Profile({"dev", "local"})  
@RequestScope  
@Getter  
public class DevQueryInfo implements QueryInfo {  
  
    private static final int MIN_WARN_SIZE = 10;  
    private Map<String, Integer> data = new HashMap<>();  
  
    public void increaseQueryCount(String query) {  
        data.merge(query, 1, Integer::sum);  
    }  
  
    public String toFormatString() {  
        StringBuilder sb = new StringBuilder();  
        data.forEach((key, value) ->  
                sb.append(key)  
                        .append(" : ")  
                        .append(value)  
                        .append(System.lineSeparator())  
                        .append(System.lineSeparator())  
        );  
        return sb.toString();  
    }  
  
    @Override  
    public boolean isExceedQuery() {  
        return data.values()  
                .stream()  
                .reduce(0, Integer::sum) >= MIN_WARN_SIZE;  
    }  
  
    @Override  
    public void clear() {  
        data.clear();  
    }  
  
    @Override  
    public int getCount() {  
        return sum();  
    }  
  
    private int sum() {  
        return data.values()  
                .stream()  
                .mapToInt(Integer::intValue)  
                .sum();  
    }  
}
@Component  
@RequiredArgsConstructor  
@Profile("inspect")  
@Getter
public class InspectQueryInfo implements QueryInfo {
	...
}

이렇게, 알아서 구현하고 Profile 과 RequestScope 만 다르게 했다.
실제 요청에서 싱글톤으로 스코프를 지정할 시, 여러 요청들이 하나의 컴포넌트를 침범해서 문제가 발생한다.
-> 이를 위해서 각 요청마다 새로운 컴포넌트를 만들어주는 RequestScope 를 사용했다.

하지만, 검사할 때는 단일 요청에서 발생하므로 상관이 없다.

QueryInspector

package corea.global.aspect.query;  
  
import org.hibernate.resource.jdbc.spi.StatementInspector;  
import org.springframework.core.env.Environment;  
import org.springframework.stereotype.Component;  
import org.springframework.web.context.request.RequestContextHolder;  
  
import java.util.Arrays;  
import java.util.Objects;  
  
@Component  
public class QueryInspector implements StatementInspector {  
  
    private final QueryInfo queryInfo;  
    private final boolean flag;  
  
    public QueryInspector(final QueryInfo apiQueryCounter, final Environment environment) {  
        this.queryInfo = apiQueryCounter;  
        this.flag = Arrays.stream(environment.getActiveProfiles())  
                .anyMatch(profile -> profile.equals("inspect"));  
    }  
  
    @Override  
    public String inspect(final String sql) {  
        if (isInRequestScope() || flag) {  
            queryInfo.increaseQueryCount(sql);  
        }  
        return sql;  
    }  
  
    private boolean isInRequestScope() {  
        return Objects.nonNull(RequestContextHolder.getRequestAttributes());  
    }  
}

StatementInspector 가 뭐지?
-> Hibernate 가 쿼리를 생성하고, DB에 보내기 전 SQL 문을 검사하고 조작하게 해주는 인터페이스이다.

Inspector : 검사하다

즉, 여기서 쿼리를 받아서 로깅을 위해 QueryInfo 에 값을 넣는다.

이때, 실행하는 분기를

  • 프로파일이 inspect ( 검사 때를 위한 설정 )
  • RequestAttributes 가 있을 때 ( 실제 요청이 발생할 때 - 이때, 테스트에서 동작 시킨다면 SpringBootTest 를 RANDOM or DEFINED 로 해도 똑같이 에러가 발생한다.)

로 지정했다.

QueryLoggingAspect

package corea.global.aspect.query;  
  
import lombok.RequiredArgsConstructor;  
import org.apache.logging.log4j.LogManager;  
import org.apache.logging.log4j.Logger;  
import org.aspectj.lang.ProceedingJoinPoint;  
import org.aspectj.lang.annotation.Around;  
import org.aspectj.lang.annotation.Aspect;  
import org.aspectj.lang.annotation.Pointcut;  
import org.springframework.context.annotation.Profile;  
import org.springframework.stereotype.Component;  
  
@Aspect  
@RequiredArgsConstructor  
@Component  
@Profile("!prod")  
public class QueryLoggingAspect {  
  
    private static final Logger log = LogManager.getLogger(QueryLoggingAspect.class);  
    private final QueryInfo queryInfo;  
  
    @Pointcut("execution(* corea..*Controller.*(..))")  
    public void controllerMethods() {}  
  
    @Around("controllerMethods()")  
    public Object logSqlStatements(ProceedingJoinPoint joinPoint) throws Throwable {  
        queryInfo.clear();  
        Object result = joinPoint.proceed();  
  
        String className = joinPoint.getSignature()  
                .getDeclaringTypeName();  
        String methodName = joinPoint.getSignature()  
                .getName();  
        String logs = queryInfo.toFormatString();  
  
        if (queryInfo.isExceedQuery()) {  
            log.warn("{}.{} exceeded query limit(count:{}): \n{}", className, methodName, queryInfo.getCount(), logs);  
        } else {  
            log.debug("{}.{} executed with queries: \n{}", className, methodName, logs);  
        }  
        return result;  
    }  
}

해당 부분에서 나는 AOP를 사용했다.
Interceptor 나 Filter 보다 더 사용하기 용이해서인데, 어차피 운영 서버내 동작 X + 로깅용 이기에 부담없이 수용하기로 결정했다.
만약, 임계치를 넘었다면 WARN 으로, 아니라면 DEBUG 로 로깅한다.

package corea.global.config;  
  
import corea.global.aspect.query.QueryInspector;  
import lombok.RequiredArgsConstructor;  
import org.hibernate.cfg.AvailableSettings;  
import org.springframework.boot.autoconfigure.orm.jpa.HibernatePropertiesCustomizer;  
import org.springframework.context.annotation.Bean;  
import org.springframework.context.annotation.Configuration;  
  
@Configuration  
@RequiredArgsConstructor  
public class HibernateConfig {  
  
    private final QueryInspector queryInspector;  
  
    @Bean  
    public HibernatePropertiesCustomizer hibernatePropertyConfig() {  
        return hibernateProperties ->  
                hibernateProperties.put(AvailableSettings.STATEMENT_INSPECTOR, queryInspector);  
    }  
}

그후, hibernateProperties 에 넣기만 하면 끝이다.
이때, 어떻게 타입이 추론되고, 저 안에 넣는거지? 라고 생각할 수 있는데 매우 간단하다.

@FunctionalInterface  
public interface HibernatePropertiesCustomizer {  
    void customize(Map<String, Object> hibernateProperties);  
}

프로퍼티 커스터마이저를 함수형 인터페이스로 제공하기 때문이다.
StatementInspector 설정에 넣으면 끝!

여러개의 Inspector 라면?
QueryInspector 내부에 여러개의 StatementInspector 를 담아서 그 여러개를 포함하는 QueryInspector 를 포함시키자.

매우 간단하다.

<springProfile name="inspect">  
    <include resource="logs/file-inspect-appender.xml"/>  
  
    <logger name="corea.global.aspect" level="DEBUG" additivity="false">  
        <appender-ref ref="FILE-INSPECT"/>  
    </logger>  
  
    <logger name="org.springframework" level="WARN"/>  
</springProfile>
<included>  
    <appender class="ch.qos.logback.core.FileAppender" name="FILE-INSPECT">  
        <encoder>  
            <pattern>${INSPECT_PATTERN}</pattern>  
        </encoder>  
        <file>inspect.log</file>  
        <append>false</append>  
    </appender>  
</included>

이떄, 로깅 레벨은 hibernate 와 따로 논다. 주의하자!


쿼리 검사 결과기

어느정도, 유의미하게 쿼리 검사에 대해서 그리고, 공유가 가능해져서 설명한다.
기존 ControllerExecutor 와 동일하므로, 그 전의 설명은 생략한다.

String[] allBeanNames = applicationContext.getBeanDefinitionNames();  
  
for (String beanName : allBeanNames) {  
    Object bean = applicationContext.getBean(beanName);  
    Class<?> beanClass = AopProxyUtils.ultimateTargetClass(bean);  
  
    if (beanClass.isAnnotationPresent(RestController.class) || beanClass.isAnnotationPresent(Controller.class)) {  
        controllerExecutor.executeAllMethod(bean);  
    }  
}

이렇게, 모든 컨트롤러를 가져와서 실행하면?

500

로그에 값을 저장시킨다.

그 후, 로그에서 값을 추출해서 html 파일로 변환한다.
변환 코드는 GPT 의 도움을 받아 파이선으로 만들었다.
코드 링크-gist

너무 코드 라인이 길어서 GIST 로 대체한다.. 🥲

450

결과들을 가져와서

  • 각 DML 들이 몇개 발생했는지
  • 총 몇개 발생했느지
  • 임계치를 넘은 메소드 비율

메소드 명을 클릭 시

  • 어떤 값과 함께 실행이 되었는지
  • 어떤 쿼리가 발생했는지
  • 에러가 발생했는지

명세와 일치하지 않은 메소드는

  • 어떤 값과 함께 했는지
  • 어떤 에러가 발생 했는지

를 드러낸다. ( 405 Not Allowed 는 왜 저러는지 모르겠다... )

디자인은 당연히, 크게 신경 안쓰고
전 글에서도 말했듯 완벽한 컨텍스트, 완벽한 문서화라면 큰 효율을 보일 것이라고 생각한다.
하지만, 이건 당연히 팀원들과 협의와 얘기를 한 후 해나가야 할 부분이다. 🙂🙂

도입이 된다면, 관련 이슈+PR, 링크를 추가하겠다.

4개의 댓글

comment-user-thumbnail
2024년 8월 21일

매우 간단하다고 하셨는데 전혀 모르겠어요.
너무 어려워요.
ㅠㅠ.

1개의 답글
comment-user-thumbnail
2024년 8월 24일

micrometer + prometheus 쓰면 카운트랑 쿼리 속도는 볼 수 있더라,, aop 넘나 어려운것

1개의 답글