프로젝트/APM Web Server 개발
(in 연산 → join) 및 커스텀 NativeQuery (24.06.14)
블랑v
2024. 9. 26. 03:56
현재
현재 사용하고 있는 IN 연산 최적화에 대한 접근 방식은 다음과 같다
- 시간 단위로 파티셔닝을 통해 필요한 데이터의 범위를 줄인 후,
(where created_at between (a, b) .. create_at을 기준으로 파티셔닝)
- 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 연산은 다음과 같은 방식으로 동작한다
- traceIdSet에 있는 값을 기반으로 traceId가 일치하는 행을 필터링한다.
- 큰 traceIdSet을 여러 개의 작은 배치로 나누어 각각 쿼리를 수행한다.
이 방식은 간단하고 직관적이지만, traceIdSet의 크기가 클 경우 성능에 영향을 미칠 수 있다.
이유는 각 쿼리마다 IN 연산을 수행하기 위해 많은 값을 비교해야 하기 때문이다.
특히 현재 BATCH_SIZE 를 5000개~ 정도로 잡고 있는데, 내부 파라미터가 늘어날 수록 성능이 유의미하게 떨어지는 것을 확인할 수 있었다.
이를 극복하기 위해 다른 방식의 쿼리를 사용해보았다.
1. IN 대신 JOIN 사용
IN 연산은 많은 값을 처리할 때 성능이 떨어질 수 있다. 조인을 사용하여 대규모 데이터 집합을 처리할 때 임시 테이블을 활용하는 것은 매우 유용할 수 있다. 임시 테이블을 사용하면 많은 수의 ID를 효율적으로 처리할 수 있으며, 데이터베이스의 조인 최적화 기능을 활용할 수 있다.
다음과 같은 방식으로 변경할 수 있다.
- inputTraceIdSet을 임시 테이블로 만든다.
- 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배 이상 효율적인 것이다.
결론
성능 차이와 개념적 이해
- IN 연산
- 많은 값을 비교할 때 성능이 저하될 수 있다.
- 데이터베이스가 각 값을 순차적으로 비교하여 필터링하기 때문에 시간이 많이 걸릴 수 있다.
- JOIN 연산
- 임시 테이블을 사용하여 대량의 값을 저장하고, JOIN을 통해 결합한다.
- 데이터베이스는 JOIN을 최적화할 수 있는 다양한 전략을 가지고 있어, 일반적으로 대량의 데이터를 처리할 때 더 효율적이다.
- 데이터베이스의 인덱스를 잘 활용할 수 있다.
- 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) 과정에서 인덱스를 전혀 사용할 수 없다는 말이다.
이는 서브쿼리 결과는 메모리 상 임시 공간에 저장되기 때문으로, 모수를 줄일 수 있다고 해도 상당히 치명적인 문제이다.
비교
- 서브쿼리를 제거하고 직접 조인
- 직접적인 인덱스 활용: 서브쿼리를 제거하고 직접 조인하면, 원본 테이블에 설정된 인덱스를 그대로 활용
- 쿼리 단순화 : 단순하고 최적화된 쿼리
- 단점 - 데이터 중복 처리: 서브쿼리를 제거하면, 원본 테이블에서 불필요한 데이터까지 모두 조인 대상이 됨. 즉, ‘테이블 내 모든 조건’을 조인 대상으로 삼아야 한다. 이것은 테이블 당 100만 ~ 1000만건의 데이터를 순회해야 하는 내 상황에서는 치명적이다.
- 임시 테이블 사용 조인
- 데이터 정제 및 최적화: 서브쿼리 결과를 임시 테이블에 저장하고, 필요한 인덱스를 생성하여 조인 성능을 최적화할 수 있다. 현재 가장 필요한 기능이다.
- 단점 - 임시 테이블 생성 오버헤드 : 개별 세션 임시 테이블 생성시 발생할 수 있는 메모리 소모를 고려해야 한다. 그 외 코드가 조금 복잡해진다는 점 역시 존재한다.
결론 : 대량의 데이터 처리와 조건 처리의 관점에서, ‘임시 테이블’을 사용하여 서브쿼리를 대체하는 것이 좋은 방법이라고 판단했다.
/**
* 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 및 임시 테이블 이름을 동적으로 만들어 동시성 처리를 수행할 필요가 있다.