[MCP] Spring 서버 진단 MCP (운영 - Log 수집 TPS 및 Deadlock 개선)

안녕하세요. 오늘은 PlayMCP에 등록된 서버 진단 MCP 서버의 Deadlock 및 트러블 슈팅 개선 내역을 정리해보겠습니다.

문제점

로그 수집 서버 장애상황을 가정 후 해결될 경우 Forwarder 에서 다량의Log가 한번에 수집 서버에 요청하게됩니다.
이때, 아래와 같은 문제가 발생했습니다.

1. DeadLock이 발생
2. 네트워크 왕복 시간이 오래걸림. TPS 개선이 필요.

즉, 로그 수집 서버의 Log 저장 로직을 수정해야 했습니다.

기존 코드

@Transactional
    public IngestResultDto ingestLogs(String serverName, List<LogEventDto> events) {
    
        ...

        for (LogEventDto e : events) {
            if (e.getEventId() == null || e.getEventId().isBlank()) {
                continue;
            }
            serverLogRepository.insertIgnoreDuplicate(
                    e.getEventId(),
                    server.getId(),
                    e.getLevel(),
                    e.getMessage(),
                    convertTimestamp(e.getTs())
            );
        }
        log.info("{} 서버로부터 로그 {}개 수신됨",
                serverName, validEvents.size());
		...
    }

이전 포스팅에서 다뤘지만 Log 저장 방식에서 큰 문제가 있었습니다.

Log를 1개씩 DB에 저장하며 네트워크 왕복 비용이 컸습니다.

또한, Log 재전송 로직이 포함될 경우 DeadLock이 발생했습니다.

export const options = {
    vus: 50,           // 50명의 가상 유저
    duration: '30s',   // 30초 동안 테스트
};
const payload = [];
const batchSize = 100;
const now = Date.now();
for (let i = 0; i < batchSize; i++) {
        let eventIdStr;

        if (currentVU === 1) {
            eventIdStr = `deadlock-trap-seq${i}`;
        } else if (currentVU === 2) {
            eventIdStr = `deadlock-trap-seq${batchSize - 1 - i}`; 
        }
        else {
            eventIdStr = `safe-zone-vu${currentVU}-iter${currentIter}-seq${i}`;
        }

        payload.push({
            eventId: eventIdStr,
            ts: now + i,
            level: 'INFO',
            message: currentVU <= 5 ? `[RETRY] realistic load test message ${i}` : `[NORMAL] realistic load test message ${i}`
        });
    }

위 코드는 DeadLock 및 TPS 체크를 위한 K6 스크립트입니다.

50개의 Thread 를 이용해 30초간 100개의 로그가 담긴 Batch를 요청합니다.

테스트

1번의 DeadLock이 발생했고 총 571,300개의 로그가 저장됐습니다.

해결방법

우선 TPS 개선부터 진행하겠습니다.

기존 코드는 Log 1개 저장을 위해 DB로 네트워크 왕복을 했으므로 BULK INSERT로 해결 가능합니다.

BULK INSERT는 대량의 데이터를 효율적으로 삽입이 가능하다.

INSERT INTO table_name (column1, column2) VALUES 
('value1', 'value2'),
('value3', 'value4'),
('value5', 'value6');

이런 식으로 여러 데이터를 한번에 저장한다.

[사용 이유]

1. Log 1개 저장을 위해 왕복보다 100개 저장을 한번에 처리할 경우 네트워크 왕복 비용이 1/100 으로 감소합니다.
   (1회 왕복에 1ms 일 경우 100ms가 걸림. -> BULK INSERT 는 1ms 로 해결 가능)
2. Log를 단 건 저장할 경우 디스크 저장 비용과 INDEX 저장 비용이 BULK INSERT에 비해 성능 차이가 심합니다.

   DB의 B-TREE 구조에서 INDEX를 저장할 때 1건 씩 처리할 경우 Page split 과정이 빈번하게 발생하며 INDEX 생성 비용이 커집니다.
   반면, BULK INSERT의 경우 넣기전에 미리 100건을 정렬 후 넣게됩니다. Page Split 시 한번에 많은 공간을 확보한 후 넣으므로 단 건으로 넣을 때 보다 약 10배는 성능이 좋아집니다.

[Trade Off]
BULK INSERT 는 JPA로 해결이 불가능합니다.
JDBCTemplete 까지 내려가야 적용 가능합니다. 즉, 복잡도가 증가할 수 있습니다.

다른 방법

JPA saveAll()
saveAll()은 PK 생성 전략이 AUTO INCREMENT일 경우 Batch Insert가 불가합니다. 즉 findAll()을 이용해도 1건 씩 저장하게됩니다.

적용

		String sql = """
            INSERT INTO server_log (event_id, server_id, level, message, created_at, occurred_at)
            VALUES (?, ?, ?, ?, NOW(), ?)
            ON DUPLICATE KEY UPDATE event_id = event_id
            """;

        jdbcTemplate.batchUpdate(sql, new BatchPreparedStatementSetter() {
            @Override
            public void setValues(PreparedStatement ps, int i) throws SQLException {
                LogEventDto e = validEvents.get(i);
                ps.setString(1, e.getEventId());
                ps.setLong(2, server.getId());
                ps.setString(3, e.getLevel());
                ps.setString(4, e.getMessage());
                ps.setObject(5, convertTimestamp(e.getTs()));
            }

            @Override
            public int getBatchSize() {
                return validEvents.size();
            }
        });

for문으로 1건 씩 저장 -> BULK INSERT로 100 건을 한번에 저장으로 수정.

테스트

[개선 결과]
HTTP_REQ_DURATION : 249.32 ms -> 86.45 ms(65.3% 개선)
TPS(초당 로그 처리량) : 19043 -> 32080(68.5% 개선)

DeadLock

성능은 크게 향상됐지만 여전히 DeadLock이 발생합니다.

K6 스크립트 설명

K6 테스트 코드에 DeadLock 발생할 수 있도록 만들었지만 회피하지 못했습니다.

		if (currentVU === 1) {
            eventIdStr = `deadlock-trap-seq${i}`;
        } else if (currentVU === 2) {
            eventIdStr = `deadlock-trap-seq${batchSize - 1 - i}`; 
        }
        else {
            eventIdStr = `safe-zone-vu${currentVU}-iter${currentIter}-seq${i}`;
        }

여기서 VU가 1, 2일 경우 재시도 요청을 가정했습니다. eventId의 중복은 재시도 요청과 같습니다.

즉, 재시도 요청에서 DeadLock이 발생해 로그가 저장되지 못하고있습니다.

위의 테스트에선 DeadLock이 1번 발생했지만 여러번의 테스트 결과 평균적으로 1 ~ 10번 발생했습니다.

발생 원인

S-Lock(공유 락) -> X-Lock(베타 락) 승격 과정에서 발생했습니다.

2개의 Thread가 같은 eventId에 접근할 경우 트렌젝션이 끝날 때 까지 해당 행의 S-Lock을 줍니다.
여기서 Update 시 X-Lock 으로 승격해야하는데 A Thread가 S-Lock을 가지고 있으므로 이를 놓을 때 까지 대기합니다.
B Thread도 X-Lock 승격을 위해 A Thread가 S-Lock을 놓기를 기다리며 DeadLock이 발생합니다.

이는 코드의 문제가 아닌 재시도 요청에서 발생하는 MySQL의 방어로직입니다.

해결 방법

1. Message Queue 도입
   Log 저장 요청을 받으면 바로 저장이 아닌 Message queue에 전달하여 순차적으로 저장시키면 Deadlock이 쉽게 해결 가능

2. Redis Distributed Lock
   같은 eventID 요청이 올 경우 한번에 처리가 아닌 줄세우기를 통해 1명씩 처리하며 DeadLock을 회피

   1, 2번의 경우 인프라 유지비용 증가로 적용하지 않았습니다.

3. eventId unique 조건 해제 & 중복 저장 허용
   중복을 허용하여 저장 후 distinct & GROUP BY로 조회합니다.

   하지만 로그 분석 서비스는 쓰기 성능보다 읽기 성능이 훨씬 중요합니다.
   groub by로 묶을 경우 리소스 낭비가 심해져 조회 성능이 안좋아집니다.

4. @Retryable 이용
   근본적인 DeadLock 회피는 못하지만 발생 시 재시도 조건을 두어 회피할 수 있습니다.

   비용 추가 없이 가장 적용하기 좋습니다.
   또한, 위 테스트보다 더 큰 요청이 오기 전까지 이용 가능합니다.

해결

    @Retryable(
            value = {CannotAcquireLockException.class, DeadlockLoserDataAccessException.class}, // 데드락 에러 발생 시에만
            maxAttempts = 3,    // 최대 3번 재시도
            backoff = @Backoff(delay = 200)  // 0.2초 대기 후 재시도
    )
    @Transactional
    public IngestResultDto ingestLogs(String serverName, List<LogEventDto> events) {
    ...
	}

Spring Retry 라이브러리를 통해 재시도 로직을 간단히 만들 수 있습니다.

테스트

DeadLock을 회피할 수 있었고 p(95) 기준 성능도 기존가 2ms 차이로 큰 차이가 없음을 확인할 수 있었습니다.
(TPS 도 기존과 1% 차이로 비슷했습니다.)

마무리

[결과]

• 에러율 1% -> 0% 로 해결
• TPS 59.4% 증가
• 추가적인 인프라 개설 X

  근본적으론 log 데이터 저장은 MySQL이 아닌 NoSQL + ElasticSearch 을 이용해 쓰기, 읽기 성능을 높힐 수 있습니다.
  하지만, 인프라 관리 포인트 증가를 피하기 위해 고려하지 않았습니다.

[아쉬운 점]

• 근본적인 DeadLock 해결 X, 회피함

  하지만, 현재 트래픽을 감당할 수 있도록 만들었으므로 더 큰 트래픽이 생길 경우 해결해보겠습니다.