사내 50여 대의 개발 및 검증용 가상머신(VM)을 관리하기 위해 구축했던 사내 VM IP 관리 시스템(IPAM)이 실무에 투입된 지 3개월 차에 접어들었을 때의 일입니다.
어느 날 오전 9시 30분, 출근 직후 슬랙 알림 채널에 “특정 개발 서버와의 통신이 끊겼다"는 경고 메시지가 간헐적으로 올라오기 시작했습니다. 그런데 정작 해당 VM에 SSH로 직접 붙어보면 CPU, 메모리, 네트워크 모두 지극히 정상으로 돌고 있었습니다.
문제의 원인은 클라이언트 VM이 아니라, 상태 하트비트를 받아 처리하는 Spring Boot 백엔드 서버의 HikariCP 커넥션 풀 고갈이었습니다. 이번 글에서는 겉보기엔 단순해 보였던 하트비트 수신 API가 어떻게 커넥션 풀을 말려버렸는지, 원인 분석과 리팩토링 과정을 공유합니다.
1. 시스템 구조와 평상시 트래픽 흐름
사내 IPAM 시스템의 동작 구조는 단순합니다.
- 각 VM에 상주하는 Go 경량 에이전트가 15초마다 CPU, 메모리, 디스크 사용량 및 IP 주소를 수집해 백엔드로
POST /api/v1/heartbeat를 전송합니다. - Spring Boot 백엔드는 하트비트를 받아 DB의
vms테이블에last_seen_at타임스탬프를 갱신합니다. - 만약 이전 상태와 비교해 디스크 사용량이 90%를 넘거나 IP가 변경되는 등 이상 징후가 감지되면 담당 팀 슬랙 채널로 웹훅 알림을 쏩니다.
VM이 50대 남짓이라 15초에 50건, 초당 평균 3~4건(TPS) 수준의 극히 미미한 트래픽이었습니다. 당연히 성능 문제가 생길 리 없다고 생각했습니다.
2. 장애 징후와 에러 로그 분석
하지만 프로덕션 로그에는 아래와 같은 끔찍한 에러 스택트레이스가 분당 수십 개씩 쌓이고 있었습니다.
org.springframework.dao.CannotAcquireLockException:
HikariPool-1 - Connection is not available, request timed out after 30002ms.
(total=10, active=10, idle=0, waiting=38)
at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:696)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:197)
at org.springframework.jdbc.datasource.DataSourceUtils.fetchConnection(DataSourceUtils.java:160)
at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:169)
HikariCP 기본 풀 사이즈인 10개의 커넥션이 100% Active 상태로 묶여 있고, 대기 큐(waiting)에 38개의 요청이 줄을 서다가 기본 타임아웃(30초)을 초과해 줄줄이 튕겨 나가고 있었습니다.
커넥션을 얻지 못한 하트비트 요청들이 500 Internal Server Error를 반환했고, 에이전트는 하트비트 전송에 실패했습니다. 백엔드의 헬스체크 스케줄러는 last_seen_at이 갱신되지 않은 VM들을 ‘비정상 오프라인’으로 판정해 슬랙에 허위 장애 경보를 쏟아낸 것이었습니다.
3. 근본 원인: 2가지 치명적인 설계 결함
소스 코드를 한 줄씩 디버깅하며 추적한 결과, 겉으로는 사소해 보였던 두 가지 설계 결함이 맞물려 발생한 병목이었습니다.
결함 1: @Transactional 내부에서 외부 HTTP I/O (슬랙 웹훅) 동기 호출
가장 치명적인 안티패턴이었습니다. 초기 서비스 로직이 아래처럼 작성되어 있었습니다.
// 문제가 된 기존 코드 (Anti-pattern)
@Service
@RequiredArgsConstructor
public class HeartbeatService {
private final VmRepository vmRepository;
private final SlackNotificationClient slackClient;
@Transactional
public void processHeartbeat(HeartbeatRequest request) {
Vm vm = vmRepository.findByMacAddress(request.macAddress())
.orElseThrow(() -> new EntityNotFoundException("VM Not Found"));
boolean isDiskCritical = request.diskUsage() >= 90.0;
boolean statusChanged = vm.updateStatus(request.ip(), request.cpuUsage(), request.diskUsage());
if (statusChanged && isDiskCritical) {
// [치명적 결함] 트랜잭션이 열린 채로 외부 네트워크 I/O를 동기 대기함!
slackClient.sendAlert(vm.getHostname() + " 디스크 용량 위험: " + request.diskUsage() + "%");
}
}
}
스프링에서 @Transactional이 선언된 메서드에 진입하면, 메서드 시작 시점에 커넥션 풀에서 DB 커넥션을 하나 꺼내옵니다.
그런데 그 트랜잭션 안에서 슬랙 외부 웹훅 HTTP 호출(slackClient.sendAlert)을 동기적으로 수행하고 있었습니다. 평소 슬랙 API가 50ms 만에 응답할 때는 문제가 없었지만, 슬랙 API 응답이 1~2초 지연되는 순간 DB 커넥션을 쥔 채로 HTTP 응답을 기다리느라 커넥션 반환이 막혀버린 것입니다.
결함 2: 50대 VM의 동기화된 하트비트 (Thundering Herd)
또 다른 원인은 Go 에이전트에 있었습니다.
// 문제가 된 기존 Go 에이전트 루프
ticker := time.NewTicker(15 * time.Second)
for range ticker.C {
sendHeartbeat()
}
사내 VM들은 템플릿 이미지를 복제해 동시에 배포된 경우가 많았습니다. 결과적으로 50대의 에이전트가 매 15초 정각(00초, 15초, 30초, 45초)에 동일한 밀리초 단위로 동시에 백엔드를 타격하는 ‘Thundering Herd’ 현상이 발생했습니다.
평균 TPS는 3~4였지만, 피크 순간에는 50개의 요청이 1초 안에 쏟아져 들어왔고, 슬랙 호출 지연과 맞물려 커넥션 풀 10개가 순식간에 동나버린 것입니다.
4. 문제 해결 및 리팩토링
이 문제를 근본적으로 해결하기 위해 3단계 조치를 단행했습니다.
조치 1: 스프링 이벤트와 @Async를 활용한 외부 I/O 트랜잭션 완전 분리
DB 커넥션은 데이터베이스 연산에만 사용하고, 외부 알림은 트랜잭션이 정상 커밋된 후 별도 스레드 풀에서 비동기로 처리하도록 분리했습니다.
@Service
@RequiredArgsConstructor
public class HeartbeatService {
private final VmRepository vmRepository;
private final ApplicationEventPublisher eventPublisher;
@Transactional
public void processHeartbeat(HeartbeatRequest request) {
Vm vm = vmRepository.findByMacAddress(request.macAddress())
.orElseThrow(() -> new EntityNotFoundException("VM Not Found"));
boolean statusChanged = vm.updateStatus(request.ip(), request.cpuUsage(), request.diskUsage());
if (statusChanged && request.diskUsage() >= 90.0) {
// 트랜잭션 내부에서는 이벤트만 발행하고 즉시 빠져나감
eventPublisher.publishEvent(new VmAlertEvent(vm.getHostname(), request.diskUsage()));
}
} // 이 시점에 DB 커넥션 즉시 반환 (점유 시간: 2~3ms)
}
그리고 이벤트 리스너에서 @TransactionalEventListener와 비동기(@Async)를 조합했습니다.
@Component
@RequiredArgsConstructor
public class VmAlertEventListener {
private final SlackNotificationClient slackClient;
@Async("notificationExecutor")
@TransactionalEventListener(phase = TransactionPhase.AFTER_COMMIT)
public void handleVmAlert(VmAlertEvent event) {
// DB 커넥션이 이미 풀로 반환된 후, 별도 스레드에서 슬랙 웹훅 발송
slackClient.sendAlert(event.hostname() + " 디스크 용량 위험: " + event.diskUsage() + "%");
}
}
이 변경으로 하트비트 처리 중 DB 커넥션 점유 시간이 기존 1,500ms 이상에서 평균 2.8ms로 약 500배 이상 단축되었습니다.
조치 2: Go 에이전트에 랜덤 지터(Full Jitter) 도입
에이전트들이 동시에 요청을 보내지 않도록 Go 클라이언트 코드에 주기 분산용 무작위 지터(Jitter)를 적용했습니다.
// 개선된 Go 에이전트 하트비트 루프
for {
sendHeartbeat()
// 기본 15초에 0~3,000ms 무작위 편차(Jitter)를 부여하여 요청 분산
jitter := time.Duration(rand.Intn(3000)) * time.Millisecond
time.Sleep(15*time.Second + jitter)
}
이 간단한 3줄의 코드로 50대의 VM이 백엔드로 보내는 요청 시점이 15초 전체에 걸쳐 완벽하게 고르게 분산되었습니다.
조치 3: HikariCP 메트릭 모니터링 구축
Spring Boot Actuator와 Prometheus 메트릭을 연동하여 커넥션 풀 상태를 실시간 모니터링하도록 대시보드를 추가했습니다.
# application.yml
management:
endpoints:
web:
exposure:
include: health, info, metrics, prometheus
metrics:
enable:
hikaricp: true
Grafana에서 hikaricp_connections_active와 hikaricp_connections_pending 지표를 감시하여, 대기 큐가 5개를 넘어가면 즉시 슬랙 비상 알림이 오도록 임계치를 설정했습니다.
5. 결과 및 교훈
리팩토링 후 2주 동안 모니터링을 진행한 결과:
- HikariCP Active 커넥션: 평상시 1~2개 유지 (최대 4개)
- 커넥션 대기(Pending) 건수: 0건
- 하트비트 타임아웃 오류: 완전 해소 (HTTP 200 성공률 100%)
이번 장애를 겪으며 얻은 가장 값진 교훈은 두 가지입니다:
@Transactional스코프 내부에는 절대로 외부 네트워크 I/O(외부 API, 웹훅, 메일 발송 등)를 두지 말 것. 슬랙 서버가 느려지면 내 데이터베이스가 멈춥니다. 외부 호출은 반드시 트랜잭션 커밋 이후 비동기로 분리해야 합니다.- 다수의 클라이언트나 에이전트가 주기적으로 폴링하는 아키텍처에서는 반드시 지터(Jitter)를 고려할 것. 고정된 인터벌은 언젠가 Thundering Herd라는 시한폭탄으로 돌아옵니다.
사내 시스템 개발과 React 대시보드 배포기를 이어가면서, 코드 몇 줄의 사소한 차이가 실제 운영 환경에서 인프라 전체의 가용성을 어떻게 좌우하는지 뼈저리게 체감한 경험이었습니다.