Spring Boot 3 Actuator로 p99 지연 원인 추적

서비스가 느려졌다는 신고는 보통 평균이 아니라 p95/p99 같은 꼬리 지연(tail latency)에서 먼저 드러납니다. 특히 p99는 “대부분은 빠르지만 가끔 아주 느린 요청”을 의미하므로, 단순히 로그 몇 줄로는 원인을 잡기 어렵습니다. Spring Boot 3에서는 Actuator와 Micrometer 기반 관측(Observability)이 기본에 가깝게 제공되며, 이를 잘 조합하면 p99 지연의 원인을 구간별로 분해해 빠르게 좁혀갈 수 있습니다.

이 글은 다음 질문에 답하는 방식으로 진행합니다.

• p99가 튀는 요청이 어떤 엔드포인트/상태코드/예외에서 발생하는가
• 지연이 서버 내부(스레드/GC/CPU) 인가, 외부 의존성(DB/HTTP) 인가
• 병목이 대기(waiting) 인가, 실행(executing) 인가

p99 지연 추적의 기본 전략: “분해해서 좁히기”

p99 지연은 보통 한 가지 원인이 아니라, 여러 레이어의 작은 문제들이 “하필 같은 시점에 겹치면서” 만들어집니다. 그래서 가장 효율적인 접근은 아래 순서로 관측 가능한 구간을 쪼개고, 각 구간에서 “p99를 악화시키는 분포의 꼬리”를 찾는 것입니다.

1. HTTP 요청 레벨: 어떤 라우트가 p99를 만드는가
2. 서버 리소스 레벨: 스레드 고갈, 큐 대기, GC, CPU 스파이크는 없는가
3. 의존성 레벨: DB 커넥션 풀/쿼리 지연, 외부 API 타임아웃/재시도는 없는가
4. 코드 레벨: 특정 로직/락/동기화/대용량 직렬화가 꼬리를 만드는가

Spring Boot 3 Actuator는 1~3을 “즉시” 확인할 수 있게 해주고, 4는 트레이싱/프로파일링/로그 상관관계로 파고듭니다.

Actuator 세팅: 필요한 엔드포인트와 히스토그램(퍼센타일) 활성화

의존성 추가

dependencies {
  implementation 'org.springframework.boot:spring-boot-starter-actuator'
  implementation 'io.micrometer:micrometer-registry-prometheus'
}

엔드포인트 노출 및 퍼센타일/히스토그램 설정

Micrometer에서 p99를 제대로 보려면 percentiles 또는 histogram을 켜야 합니다. 운영에서는 Prometheus를 많이 쓰므로 Prometheus scrape를 전제로 설정합니다.

management:
  endpoints:
    web:
      exposure:
        include: health,info,metrics,prometheus,threaddump,heapdump,loggers,env
  endpoint:
    health:
      show-details: when_authorized
  metrics:
    tags:
      application: my-service
    distribution:
      percentiles:
        http.server.requests: 0.5,0.9,0.95,0.99
      percentiles-histogram:
        http.server.requests: true

• http.server.requests는 Spring MVC/WebFlux 모두에서 핵심 지표입니다.
• percentiles-histogram을 켜면 Prometheus에서 histogram_quantile로 p99를 계산하기 쉬워집니다.

1단계: p99가 “어떤 요청”에서 발생하는지 먼저 특정하기

Actuator의 metrics로도 확인 가능하지만, 실전에서는 Prometheus/Grafana에서 라벨로 쪼개는 것이 가장 빠릅니다.

Prometheus에서 p99 계산(히스토그램 기반)

http_server_requests_seconds_bucket를 기반으로 p99를 계산합니다.

histogram_quantile(
  0.99,
  sum by (le, uri, method, status) (
    rate(http_server_requests_seconds_bucket{application="my-service"}[5m])
  )
)

여기서 핵심은 uri, method, status로 분해해 “p99를 만드는 조합”을 찾는 것입니다.

• 특정 uri에서만 튄다: 해당 핸들러/의존성/쿼리로 좁힙니다.
• 모든 uri에서 동시에 튄다: 스레드/GC/CPU/네트워크 같은 공통 원인을 의심합니다.

라벨 카디널리티 주의: uri 폭발 방지

동적 경로(예: /users/123)가 그대로 라벨이 되면 시계열이 폭발합니다. Spring은 기본적으로 템플릿 기반 uri를 쓰지만, 커스텀 필터나 프록시 설정에 따라 실제 경로가 들어갈 수 있습니다. 반드시 Grafana에서 uri 시계열이 과도하게 늘지 않는지 확인하세요.

2단계: “대기”가 원인인지 확인 (스레드/커넥션 풀 고갈)

p99가 튀는 가장 흔한 이유는 실행 시간이 길어서가 아니라, 실행을 시작하기까지 대기 시간이 길어지는 것입니다.

JVM 스레드 덤프: threaddump로 즉시 확인

Actuator 엔드포인트:

• GET /actuator/threaddump

스레드 덤프에서 다음 패턴을 봅니다.

• WAITING 또는 TIMED_WAITING 상태 스레드가 급증
• 특정 락/모니터에서 다수 스레드가 블로킹
• http-nio-...(Tomcat) 워커가 모두 점유되어 요청이 큐에서 대기

운영에서 스레드 덤프는 민감 정보가 포함될 수 있으니 접근 제어는 필수입니다.

Tomcat 스레드 풀/큐 대기 지표 확인

Boot 3 + Micrometer는 Tomcat 지표를 노출합니다. 예를 들어 다음과 같은 지표를 확인합니다.

• tomcat.threads.busy
• tomcat.threads.current
• tomcat.threads.config.max

Actuator에서 확인:

• GET /actuator/metrics/tomcat.threads.busy

p99 스파이크 시점에 busy가 max에 붙어 있으면, 애플리케이션이 느린 게 아니라 처리량 한계로 인해 대기열이 쌓이는 상황일 수 있습니다.

DB 커넥션 풀(Hikari) 고갈 체크

DB가 있는 서비스라면 p99 스파이크의 1차 용의자는 Hikari 풀 고갈입니다.

• hikaricp.connections.active
• hikaricp.connections.pending
• hikaricp.connections.max

pending이 증가하면 커넥션을 못 구해 대기 중이라는 뜻이고, 이 대기가 그대로 p99로 반영됩니다.

max_over_time(hikaricp_connections_pending{application="my-service"}[5m])

커넥션 풀이 고갈되는 이유는 보통 아래 중 하나입니다.

• 느린 쿼리로 커넥션이 오래 점유됨
• 트랜잭션 범위가 과도하게 큼(불필요한 외부 호출을 트랜잭션 안에서 수행)
• 커넥션 누수(예외 경로에서 close 누락 등)

DB 락/데드락도 tail latency를 크게 만들 수 있습니다. InnoDB 데드락과 트랜잭션 경합을 다루는 글도 함께 참고하면 좋습니다: MySQL InnoDB 데드락 1213 에러 원인·해결

3단계: “실행”이 느린지 확인 (GC/CPU/메모리 압박)

대기가 아니라 실행 자체가 느려지는 경우, 보통 GC 또는 CPU 포화가 p99 꼬리를 만듭니다.

GC/메모리 관련 핵심 지표

• jvm.gc.pause (히스토그램)
• jvm.memory.used
• jvm.memory.max
• jvm.threads.live

Prometheus에서 GC pause p99:

histogram_quantile(
  0.99,
  sum by (le) (rate(jvm_gc_pause_seconds_bucket{application="my-service"}[5m]))
)

p99 스파이크 시점에 GC pause p99도 같이 튄다면, HTTP p99의 상당 부분이 GC에 의해 설명될 수 있습니다.

CPU 포화 확인

Actuator만으로 CPU를 완벽히 보긴 어렵지만, 보통은 인프라 지표(노드/컨테이너 CPU)와 함께 봅니다. 그래도 애플리케이션 관점에서는 다음 신호가 유용합니다.

• 스레드 덤프에서 RUNNABLE 스레드가 많고 스택이 특정 연산(직렬화/암호화/정규식/JSON 변환)에 몰림
• GC가 잦아지고 allocation rate가 높아짐

4단계: HTTP 지표를 “더 쪼개기” (상태코드/예외/클라이언트 구분)

http.server.requests는 기본적으로 status, exception 라벨을 제공합니다. p99가 200 OK에서만 튀는지, 5xx/timeout에서 튀는지에 따라 접근이 갈립니다.

• 5xx 비중이 증가: 의존성 장애, 타임아웃, 서킷브레이커 동작을 의심
• 200인데 p99만 증가: 쿼리/락/스레드풀 대기/GC 같은 성능 이슈를 의심

PromQL 예시(상태코드별 p99):

histogram_quantile(
  0.99,
  sum by (le, status) (
    rate(http_server_requests_seconds_bucket{application="my-service", uri="/api/orders"}[5m])
  )
)

5단계: 커스텀 관측으로 “의존성 구간”을 분리하기

Actuator 기본 지표만으로는 “컨트롤러 전체 시간”만 보이기 쉽습니다. p99 원인을 빨리 잡으려면 DB 호출, 외부 API 호출, 캐시 조회 같은 핵심 구간을 별도 타이머로 측정해 분리합니다.

Micrometer @Timed로 서비스 메서드 구간 계측

import io.micrometer.core.annotation.Timed;
import org.springframework.stereotype.Service;

@Service
public class OrderService {

  @Timed(value = "orders.place", percentiles = {0.95, 0.99})
  public void placeOrder(Long userId) {
    // 핵심 로직
  }
}

이렇게 하면 orders.place라는 별도 타이머가 생기고, HTTP p99가 튀는 시점에 이 타이머 p99도 같이 튀는지 비교할 수 있습니다.

• HTTP p99만 튄다: 필터/서블릿 컨테이너/스레드 대기/네트워크 문제 가능
• orders.place도 같이 튄다: 비즈니스 로직/의존성 호출이 원인일 가능성

Timer를 직접 사용해 외부 호출 p99 분리

import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.Timer;
import org.springframework.stereotype.Component;

@Component
public class PaymentClient {
  private final Timer timer;

  public PaymentClient(MeterRegistry registry) {
    this.timer = Timer.builder("payment.http")
        .description("Payment API latency")
        .publishPercentileHistogram()
        .publishPercentiles(0.95, 0.99)
        .register(registry);
  }

  public String pay(String payload) {
    return timer.record(() -> {
      // 외부 HTTP 호출
      return "ok";
    });
  }
}

이렇게 분리해두면 p99의 원인이 “외부 결제 API”인지, “DB”인지, “내부 로직”인지가 훨씬 빨리 드러납니다.

6단계: 로그/트레이스와 연결하기 (상관관계 ID)

Actuator/메트릭은 “어디가 느린지”를 알려주지만, “왜 느린지”는 보통 트레이스/로그가 필요합니다. 최소한 아래는 권장합니다.

• 요청 ID를 MDC에 넣고 응답 헤더에도 내려 상관관계 확보
• 느린 요청(예: 2초 이상)만 샘플링해서 구조화 로그로 남김

예시(서블릿 필터):

import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;
import org.springframework.web.filter.OncePerRequestFilter;

import java.io.IOException;
import java.util.UUID;

@Component
public class RequestIdFilter extends OncePerRequestFilter {
  @Override
  protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
      throws ServletException, IOException {

    String requestId = UUID.randomUUID().toString();
    MDC.put("request_id", requestId);
    response.setHeader("X-Request-Id", requestId);

    try {
      filterChain.doFilter(request, response);
    } finally {
      MDC.remove("request_id");
    }
  }
}

이후 p99가 튄 시점의 느린 요청 로그를 모아 공통점(특정 파라미터, 특정 사용자, 특정 쿼리 패턴)을 찾습니다.

7단계: 자주 나오는 p99 원인 패턴과 Actuator로 잡는 법

패턴 A: 커넥션 풀 pending 증가 + HTTP p99 증가

• 증상: hikaricp.connections.pending가 스파이크와 동행
• 원인 후보: 느린 쿼리, 인덱스 누락, 락 경합, 트랜잭션 범위 과다
• 조치: 느린 쿼리 로깅/플랜 확인, 트랜잭션 축소, 적절한 인덱스, 락 경합 제거

패턴 B: Tomcat busy가 max에 붙고 p99가 튐

• 증상: 처리량 한계로 요청이 큐에서 대기
• 원인 후보: 특정 엔드포인트의 CPU-heavy 작업, 동기 블로킹 I/O, 외부 API 타임아웃
• 조치: 타임아웃 단축, bulkhead(격리), 캐싱, 비동기 처리, 워커/리소스 증설

패턴 C: jvm.gc.pause p99가 튀면서 HTTP p99도 튐

• 증상: GC pause가 꼬리를 만들고 전체 지연을 끌어올림
• 원인 후보: 객체 할당 과다, 큰 컬렉션/버퍼, 응답 페이로드 과대
• 조치: 페이로드 축소, 스트리밍 처리, 캐시/버퍼 재사용, 힙/GC 튜닝

운영 팁: Actuator 보안과 성능

• threaddump, heapdump, env는 민감 정보가 포함될 수 있으니 반드시 인증/인가를 적용하세요.
• 퍼센타일/히스토그램은 비용이 있습니다. 모든 메트릭에 무작정 적용하지 말고 http.server.requests와 핵심 커스텀 타이머에만 선별 적용하세요.
• uri 라벨 카디널리티는 반드시 통제하세요. 카디널리티 폭발은 모니터링 시스템 자체를 느리게 만들고, 결국 관측이 불가능해집니다.

정리: p99는 “한 번에” 잡지 말고 “구간별로” 잡는다

Spring Boot 3 Actuator는 p99 지연을 추적할 때 출발점으로 매우 강력합니다. 핵심은 다음 3가지를 습관처럼 적용하는 것입니다.

1. http.server.requests p99를 uri/method/status로 분해해 범위를 좁힌다
2. 스레드/커넥션 풀 지표로 “대기 병목” 여부를 먼저 판별한다
3. DB/외부 API/핵심 로직을 커스텀 타이머로 분리해 p99 꼬리가 생기는 구간을 특정한다

DB 락/트랜잭션 경합이 의심된다면 데드락/락 대기까지 함께 점검해보세요: MySQL InnoDB 데드락 1213 에러 원인·해결