(in 연산 → join) 및 커스텀 NativeQuery (24.06.14)

현재

현재 사용하고 있는 IN 연산 최적화에 대한 접근 방식은 다음과 같다

1. 시간 단위로 파티셔닝을 통해 필요한 데이터의 범위를 줄인 후,

(where created_at between (a, b) .. create_at을 기준으로 파티셔닝)

1. IN 연산을 사용하여 특정 조건의 값들을 필터링하고 있음.

이 과정에서 IN SET의 경우 SET<Long>을 사용하며, 최대 배치 사이즈 = 5000으로 실시한 뒤 스플릿하여 IO를 여러 번 보내고 있음.

//조회 로직 중 일부

 public List<SpanDto> getSpansUseTraceIdSet(List<UUID> inputTraceIdSet, Long minTime, Long maxTime ) {
        try {
            Timestamp createdAtMin = new Timestamp(minTime / 1_000_000);
            Timestamp createdAtMax = new Timestamp(maxTime / 1_000_000);
            List<SpanDto> result = new ArrayList<>();
            List<Set<UUID>> traceIdSets = sliceSet(inputTraceIdSet);
            
            for (Set<UUID> traceIdSet : traceIdSets) {
                result.addAll(
                        jpaQueryFactory.select(Projections.constructor(SpanDto.class,
                                        qSpan.id,
                                        qSpan.scopeName,
                                        qSpan.traceId,
                                        qSpan.spanId,
                                        qSpan.parentSpanId,
                                        qSpan.flag,
                                        qSpan.name,
                                        qSpan.kind,
                                        qSpan.startTimeUnixNano,
                                        qSpan.endTimeUnixNano,
                                        qSpan.statusIsError,
                                        qSpan.attributes,
                                        qSpan.hasEvent
                                ))
                                .from(qSpan)
                                .where(qSpan.createdAt.between(createdAtMin, createdAtMax) //파티션 분할 먼저 조회
                                .and(qSpan.traceId.in(traceIdSet)))
                                .fetch()
                );
            }

            return result;
        } catch (Exception e) {
            ErrorLogger.log(this.getClass().getName(), "getSpansUseTraceIdSet");
            throw e;
        }
        
        
            //Set을 Batch 크기에 맞는 List로 잘라 할당하기
    private static <T> List<Set<T>> sliceSet(List<T> originalSet) {
        List<Set<T>> slicedSets = new ArrayList<>();
        Iterator<T> iterator = originalSet.iterator();

        while (iterator.hasNext()) {
            Set<T> batch = new HashSet<>();
            for (int i = 0; i < BATCH_SIZE && iterator.hasNext(); i++) {
                batch.add(iterator.next());
            }
            slicedSets.add(batch);
        }
        return slicedSets;
    }

(테스트 중 가장 나은 퍼포먼스를 낸 기록. 일반적으로 1000ms 이상 지연이 발생한다)

기본적으로 컬럼의 개수가 상당히 많고, 단순 조회가 아닌 내부적으로 복잡한 매핑 연산을 사용하기에, 성능이 많이 떨어지는 상황이다.

대략적으로 1~3만개의 쿼리를 3개의 테이블에서 가져와서 스트림으로 매핑하여 제공하는데 1-2초 내외의 시간이 걸린다. 현실적으로 서비스로 제공하기 어려운 시간이다.

현재 사용 중인 IN 연산은 다음과 같은 방식으로 동작한다

1. traceIdSet에 있는 값을 기반으로 traceId가 일치하는 행을 필터링한다.
2. 큰 traceIdSet을 여러 개의 작은 배치로 나누어 각각 쿼리를 수행한다.

이 방식은 간단하고 직관적이지만, traceIdSet의 크기가 클 경우 성능에 영향을 미칠 수 있다.

이유는 각 쿼리마다 IN 연산을 수행하기 위해 많은 값을 비교해야 하기 때문이다.

특히 현재 BATCH_SIZE 를 5000개~ 정도로 잡고 있는데, 내부 파라미터가 늘어날 수록 성능이 유의미하게 떨어지는 것을 확인할 수 있었다.

이를 극복하기 위해 다른 방식의 쿼리를 사용해보았다.

1. IN 대신 JOIN 사용

IN 연산은 많은 값을 처리할 때 성능이 떨어질 수 있다. 조인을 사용하여 대규모 데이터 집합을 처리할 때 임시 테이블을 활용하는 것은 매우 유용할 수 있다. 임시 테이블을 사용하면 많은 수의 ID를 효율적으로 처리할 수 있으며, 데이터베이스의 조인 최적화 기능을 활용할 수 있다.

다음과 같은 방식으로 변경할 수 있다.

1. inputTraceIdSet을 임시 테이블로 만든다.
2. JOIN을 사용하여 traceId가 일치하는 행을 필터링한다.

임시 테이블용 QClass

import com.querydsl.core.types.PathMetadata;
import com.querydsl.core.types.PathMetadataFactory;
import com.querydsl.core.types.dsl.EntityPathBase;
import com.querydsl.core.types.dsl.PathBuilder;
import com.querydsl.core.types.dsl.SimplePath;

import java.util.UUID;

/**
 * Trace ID 임시 테이블 선언용
 * 임시 테이블을 다루기 위해 임시적으로 Q 클래스를 수동으로 정의
 */
public class QTempTraceIds extends EntityPathBase<UUID> {

    private static final long serialVersionUID = 1L;

    public static final QTempTraceIds tempTraceIds = new QTempTraceIds("temp_trace_ids");

    public final SimplePath<UUID> traceId = createSimple("trace_id", UUID.class);

    public QTempTraceIds(String variable) {
        super(UUID.class, PathMetadataFactory.forVariable(variable));
    }

    public QTempTraceIds(PathMetadata metadata) {
        super(UUID.class, metadata);
    }

    public QTempTraceIds(PathBuilder<?> entity) {
        super(UUID.class, entity.getMetadata());
    }
}

네이티브 쿼리 적용하기

   @Override
    public List<SpanDto> getSpansUseTraceIdSet(List<UUID> inputTraceIdSet, Long minTime, Long maxTime ) {
        try {
            Timestamp createdAtMin = new Timestamp(minTime / 1_000_000);
            Timestamp createdAtMax = new Timestamp(maxTime / 1_000_000);
            List<SpanDto> result = new ArrayList<>();

            //List<UUID>를 가지는 임시 테이블 생성
            entityManager.createNativeQuery("CREATE TEMPORARY TABLE temp_trace_ids (trace_id UUID)").executeUpdate();
            traceUtil.batchInsertTraceIds(inputTraceIdSet); // 임시 테이블에 데이터 배치 삽입

            //임시 테이블 Set을 기반으로 JOIN 실행
            result.addAll(
                    jpaQueryFactory.select(Projections.constructor(SpanDto.class,
                                    qSpan.id,
                                    qSpan.scopeName,
                                    qSpan.traceId,
                                    qSpan.spanId,
                                    qSpan.parentSpanId,
                                    qSpan.flag,
                                    qSpan.name,
                                    qSpan.kind,
                                    qSpan.startTimeUnixNano,
                                    qSpan.endTimeUnixNano,
                                    qSpan.statusIsError,
                                    qSpan.attributes,
                                    qSpan.hasEvent
                            ))
                            .from(qSpan)
                            .where(qSpan.createdAt.between(createdAtMin, createdAtMax)) //원본 데이터 파티셔닝 기반으로 가져오기
                            .join(tempTraceIds) //파티셔닝된 값 x 임시 테이블 조인 (모수가 훨씬 적음)
                            .on(qTrace.spanTraceId.eq(tempTraceIds.traceId))
                            .fetch()
            );

            return result;
        } catch (Exception e) {
            ErrorLogger.log(this.getClass().getName(), "getSpansUseTraceIdSet");
            throw e;
        } finally {
            //모든 작업이 끝난 후 임시 테이블을 삭제하여 메모리에서 해제
            entityManager.createNativeQuery("DROP TABLE temp_trace_ids").executeUpdate();
        }

그런데, 위의 쿼리는 로직상 적용되지 않았다.

QueryDSL 및 JPA에서 지원하지 않기 때문이다.. 따라서 네이티브 쿼리로 변경해야 했다.

https://shanepark.tistory.com/393 (만일 객체가 간단하다면 이 방법을 사용하자.)

이 와중에 JDBC 방언 문제(1111)도 발생했다.

이를 매핑하기 위해 Entity 자체를 변경해주어야 한다.

@Entity
@Getter
@Table(name = "tbl_apm_trace_span")
@TypeDef(name = "jsonb", typeClass = JsonbType.class)
@TypeDef(name = "bytearray", typeClass = ByteArrayType.class)
@TypeDef(name = "uuid", typeClass = UUIDType.class)
@SqlResultSetMapping( //JPA에서 네이티브 쿼리의 결과를 엔티티 또는 DTO로 매핑하기 위해 사용하는 어노테이션.
        name = "SpanMapping", //매핑 이름 정의
        entities = @EntityResult(
                entityClass = Span.class,
                fields = {
                        @FieldResult(name = "id", column = "id"),
                        @FieldResult(name = "scopeName", column = "scope_name"),
                        @FieldResult(name = "traceId", column = "trace_id"),
                        @FieldResult(name = "spanId", column = "span_id"),
                        @FieldResult(name = "parentSpanId", column = "parent_span_id"),
                        @FieldResult(name = "flag", column = "flag"),
                        @FieldResult(name = "name", column = "name"),
                        @FieldResult(name = "kind", column = "kind"),
                        @FieldResult(name = "startTimeUnixNano", column = "start_time_unix_nano"),
                        @FieldResult(name = "endTimeUnixNano", column = "end_time_unix_nano"),
                        @FieldResult(name = "statusIsError", column = "status_is_error"),
                        @FieldResult(name = "attributes", column = "attributes"),
                        @FieldResult(name = "hasEvent", column = "has_event"),
                        @FieldResult(name = "createdAt", column = "created_at")
                }
        )
)
public class Span {
    @Id
    @GeneratedValue(strategy = GenerationType.IDENTITY)
    private long id;

    private String scopeName;

//기본 JPA에서 제공하지 않는 타입은 TypeDef를 통해 어떻게 변환할 지 알려주어야 한다.
//여기서 다룰 내용은 아닌 것 같아 생략한다. (UserType Override 사용하면 된다.)
    @Type(type = "uuid") 
    private UUID traceId;

    @Type(type = "bytearray")
    private byte[] spanId;

    @Type(type = "bytearray")
    private byte[] parentSpanId;

    private int flag;

    private String name;

    private int kind;

    private long startTimeUnixNano;

    private long endTimeUnixNano;

    private boolean statusIsError;

    @Type(type = "jsonb")
    private JsonNode attributes;

    private boolean hasEvent;

    private Timestamp createdAt;
}

//네이티브 쿼리
    @Override
    public List<SpanDto> getSpansUseTraceIdSet(List<UUID> inputTraceIdSet, Long minTime, Long maxTime) {
        try {
            Timestamp createdAtMin = new Timestamp(minTime / 1_000_000);
            Timestamp createdAtMax = new Timestamp(maxTime / 1_000_000);
            List<SpanDto> result = new ArrayList<>();

            //List<UUID>를 가지는 임시 테이블 생성
            entityManager.createNativeQuery("CREATE TEMPORARY TABLE temp_trace_ids (trace_id UUID)").executeUpdate();
            traceUtil.batchInsertTraceIds(inputTraceIdSet); // 임시 테이블에 데이터 배치 삽입

            // 2. 네이티브 쿼리로 조인 실행
            // JPA 설계 원칙 상 임시 테이블을 사용한 조인을 JPA나 QueryDSL에서 직접적으로 지원하지 않는다.. (객체지향 접근성 위반)
            String nativeQuery = "SELECT span.id, span.scope_name, span.trace_id, span.span_id, span.parent_span_id, span.flag, span.name, span.kind, span.start_time_unix_nano, span.end_time_unix_nano, span.status_is_error, span.attributes, span.has_event " +
                    "FROM span " +
                    "JOIN temp_trace_ids ON span.trace_id = temp_trace_ids.trace_ide_id " +
                    "WHERE span.created_at BETWEEN :createdAtMin AND :createdAtMax";

            List<Span> spans = entityManager.createNativeQuery(nativeQuery)
                    .setParameter("createdAtMin", createdAtMin)
                    .setParameter("createdAtMax", createdAtMax)
                    .getResultList();

            // Span 엔티티 리스트를 SpanDto 리스트로 변환
            return spans.stream()
                    .map(SpanDto::new) // Span 엔티티를 SpanDto로 변환
                    .collect(Collectors.toList());
        } catch (Exception e) {
            ErrorLogger.log(this.getClass().getName(), "getSpansUseTraceIdSet");
            throw e;
        } finally {
            //모든 작업이 끝난 후 임시 테이블을 삭제하여 메모리에서 해제
            entityManager.createNativeQuery("DROP TABLE temp_trace_ids").executeUpdate();
        }

/**
 * Trace 레이어 비즈니스 로직 연산 시 공통적으로 사용하는 유틸 클래스
 */
@Component
@RequiredArgsConstructor
public class TraceUtil {

    @PersistenceContext
    private final EntityManager entityManager;

    /**
     *     Set을 Batch 크기에 맞는 List로 잘라 할당하기
     *     In 연산에서 사용
     */
    public static <T> List<Set<T>> sliceSet(List<T> originalSet) {
        List<Set<T>> slicedSets = new ArrayList<>();
        Iterator<T> iterator = originalSet.iterator();

        while (iterator.hasNext()) {
            Set<T> batch = new HashSet<>();
            for (int i = 0; i < BATCH_SIZE && iterator.hasNext(); i++) {
                batch.add(iterator.next());
            }
            slicedSets.add(batch);
        }
        return slicedSets;
    }

    /**
     * Batch Size만큼 traceIds를 임시 테이블에 저장
     */
    public void batchInsertTraceIds(List<UUID> traceIds) {
        try {
            int batchSize = BATCH_SIZE;
            int totalSize = traceIds.size();
            for (int i = 0; i < totalSize; i += batchSize) {
                int endIndex = Math.min(i + batchSize, totalSize);
                List<UUID> batchList = traceIds.subList(i, endIndex);
                insertBatch(batchList);
            }
        } catch (Exception e) {
            ErrorLogger.log(this.getClass().getName(), "batchInsertTraceIds");
            throw e;
        }
    }

    private void insertBatch(List<UUID> batchList) {
        StringBuilder sql = new StringBuilder("INSERT INTO temp_trace_ids (trace_id) VALUES ");
        for (int i = 0; i < batchList.size(); i++) {
            sql.append("(:traceId").append(i).append("),");
        }
        sql.deleteCharAt(sql.length() - 1); // 마지막 쉼표 제거

        Query query = entityManager.createNativeQuery(sql.toString());
        for (int i = 0; i < batchList.size(); i++) {
            query.setParameter("traceId" + i, batchList.get(i));
        }
        query.executeUpdate();
    }

}

발생한 중간 이슈 : 이론과 정 반대의 결과.. 더 느려졌다.

놀랍게도, 동일한 쿼리 기준 5초 이상 (기존은 1초 내외..)이 걸리는 절망적인 사태가 발생했다.

이것의 이유는 임시 테이블을 만드는 과정에서 Insert가 효율적이지 않아 이 과정에서 오버헤드가 상당히 많이 발생했기 때문이다.

이를 최적화하기 위해 위 테이블의 batchInsertTraceIds를 기본 JDBC 구현체를 사용하여 Batch 처리해보자.

    /**
     * Batch Size만큼 traceIds를 임시 테이블에 저장, 기본 JDBC Batch 사용
     */
    public void batchInsertTraceIds(List<UUID> traceIds) throws SQLException {
        String sql = "INSERT INTO temp_trace_ids (trace_id) VALUES (?)";
        try (Connection connection = dataSource.getConnection();
             PreparedStatement ps = connection.prepareStatement(sql)) {
            connection.setAutoCommit(false);

            int batchSize = BATCH_SIZE;
            int count = 0;

            for (UUID traceId : traceIds) {
                ps.setObject(1, traceId);
                ps.addBatch();

                if (++count % batchSize == 0) {
                    ps.executeBatch();
                }
            }
            ps.executeBatch(); // 남은 배치 실행
            connection.commit();
        } catch (Exception e) {
            ErrorLogger.log(this.getClass().getName(), "batchInsertTraceIds");
            throw e;
        }
    }

기존 방법은 entityManager를 통해 네이티브 쿼리를 생성하고 실행했다.

이는 각 파라미터 설정 시 entityManager를 통해 처리되므로 추가적인 오버헤드가 많이 발생했다.

지금의 방법은 기본적인 JDBC Batch를 사용하여 성능을 최대한 끌어올린 것이다.

최종 결과

//1. 파티션 테이블 IN 사용 로직 : 10000개를 넘는 순간 많은 시간 Loss가 발생한다.
{
  "SIZE": 1013,
  "TIME USED(ms)": 31
}

{
  "SIZE": 10068,
  "TIME USED(ms)": 431
}

{
  "SIZE": 101423,
  "TIME USED(ms)": 4279
}

{
  "SIZE": 352489,
  "TIME USED(ms)": 43912 //기간 최대 조회 : 43초
}

//2. 임시 테이블 x 파티션 테이블 JOIN 사용 로직
{
  "SIZE": 1009,
  "TIME USED(ms)": 19
}

{
  "SIZE": 10089,
  "TIME USED(ms)": 48
}

{
  "SIZE": 101410, //기술적 목표치 : 300ms 내에서 안정적 제공 가능
  "TIME USED(ms)": 309 
}

{
  "SIZE": 353540,
  "TIME USED(ms)": 1128
}

//번외 : 다른 로직(Trace) 역시 임시 테이블을 수행하여 최대로 최적화했을 경우

동일 비즈니스 로직에서 ‘Span’의 조회 부분만 변경했을 시 걸리는 시간.

temp 테이블 생성 오버헤드 + (임시 테이블 생성 x 파티셔닝된 데이터 모수 Join)의 결과가 기존 (파티셔닝 테이블 조회 In (조건)) 보다 대략 8배 이상 효율적인 것이다.

결론

성능 차이와 개념적 이해

1. IN 연산
   • 많은 값을 비교할 때 성능이 저하될 수 있다.
   • 데이터베이스가 각 값을 순차적으로 비교하여 필터링하기 때문에 시간이 많이 걸릴 수 있다.
2. JOIN 연산
   • 임시 테이블을 사용하여 대량의 값을 저장하고, JOIN을 통해 결합한다.
   • 데이터베이스는 JOIN을 최적화할 수 있는 다양한 전략을 가지고 있어, 일반적으로 대량의 데이터를 처리할 때 더 효율적이다.
   • 데이터베이스의 인덱스를 잘 활용할 수 있다.
3. EXISTS 연산
   • 서브쿼리를 통해 조건에 맞는 행이 존재하는지 확인한다.
   • EXISTS는 서브쿼리가 참일 경우 즉시 반환하기 때문에 많은 경우에 효율적이다.
   • 하지만 서브쿼리를 반복적으로 수행하므로, 경우에 따라 성능이 저하될 수 있다.

0617

/**
 * Trace 레이어 비즈니스 로직 연산 시 공통적으로 사용하는 유틸 클래스
 */
@Component
@RequiredArgsConstructor
public class TraceUtil {

    private final ObjectMapper objectMapper = new ObjectMapper();
    private final DataSource dataSource;

    /**
     * Set을 Batch 크기에 맞는 List로 잘라 할당하기
     * In 연산에서 사용
     */
    public <T> List<Set<T>> sliceSet(List<T> originalSet) {
        List<Set<T>> slicedSets = new ArrayList<>();
        Iterator<T> iterator = originalSet.iterator();

        while (iterator.hasNext()) {
            Set<T> batch = new HashSet<>();
            for (int i = 0; i < BATCH_SIZE && iterator.hasNext(); i++) {
                batch.add(iterator.next());
            }
            slicedSets.add(batch);
        }
        return slicedSets;
    }

    public <T> List<Set<T>> sliceSet(Set<T> originalSet) {
        List<Set<T>> slicedSets = new ArrayList<>();
        Iterator<T> iterator = originalSet.iterator();

        while (iterator.hasNext()) {
            Set<T> batch = new HashSet<>();
            for (int i = 0; i < BATCH_SIZE && iterator.hasNext(); i++) {
                batch.add(iterator.next());
            }
            slicedSets.add(batch);
        }

        return slicedSets;
    }

    /**
     * 임시 테이블 사용하여 새롭게 생성 후 데이터 삽입
     * Connection 및 기본 JDBC 구현체 사용 (EM의 경우 성능 이슈 발생)
     * @param traceIds
     * @return
     * @throws SQLException
     */

    public <T> List<T> batchInsertTraceIds(List<UUID> traceIds, Timestamp createdAtMin, Timestamp createdAtMax, int type) throws SQLException, IOException {
        long startTime = System.currentTimeMillis();//log
        final String createTableSQL = "CREATE TEMPORARY TABLE IF NOT EXISTS temp_trace_ids (trace_id UUID)";
        final String insertSQL = "INSERT INTO temp_trace_ids (trace_id) VALUES (?)"; //임시 테이블
        final String createIndexSQL = "CREATE INDEX idx_trace_id ON temp_trace_ids(trace_id)"; //임시 테이블 인덱스
        List<T> result = new ArrayList<>(); //결과값
        try (Connection connection = dataSource.getConnection();
             PreparedStatement createTableStmt = connection.prepareStatement(createTableSQL);
             PreparedStatement createIndexStmt = connection.prepareStatement(createIndexSQL);
             PreparedStatement insertStmt = connection.prepareStatement(insertSQL);
             PreparedStatement queryStmt = connection.prepareStatement(joinTempTableQuery[type])) {

            connection.setAutoCommit(false);

            long createTableStart = System.currentTimeMillis(); //log
            createTableStmt.executeUpdate(); // 임시 테이블 생성
            long createTableEnd = System.currentTimeMillis(); //log
            System.out.println("임시 테이블 생성 시간: " + (createTableEnd - createTableStart) + "ms");

            //인덱스
            long createIndexStart = System.currentTimeMillis(); //log
            createIndexStmt.executeUpdate(); // 인덱스 생성
            long createIndexEnd = System.currentTimeMillis(); //log
            System.out.println("인덱스 생성 시간: " + (createIndexEnd - createIndexStart) + "ms");

            // 데이터 삽입 후 Commit 시행
            long insertStart = System.currentTimeMillis(); //log
            for (UUID traceId : traceIds) {
                insertStmt.setObject(1, traceId);
                insertStmt.addBatch();
            }
            insertStmt.executeBatch();

            long insertEnd = System.currentTimeMillis(); //log
            System.out.println("데이터 삽입 시간: " + (insertEnd - insertStart) + "ms");

            // 네이티브 쿼리로 조인 실행
            long queryStart = System.currentTimeMillis();//log
            queryStmt.setTimestamp(1, createdAtMin);
            queryStmt.setTimestamp(2, createdAtMax);
            try (ResultSet rs = queryStmt.executeQuery()) {
                System.out.println("데이터 조회 시간 : " + (System.currentTimeMillis() - queryStart));
                while (rs.next()) {
                    switch (type) {
                        case 0 : {
                            result.add((T) spanDtoMapper(rs));
                            break;
                        }
                        case 1 : {
                            result.add((T) traceDtoMapper(rs));
                            break;
                        }
                        default: {
                            ErrorLogger.log(this.getClass().getName(), "Native Query 시행 시 Type Input Param 유효하지 않음");
                        }
                    }
                }
            }
            long queryEnd = System.currentTimeMillis(); //log
            System.out.println("데이터 조회 및 매핑 시간: " + (queryEnd - queryStart) + "ms");
        } catch (Exception e) {
            ErrorLogger.log(this.getClass().getName(), "batchInsertTraceIds");
            throw e;
        }
        long endTime = System.currentTimeMillis();
        System.out.println("총 처리 시간: " + (endTime - startTime) + "ms");

        return result;

    }

    /**
     * 모듈화 위한 네이티브 쿼리 모음
     */
    private final String[] joinTempTableQuery = {
            // 0 : SpanDto
            "SELECT s.id, s.scope_name, cast(s.trace_id as varchar), s.span_id, s.parent_span_id, s.flag, s.name, " +
                    "s.kind, s.start_time_unix_nano, s.end_time_unix_nano, s.status_is_error, s.attributes, s.has_event " +
                    "FROM tbl_apm_trace_span s " +
                    "JOIN temp_trace_ids t ON s.trace_id = t.trace_id " +
                    "WHERE s.created_at BETWEEN ? AND ?",

            // 1 : TraceDto
            "SELECT tr.id, tr.agent_id, tr.span_trace_id, tr.span_start_time_unix_nano, tr.span_end_time_unix_nano," +
                    "tr.is_err, tr.resource_id, tr.created_at " +
                    "FROM tbl_apm_trace tr " +
                    "JOIN temp_trace_ids te ON tr.span_trace_id = te.trace_id " +
                    "WHERE tr.created_at BETWEEN :createdAtMin AND :createdAtMax"

            // for more ..
    };

    /**
     * ResultSet SpanDto Mapper
     */
    private SpanDto spanDtoMapper(ResultSet rs) throws SQLException, IOException {
        return new SpanDto(
                rs.getLong("id"),
                rs.getString("scope_name"),
                UUID.fromString(rs.getString("trace_id")),
                rs.getBytes("span_id"),
                rs.getBytes("parent_span_id"),
                rs.getInt("flag"),
                rs.getString("name"),
                rs.getInt("kind"),
                rs.getLong("start_time_unix_nano"),
                rs.getLong("end_time_unix_nano"),
                rs.getBoolean("status_is_error"),
                objectMapper.readTree(rs.getString("attributes")),
                rs.getBoolean("has_event")
                // rs.getTimestamp("created_at")
        );
    }

    /**
     * ResultMap TraceDto Mapper
     */
    private TraceDto traceDtoMapper(ResultSet rs) throws SQLException {
        return new TraceDto(
                rs.getLong("id"),
                UUID.fromString(rs.getString("span_trace_id")),
                rs.getLong("span_start_time_unix_nano"),
                rs.getLong("span_end_time_unix_nano"),
                rs.getBoolean("status_is_error"),
                rs.getLong("agent_id"),
                rs.getLong("resource_id")

        );
    }

}

1440분 = 하루 조회의 경우, 전체 출력 시 대략 100~400MB 용량의 json 크기이다.

: 현 상황에서 DB CP가 부족하기에, 매 IO 요청마다 200~300ms 정도 로스가 발생하는 상황이다.

분석 결과

타임스탬프: 1718596751478900325, 1718600345714547837
2024-06-17 12:52:54.192
2024-06-17 13:52:45.935
2024-06-17 14:45:25.961 DEBUG 1732 --- [nio-8089-exec-5] org.hibernate.SQL: 
    select id, scope_name, trace_id, span_id, parent_span_id, flag, name, kind, start_time_unix_nano, end_time_unix_nano, status_is_error, attributes, has_event 
    from tbl_apm_trace_span 
    where created_at between ?1 and ?2
2024-06-17 14:45:25.963 TRACE 1732 --- [nio-8089-exec-5] o.h.type.descriptor.sql.BasicBinder: binding parameter [1] as [TIMESTAMP] - [2024-06-17 12:52:54.192]
2024-06-17 14:45:25.963 TRACE 1732 --- [nio-8089-exec-5] o.h.type.descriptor.sql.BasicBinder: binding parameter [2] as [TIMESTAMP] - [2024-06-17 13:52:45.935]
걸린 시간: 511ms
2024-06-17 14:45:26.472 INFO 1732 --- [nio-8089-exec-5] i.StatisticalLoggingSessionEventListener: Session Metrics {
    889000 nanoseconds spent acquiring 1 JDBC connections;
    0 nanoseconds spent releasing 0 JDBC connections;
    945800 nanoseconds spent preparing 1 JDBC statements;
    244547200 nanoseconds spent executing 1 JDBC statements;
    0 nanoseconds spent executing 0 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections);
    0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections)
}

Spring 애플리케이션

• 총 시간: 511ms
• JDBC 커넥션 획득 시간: 0.89ms
• JDBC 스테이트먼트 준비 시간: 0.94ms
• JDBC 스테이트먼트 실행 시간: 244.55ms
• 기타 작업 시간: 264.62ms

EXPLAIN ANALYZE

• 총 실행 시간: 27.770ms
  • Index Scan 및 Seq Scan 시간: 26.869ms
  • 계획 수립 시간: 0.238ms

네트워크, DB IO 등 바꿀 수 없는 부분

네트워크 지연과 데이터베이스 I/O는 애플리케이션 레벨에서 변경하기 어렵다.

네트워크 지연 (Network Latency)

• 설명: Spring 애플리케이션이 데이터베이스와 통신하는 동안 발생하는 네트워크 왕복 시간.
• 로그: JDBC 커넥션 획득 및 준비에 소요된 시간 (약 1.83ms, 즉 0.89ms + 0.94ms).

데이터베이스 I/O (DB I/O)

• 설명: 데이터베이스가 쿼리를 실행하고 결과를 반환하는 시간.
• 로그: JDBC 스테이트먼트 실행 시간 (244.55ms).

가상 테이블 조회 5초~6초

where trace.spanStartTimeUnixNano between ?1 and ?2 and trace.agentId = ?3 */ select trace0_.id as col_0_0_, trace0_.span_trace_id as col_1_0_, trace0_.span_start_time_unix_nano as col_2_0_, trace0_.span_end_time_unix_nano as col_3_0_, trace0_.is_err as col_4_0_, trace0_.agent_id as col_5_0_, trace0_.resource_id as col_6_0_ from tbl_apm_trace trace0_ where (trace0_.span_start_time_unix_nano between ? and ?) and trace0_.agent_id=?
2024-06-17 15:45:04.008 TRACE 13768 --- [nio-8089-exec-8] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [BIGINT] - [1718520304008000000]
2024-06-17 15:45:04.008 TRACE 13768 --- [nio-8089-exec-8] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [BIGINT] - [1718606704008000000]
2024-06-17 15:45:04.008 TRACE 13768 --- [nio-8089-exec-8] o.h.type.descriptor.sql.BasicBinder      : binding parameter [3] as [BIGINT] - [217]
사이즈 : 86336
타임스탬프 : 1718520305000000000 , 1718606701000000000
2024-06-16 15:45:05.0
2024-06-17 15:45:01.0
시작
임시 테이블 생성 시간: 14ms
인덱스 생성 시간: 1ms
데이터 삽입 시간: 1566ms
데이터 조회 시간 : 2655
데이터 조회 및 매핑 시간: 3935ms
총 처리 시간: 5581ms
걸린 시간 : 5581
2024-06-17 15:45:10.194  INFO 13768 --- [nio-8089-exec-8] i.StatisticalLoggingSessionEventListener : Session Metrics {
    987500 nanoseconds spent acquiring 1 JDBC connections;
    0 nanoseconds spent releasing 0 JDBC connections;
    29200 nanoseconds spent preparing 1 JDBC statements;
    111419400 nanoseconds spent executing 1 JDBC statements;
    0 nanoseconds spent executing 0 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections);
    4400 nanoseconds spent executing 1 partial-flushes (flushing a total of 0 entities and 0 collections)
}

---

사이즈 : 86338
타임스탬프 : 1718520353000000000 , 1718606751001000000
2024-06-16 15:45:53.0
2024-06-17 15:45:51.001
시작
임시 테이블 생성 시간: 3ms
인덱스 생성 시간: 0ms
데이터 삽입 시간: 1546ms
데이터 조회 시간 : 2981
데이터 조회 및 매핑 시간: 4567ms
총 처리 시간: 6185ms
걸린 시간 : 6185
2024-06-17 15:45:59.382  INFO 16460 --- [nio-8089-exec-2] i.StatisticalLoggingSessionEventListener : Session Metrics {
    1116200 nanoseconds spent acquiring 1 JDBC connections;
    0 nanoseconds spent releasing 0 JDBC connections;
    1644100 nanoseconds spent preparing 1 JDBC statements;
    150084300 nanoseconds spent executing 1 JDBC statements;
    0 nanoseconds spent executing 0 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections);
    22500 nanoseconds spent executing 1 partial-flushes (flushing a total of 0 entities and 0 collections)
}

IN 요청

    @Override
    @Transactional(propagation = Propagation.REQUIRED)
    public List<SpanDto> getSpansUseTraceIdSet(List<UUID> inputTraceIdSet, Long minTime, Long maxTime) {
        List<SpanDto> result = new ArrayList<>();
        Timestamp createdAtMin = new Timestamp(minTime / 1_000_000);
        Timestamp createdAtMax = new Timestamp(maxTime / 1_000_000);
        System.out.println("타임스탬프 : " + minTime + " , " + maxTime);
        System.out.println(createdAtMin);
        System.out.println(createdAtMax);
        System.out.println("시작");
        long now = System.currentTimeMillis();
        try {
//            traceUtil.batchInsertTraceIds(inputTraceIdSet, createdAtMin, createdAtMax, 0);
            //List<UUID>를 가지는 임시 테이블 생성

            List<Set<UUID>> traceIdSet =  traceUtil.sliceSet(inputTraceIdSet);
            for (Set<UUID> traceIds : traceIdSet) {
                result.addAll(jpaQueryFactory.select(
                        Projections.constructor(SpanDto.class,
                                        qSpan.id,
                                        qSpan.scopeName,
                                        qSpan.traceId,
                                        qSpan.spanId,
                                        qSpan.parentSpanId,
                                        qSpan.flag,
                                        qSpan.name,
                                        qSpan.kind,
                                        qSpan.startTimeUnixNano,
                                        qSpan.endTimeUnixNano,
                                        qSpan.statusIsError,
                                        qSpan.attributes,
                                        qSpan.hasEvent
                        )).from(qSpan)
                        .where(qSpan.createdAt.between(createdAtMin, createdAtMax).and(qSpan.traceId.in(traceIds)))
                        .fetch()
                );
            }

        } catch (Exception e) {
            ErrorLogger.log(this.getClass().getName(), "getSpansUseTraceIdSet", e);
        }

        System.out.println("걸린 시간 : " + (System.currentTimeMillis() - now));
        return result;
    }

BATCH SIZE : 2000 정도로 두고 요청을 보내는데, 조회가 10만건++ 정도가 되다 보니, 기본적으로 하나의 요청에 수십 개의 CP를 먹는 것 같다. (Wait으로 인해 사실상 로직이 사용 불가능 수준이다. DB에 이 서버만 연결된 것이 아니다보니.. )

전체 수를 줄여 144분( 비교 대상의 1/5)로 조회해보자. 사실 로직 상 모수가 작을 수록 매핑 속도가 훨씬 더 빠르다.

2024-06-17 15:51:03.469 TRACE 7728 --- [nio-8089-exec-2] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [TIMESTAMP] - [2024-06-17 11:03:02.0]
2024-06-17 15:51:03.469 TRACE 7728 --- [nio-8089-exec-2] o.h.type.descriptor.sql.BasicBinder      : binding parameter [2] as [TIMESTAMP] - [2024-06-17 15:51:01.0]
걸린 시간 : 2326
2024-06-17 15:51:03.614  INFO 7728 --- [nio-8089-exec-2] i.StatisticalLoggingSessionEventListener : Session Metrics {
    926000 nanoseconds spent acquiring 1 JDBC connections;
    0 nanoseconds spent releasing 0 JDBC connections;
    6734300 nanoseconds spent preparing 10 JDBC statements;
    1189451400 nanoseconds spent executing 10 JDBC statements;
    0 nanoseconds spent executing 0 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    0 nanoseconds spent executing 0 flushes (flushing a total of 0 entities and 0 collections);
    56300 nanoseconds spent executing 10 partial-flushes (flushing a total of 0 entities and 0 collections)
}

0827 개선

코드 최적화 및 임시 테이블 다중 사용

검색 시 특정 이름 제외 과정을 개발 중이었다. analyze Query 분석 과정에서 생각보다 많은 시간이 걸리는 점을 확인했다.

이것의 원인은, from 등 서브쿼리 스칼라 절의 테이블 결과값에는 ‘인덱스가 적용되지 않는다는 점’이다.

즉, (A Table) - Merge / Hash Join - (B Table) 과정에서 인덱스를 전혀 사용할 수 없다는 말이다.

이는 서브쿼리 결과는 메모리 상 임시 공간에 저장되기 때문으로, 모수를 줄일 수 있다고 해도 상당히 치명적인 문제이다.

비교

1. 서브쿼리를 제거하고 직접 조인

• 직접적인 인덱스 활용: 서브쿼리를 제거하고 직접 조인하면, 원본 테이블에 설정된 인덱스를 그대로 활용
• 쿼리 단순화 : 단순하고 최적화된 쿼리
• 단점 - 데이터 중복 처리: 서브쿼리를 제거하면, 원본 테이블에서 불필요한 데이터까지 모두 조인 대상이 됨. 즉, ‘테이블 내 모든 조건’을 조인 대상으로 삼아야 한다. 이것은 테이블 당 100만 ~ 1000만건의 데이터를 순회해야 하는 내 상황에서는 치명적이다.

1. 임시 테이블 사용 조인

• 데이터 정제 및 최적화: 서브쿼리 결과를 임시 테이블에 저장하고, 필요한 인덱스를 생성하여 조인 성능을 최적화할 수 있다. 현재 가장 필요한 기능이다.
• 단점 - 임시 테이블 생성 오버헤드 : 개별 세션 임시 테이블 생성시 발생할 수 있는 메모리 소모를 고려해야 한다. 그 외 코드가 조금 복잡해진다는 점 역시 존재한다.

결론 : 대량의 데이터 처리와 조건 처리의 관점에서, ‘임시 테이블’을 사용하여 서브쿼리를 대체하는 것이 좋은 방법이라고 판단했다.

/**
 * TraceId 기준 조회 배치 로직
 * 대규모 조회 고려하여 Native Query 사용
 */
@Component
@RequiredArgsConstructor
public class BatchGetSpanDtoUsingTraceId {

    private final DataSource dataSource;
    // Span Join Query
    private final String spanJoinSql =
            "SELECT s.id, s.scope_name, s.trace_id, s.span_id, s.parent_span_id, s.flag, s.name, " +
                    "s.kind, s.start_time_unix_nano, s.end_time_unix_nano, s.status_is_error, s.attributes, s.has_event " +
                    "FROM (SELECT * FROM tbl_apm_trace_span WHERE created_at BETWEEN ? AND ?) as s " +
                    "JOIN temp_trace_ids t ON s.trace_id = t.trace_id ";

    //서브쿼리 대체, 임시 테이블 생성 및 삽입 로직
    private final String fullTempTableSetupAndInsertSql =
            "CREATE TEMPORARY TABLE IF NOT EXISTS temp_trace_ids (trace_id UUID); " + //임시 테이블 생성
                    "CREATE INDEX idx_trace_id ON temp_trace_ids(trace_id); " + //인덱스 생성
                    "INSERT INTO temp_trace_ids (trace_id) " + //Insert 로직
                    "SELECT span_trace_id " +
                    "FROM tbl_apm_trace " +
                    "WHERE span_start_time_unix_nano BETWEEN ? AND ? AND agent_id = ?";

    private String addNotInName(List<String> excludeNameSet) {
        if (excludeNameSet == null || excludeNameSet.isEmpty()) return "";
        String names = excludeNameSet.stream()
                .map(name -> "'" + name + "'")
                .collect(Collectors.joining(", "));
        return " AND name not in (" + names + ")";
    }

    public <T> List<T> getSpans(RequestParamResult req, List<String> excludeNameList) throws SQLException, IOException {
        List<T> result = new ArrayList<>(); //결과값
        Connection connection = dataSource.getConnection();

        try (
                PreparedStatement createTempTablePstmt = connection.prepareStatement(fullTempTableSetupAndInsertSql + addNotInName(excludeNameList));
                PreparedStatement spanJoinPstmt = connection.prepareStatement(spanJoinSql);
        ) {
            connection.setAutoCommit(false);

            //temp table insert
            int idx = 1;
            createTempTablePstmt.setLong(idx++, req.getMinTimeUnixNano());
            createTempTablePstmt.setLong(idx++, req.getTimeUnixNano());
            createTempTablePstmt.setLong(idx++, req.getAgentId());
            createTempTablePstmt.executeUpdate();

            //span join
            idx = 1;
            spanJoinPstmt.setTimestamp(idx++, req.getCreatedAt()[0]);
            spanJoinPstmt.setTimestamp(idx++, req.getCreatedAt()[1]);

            ResultSet rs = spanJoinPstmt.executeQuery();
            while (rs.next()) {
                result.add((T) spanDtoMapper(rs));
            }

            connection.commit(); // Commit transaction
        } catch (Exception e) {
            connection.rollback(); // Rollback transaction on exception
            ErrorLogger.log(this.getClass().getName(), "batchInsertTraceIdGetSpanDtos");
            throw e;
        } finally {
            connection.setAutoCommit(true);
        }
        return result;
    }

    /**
     * ResultSet SpanDto Mapper
     */
    private SpanDto spanDtoMapper(ResultSet rs) throws SQLException, IOException {
        return new SpanDto(
                rs.getLong("id"),
                rs.getString("scope_name"),
                rs.getObject("trace_id", UUID.class),
                rs.getBytes("span_id"),
                rs.getBytes("parent_span_id"),
                rs.getInt("flag"),
                rs.getString("name"),
                rs.getInt("kind"),
                rs.getLong("start_time_unix_nano"),
                rs.getLong("end_time_unix_nano"),
                rs.getBoolean("status_is_error"),
                ObjectMapperProvider.get().readTree(rs.getBytes("attributes")),
                rs.getBoolean("has_event")
                // rs.getTimestamp("created_at")
        );
    }

HikariCP가 커넥션을 풀에 반환할 때, 해당 커넥션의 세션은 그대로 유지된다. 이는 세션을 가지고 있는 Connection 객체 자체가 세션을 끊지 않고 CP에 반환되기 때문일 것이다.

즉, 임시 테이블 등 세션 내에 존재하는 모든 데이터도 유지된 상태로 남아 있게 된다.

이를 해결하기 위해 명시적 DROP 및 임시 테이블 이름을 동적으로 만들어 동시성 처리를 수행할 필요가 있다.