로그 수집 서비스 성능 개선하기(정제 서버 편)

multi-row insert와 multi-thread, 근데 이제 자료 구조를 곁들인
maro's avatar
Sep 19, 2024
로그 수집 서비스 성능 개선하기(정제 서버 편)
이 글에서는 데이터 웨어하우스에 대량의 데이터를 insert 하는 정제 서버의 성능 개선에 대한 내용을 다룹니다.
이 글은 다음 글들과 이어집니다.
 
사내에 대량의 트래픽이 몰리는 서비스 중 로그 수집 서비스가 있습니다. 사내의 모든 서비스 지표들을 모아서 시각화하는 서비스로 일일 2000만 건 이상의 데이터를 처리해야 합니다.
notion image
서비스에는 위와 같이 각 서비스에서 보내는 로그를 받아주는 로그 수집서버, 받은 로그를 정형화하여 AWS Redshift에 저장하는 정제 서버가 있습니다. 이 글에서는 정제 서버의 성능 개선에 대한 내용을 다루고, 다른 글에서 로그 수집서버의 성능 개선 내용을 다뤄보도록 하겠습니다.
 

성능 측정

앞서 다른 글들에서 설정한 k6로 성능 테스트를 하던 중, 아래와 같은 심각한 결과를 보게 되었습니다.
notion image
위 지표는 버퍼 역할을 하는 ElasticCache Redis의 데이터베이스 용량 사용률 지표입니다. 보시는 바와 같이 대략 38% 용량의 데이터가 처리되는 데에 6일 16시간 정도 걸렸습니다. 테스트에 사용된 Redis의 노드 유형은 cache.t4g.micro로 0.5GB의 용량을 가집지다. 따라서 약 0.18GB(35만건)의 데이터를 처리하는데 일주일 가까운 시간이 걸린 셈입니다.
 

성능 저하의 원인

insert into log_login (column1, column2, column3 ...) values ($1, $2, $3 ...); insert into log_login (column1, column2, column3 ...) values ($1, $2, $3 ...); insert into log_login (column1, column2, column3 ...) values ($1, $2, $3 ...);
Redshift의 쿼리 모니터링으로 확인해보니, 모든 쿼리가 단건으로 처리되고 있었습니다. 테스트한 프로젝트는 이전에는 MyBatis를 쓰던 부분을 JPA로 리팩토링하였는데, 이 과정에서 Multi-row로 insert하던 부분이 단 건으로 바뀌었던 것입니다. 이 부분을 다시 Multi-row 방식으로 바꾸면서 다른 부분들도 개선하기로 하였습니다.
 

서버의 구조

notion image
정제 서버는 Reader 파트, Data Praser 파트, Writer 파트로 나눌 수 있습니다. Reader가 정해진 Chunk 사이즈로 데이터를 읽어오면, Data Parser에서 데이터를 정형화하고, Writer에서 Redshift에 데이터를 삽입합니다.
여기서 각 파트 별로 성능 개선점을 찾고 개선해보도록 하겠습니다.
 

Writer

Writer는 chunk 하나 당 시간이 초 단위로 걸리는 주요 병목 지점입니다. 그래서 우선적으로 살펴보겠습니다.
 

Bulk Insert

단 건으로 Insert 요청을 하는 것이 문제이기에 JPA에서 이 문제의 해결 방법을 찾으면 제일 먼저 나오는 키워드가 Bulk Insert 일 것입니다. Bulk Insert는 쿼리를 모아서 DB 서버로 보내기 때문에 네트워크 I/O를 줄여서 성능 개선을 할 수 있습니다. (JPA에서 Bulk Insert 설정하는 방법은 이 글을 참고 해주시기 바랍니다.)
notion image
성능 개선 효과는 확실했습니다. 총 처리 시간에서 무려 63%의 개선이 이루어졌습니다. 하지만 여전히 50만건에 3일이 넘는 시간이 소요되는 수준이었고, 훨씬 더 많은 개선이 필요했습니다.
 

Multi-row Insert

사실 Bulk Insert는 제가 원래 원했던 것이 아니었습니다. Bulk Insert는 네트워크 전송만 한 번에 보낼 뿐 DB 서버에서 Insert는 개별로 이루어집니다. 원래 원하던 것처럼 하나의 쿼리에서 여러 row를 삽입하는 것은 Multi-row Insert 라고 합니다.
// 원하던 것은 이런 쿼리 입니다. insert into log_login (column1, column2, column3 ...) values ($1, $2, $3 ...), ($1, $2, $3 ...), ($1, $2, $3 ...);
JPA로 Multi-row Insert를 하려면 Bulk Insert를 위해 쓰기 지연 연산소에 모아놓았던 쿼리들을 JDBC 단에서 재조합하여 Multi-row Insert 쿼리로 만들어야 합니다. 이를 위해 data source properies에 설정을 추가해야 하는데, 이때 MySQL은 rewriteBatchedStatements이고, Postgresql는 rewriteBatchedInserts를 설정명으로 사용하시면 됩니다.
datasource.url: jdbc:mysql://localhost:3306/db?rewriteBatchedStatements=true datasource.url: jdbc:postgresql://localhost:5432/db?rewriteBatchedInserts=true // url에 설정하지 않고, properies로 설정할 수도 있다. spring.datasource.hikari.data-source-properties.rewriteBatchedStatements: true spring.datasource.hikari.data-source-properties.rewriteBatchedInserts: true
하지만 Redshift가 PostgreSQL 8.0.2 버전을 기반으로 만들어졌음에도 위 설정에 대해서는 제대로 동작하지 않습니다. 그리고 무엇보다도 성능 개선을 위해 Multi-row Insert를 하려는데, 위와 같은 방식은 쿼리를 다시 재조합하는 과정이 있다는 면에서 성능 저하가 우려되었습니다. 또한, ID 생성 전략으로 IDENTITY를 쓸 수 없다는 점도 JPA를 고집할 이유를 없게 만들었습니다.
그래서 선택한 방법은 JDBC Batch Insert 방식을 사용하는 것입니다.
@Repository @RequiredArgsConstructor public class LogLoginRepository { private final JdbcTemplate jdbcTemplate; public void saveAll(List<LogLogin> logLogins) { String sql = "INSERT INTO log_login " + "(column1, column2, column3)" + "VALUES (?, ?, ?)"; StringBuilder multiRowSql = new StringBuilder(sql); multiRowSql.append(", (?, ?, ?)".repeat(Math.max(0, logLogins.size() - 1))); jdbcTemplate.update(connection -> { PreparedStatement ps = connection.prepareStatement(multiRowSql.toString()); int index = 1; for (LogLogin logLogin : logLogins) { ps.setLong(index++, logLogin.getColumn1()); ps.setInt(index++, logLogin.getColumn2()); ps.setString(index++, logLogin.getColumn3()); } return ps; }); } }
위와 같이 Multi-row를 위한 PreparedStatement를 생성하고 여기에 Insert할 도메인 객체를 할당하여서 쿼리를 생성합니다.
notion image
Multi-row로 변경한 결과, 298,800초(83시간) 걸리던 작업이 560초(9분 20초)만에 처리되었습니다. 퍼센트로 따지면 무려 99.81%의 개선 효과입니다.
이제 writer 부분은 어느정도 개선된 것 같으니 다른 부분을 개선해보도록 하겠습니다.
 

Reader

Limit of the PostgreSQL JDBC driver

사실 Writer 파트에서 Multi-row Insert 방식으로 변경하면서 발생한 이슈가 있었습니다.
HikariPool-1 - Connection com.amazon.redshift.jdbc.RedshiftConnectionImpl@709e8a01 marked as broken because of SQLSTATE(08006), ErrorCode(0) Caused by: java.io.IOException: Tried to send an out-of-range integer as a 2-byte value: 60000
PostgreSQL JDBC Driver에는 최대 32767개의 매개 변수 상한 제한이 있습니다. 이건 Java의 short 데이터 타입 최대값(2byte)에 따른 것입니다. (2^15 -1) 그런데 이 제한을 넘어서 매개 변수를 넣다보니 위와 같은 이슈가 발생한 것입니다.
서버에서는 1초에 한 번 Redis에서 데이터를 5000건씩 가져오도록 되어있었는데, 이 Chunk 사이즈를 조정하여 문제를 해결하기로 하였습니다. 그리고 서비스 특성 상 컬럼 개수가 여유분을 감안하더라도 16개를 넘지 않을 것으로 감안하고 Chunk 사이즈를 2000개로 변경하였습니다. (2^15 -1)/2000 = 16.xxx
 

멀티 스레드 스케줄링

스케줄링이 1초에 한 번씩 돌도록 되어있다고 했는데, 작업이 단일 스레드로 돌고 있으므로 Block되는 시간이 1초를 넘어가면 다음 작업 시간이 밀리게 됩니다. 실제로 서버에서는 1초가 아닌 약 2초에 한 번씩 동작합니다. 멀티 스레딩으로 동작할 수 있도록 이 부분을 비동기 방식으로 변경하겠습니다.
@EnableAsync @Configuration public class AsyncConfig { @Bean(name = "asyncTaskExecutor") public ThreadPoolTaskExecutor asyncTaskExecutor() { ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor(); executor.setCorePoolSize(5); executor.setMaxPoolSize(5); executor.setThreadNamePrefix("AsyncTask-"); executor.initialize(); return executor; } } @Async("asyncTaskExecutor") @Scheduled(fixedDelay = 1000) public void scheduler() { // 스케줄 동작 }
Async설정을 위한 AsyncConfig 클래스를 생성하고, PoolSize를 지정합니다. 그리고 비동기 동작을 원하는 메서드 위에 @Async 어노테이션을 달아줍니다.
hikari.maximum-pool-size: 5
HikariCP를 사용한다면 커넥션 풀 사이즈도 알맞게 조정해줘야 합니다. 커넥션 풀 사이즈가 비동기 풀 사이즈보다 작다면 커넥션을 기다리다 SQLTransientConnectionException이 발생할 것입니다.
 

스레드 풀 사이즈 정하기

멀티 스레드로 작업하기로 하였다면 스레드 개수를 몇 개로 할지가 가장 고민되는 사항입니다. 무작정 스레드 개수를 많이 한다면 컨텍스트 스위칭 비용 때문에 오히려 성능 저하가 발생할 것이기 때문입니다. 따라서 서버의 코어 개수와 DB 서버의 성능 등을 고려하여 결정해야 합니다.
다음은 스레드 개수 별 DB Insert 시간 비교 입니다.
notion image
위 데이터를 보면 동시에 요청하는 커넥션 개수에 비례하여 DB의 처리 시간도 늘어나고 있는 것을 볼 수 있습니다. 즉, 우리가 기대하는 것처럼 커넥션 개수가 늘어난다고 해서 전체 처리 시간이 크게 줄어들지는 않습니다.
물론, 여기서는 DB 서버의 성능을 고려해야합니다. 테스트에 사용한 Redshift의 노드 유형은 dc2.largevCPU가 2개입니다. 그리고 실제 코어 수는 vCPU의 반이기에 1개의 코어로 쿼리를 처리하고 있는 것입니다. 코어 수가 많다면 코어 수까지는 커넥션 수가 늘었을 때 큰 시간 감소를 기대할 수 있겠지만 여기서는 코어 수가 1개이기 때문에 크게 시간이 줄지 않는 것입니다.
chunk 사이즈인 2000개 당 처리 시간으로 환산했을 땐 어떤지 확인해보겠습니다.
notion image
데이터를 보면 스레드 4개까지는 시간이 줄어들다가 그 이후로는 오히려 시간이 증가하는 것을 볼 수 있습니다. 이는 Redshift 내부에서 Blocking되는 작업에 대해 멀티 스레드로 병렬 처리를 하기 때문에 시간이 감소하나 4개 이후에는 컨텍스트 스위칭 비용이 더 커지기 때문으로 짐작할 수 있습니다.
결론적으로, dc2.large노드 유형의 Redshift 서버에서는 스레드 풀 사이즈를 4로 변경하고, 스케줄 시간도 100ms로 변경하였습니다. 그 결과, 9분 20초 걸리던 작업이 3분 59초까지 약 58% 감소되었습니다.
notion image
 

Data Parser

Data Parser에서는 로그 종류 별로 해당하는 테이블에 데이터를 넣기 위해 분류하고 객체로 변환하는 작업을 하고 있습니다. JPA로 변환한 신규 프로젝트와 달리 MyBatis로 되어있던 구 프로젝트는 데이터 처리방식이 달라 많은 시간이 소요되고 있었습니다. 따라서 이 부분을 병렬 처리하여 개선해보도록 하겠습니다.
JPA의 신 프로젝트에선 이미 Common Thread Pool 사이즈(프로세서 코어수 - 1)에 가깝게 스케줄링 멀티 스레드를 쓰고 있어서 성능 이득이 거의 없겠지만, 구 프로젝트에서는 큰 성능 개선이 기대됩니다.

Parallel Stream

// 병렬 처리 logList.parallelStream().forEach(logStr -> { // 로그 파싱하여 List에 추가 }
Java8부터는 병렬 스트림을 이용해 간단하게 병렬 처리를 할 수 있습니다. 위와 같이 변경하여 결과를 확인해보겠습니다.
notion image
기존 순차 처리 시 11500ms 걸리던 작업이 병렬 처리 후 7200ms로 약 38% 시간 감소되었습니다.

Thread-Safe한 Collection

간편하게 병렬 작업을 하도록 변경하였지만 문제가 있습니다. 다음은 처리 요청 건수와 실제 처리된 건수입니다.
  • 요청 데이터 : 299,291 건
  • 저장 데이터 : 297,841 건
위와 같이 누락되는 데이터가 있습니다. 이는 멀티 스레딩 동작 시 흔히 문제되는 동시성 문제입니다. 동시성 문제를 해결하는 방법에는 여러가지가 있지만 현재 상황에서 가장 쉽게 해결하는 방법은 Synchronized Collection을 사용하는 것입니다.
ConcurrentLinkedQueue가 Synchronized Collection에 비해 더 효율적인 방식이며 Queue도 Collection 인터페이스를 구현하기 때문에 foreach 구문에서 사용 가능합니다.
List<LogLogin> loginList = Collections.synchronizedList(new ArrayList<>());
파싱한 로그를 저장하는 리스트를 Collections.synchronizedList 메서드로 생성하면 Thread-Safe한 리스트가 생성됩니다.
Synchronized Collection으로 변경하고 다시 테스트를 해본 결과 아래와 같이 요청 데이터가 누락없이 저장된 것을 확인할 수 있었습니다. 처리 시간에 있어서도 거의 같은 모습을 보였습니다.
  • 요청 데이터 : 299,360 건
  • 저장 데이터 : 299,360 건
List 구현 클래스는 LinkedList가 아닌 ArrayList를 사용해야합니다. parallelStream으로 병렬 작업 시 스레드가 데이터를 분할하여 처리해야 하는데 Array는 저렴하고 균등하게 분할 할 수 있는 반면, LinkedList는 그렇게 동작하지 않기 때문입니다.

List to HashMap

public enum LogGroup { LOGIN("인증", 3, Arrays.asList(LOG_ITEM_CODE_LOGIN)), PURCHASE("결제", 2, Arrays.asList(LOG_ITEM_CODE_PURCHASE_RECEIPT_COMPLETE, LOG_ITEM_CODE_PURCHASE_RECEIPT_VERIFY_FAIL, LOG_ITEM_CODE_PURCHASE_RECEIPT_ETC_FAIL)); }
파싱 작업 중에는 로그를 지정된 테이블에 넣기 위해 enum으로 관리하는 클래스에서 테이블 유형을 찾는 프로세스가 있습니다. 여기서 전체 항목의 List를 순회하여 맞는 테이블 유형을 찾는지라 O(n)의 시간이 걸리고 있었습니다.
private static final Map<Integer, LogGroup> CODE_TO_LOG_GROUP_MAP; static { Map<Integer, LogGroup> tempMap = new HashMap<>(); for (LogGroup logGroup : LogGroup.values()) { for (Integer logCode : logGroup.getLogItemList()) { tempMap.put(logCode, logGroup); } } CODE_TO_LOG_GROUP_MAP = Collections.unmodifiableMap(tempMap); } public static LogGroup findByItemCode(int itemCode) { return CODE_TO_LOG_GROUP_MAP.getOrDefault(itemCode, LogGroup.NOT_VALID); }
이를 Static 생성자에서 HashMap으로 관리하도록 하여 테이블 유형을 찾을 때 O(1)의 시간 복잡도로 찾을 수 있도록 변경하였습니다. 그 결과, 처리 시간이 6500ms로 약 10%의 시간 절감 효과를 얻을 수 있었습니다.
HashMap을 사용한다고 해서 항상 O(1)의 시간 복잡도를 보장하는 것은 아닙니다. Java에서 HashMap은 키의 hashCode() 메서드를 사용하여 해시값을 계산합니다. 예를 들어, 키가 String 타입일 경우, String의 hashCode() 메서드는 내부적으로 문자열 길이에 비례하는 반복문을 사용합니다. 따라서 이 경우 HashMap의 실제 시간 복잡도는 O(1)이 아닌 O(n)이 될 수 있습니다. 따라서, 위의 예시에서는 Key로 Integer를 사용하였습니다.
 
notion image
 

결론

정제 서버에서 Reader, Data parser, Writer로 나눠 Multi-row Insert, 멀티 스레딩, 자료 구조 변경 등을 통해 성능 개선을 해보았습니다. 이 과정에서 스레드를 늘리는 것이 무조건 성능 향상을 가져오지 않는다는 점과 동시성 이슈에 대해서도 잠시 확인해볼 수 있었습니다.
다음은 성능 개선 결과입니다. AWS Redshift dc2.large 노드 유형 1개 클러스터를 기준으로 50만건 처리에 9일 12시간이 걸리던 것이 3분 59초로 줄여서 무려 99.98%의 개선 효과를 이뤘습니다.
개별 Insert
Bulk Insert
Multi-row
Multi-row + Multi Thread 100ms
50만 건 처리 시간
9일 12시간
3일 11시간
9분 20초
3분 59초
혹시 Insert 시간이 너무 오래 걸리거나 위 아키텍처에 문제가 있다고 느끼시나요? 맞습니다. OLAP 데이터 웨어하우스인 Redshift에 바로 Insert 하는 것은 좋은 생각이 아닙니다. OLTP RDS에 넣거나 S3에 넣어서 Redshift로 보내는 것이 더 효율적인 방법입니다. 다만, 여기서는 기존 아키텍처를 최대한 건들지 않으면서 개선하고자 했습니다.
다음 글에서는 로그 수집 서버의 성능을 측정하고, 개선하는 작업을 해보겠습니다. 여기서는 제대로 k6의 성능 테스트를 사용해볼 수 있을 것입니다.
Share article

maro