.svg)
%201.svg)
%201.svg){kind=icon}
담당자가 프로모션 코드를 발송해 드립니다.
와탭을 경험해 보세요.
와탭을 경험해 보세요.
와탭을 경험해 보세요.
와탭을 경험해 보세요.
와탭을 경험해 보세요.
와탭을 경험해 보세요.
와탭을 경험해 보세요.
와탭을 경험해 보세요.
WhaTap AI를 경험해 보세요.
"에러 로그는 쌓이는데 진짜 원인이 안 보여요" 김부장이 메트릭·로그·트레이스 보는 순서
장애가 나면 저도 한동안은 로그 검색창부터 열었습니다. Error, Exception, Critical을 넣고 화면을 새로고침하면서 뭔가 걸리기를 기다렸습니다. 작은 장애는 그렇게도 잡혔습니다. 문제는 서비스가 여러 개로 쪼개지고 나서였습니다.
큰 장애일수록 로그부터 여는 방법이 가장 오래 걸렸습니다. 수만 줄이 쏟아지는 검색 결과 앞에서, 정작 시스템을 멈춰 세운 게 무엇인지는 좀처럼 드러나지 않았습니다. 로그는 벌어진 일을 하나하나 정확히 적어 두지만, 지금 이 장애가 어떻게 얽혀서 커졌는지는 알려주지 않습니다. 그 얘기를 하려면 다른 데이터부터 봐야 한다는 걸, 저는 몇 번 시간을 날리고 나서야 알았습니다.
시스템이 남기는 메트릭, 로그, 트레이스를 언제 꺼내 쓰고 어떻게 넘어가는지, 현장에서 여러 번 마주친 장애를 대표적인 한 사례로 처음부터 되짚어 봤습니다.
메트릭, 로그, 트레이스는 각각 다른 질문에 답합니다
메트릭, 로그, 트레이스는 시스템이 밖으로 내보내는 세 가지 신호로, 흔히 옵저버빌리티 3요소라고 부릅니다. 셋 중 뭘 먼저 볼지는 각자가 답하는 질문이 다르다는 것만 기억하면 대부분 자연스럽게 정해집니다.
- 메트릭(Metrics): "지금, 어디가, 얼마나 아픈가?" 응답 시간 p95, 에러율, 커넥션 풀 점유율처럼 시간에 따라 쌓인 숫자로 문제의 발생 여부와 규모를 먼저 알려줍니다.
- 로그(Logs): "무슨 일이 있었나?" 특정 시점에 찍힌 예외 메시지와 스택 트레이스로 실패의 구체적인 원인을 문장으로 보여줍니다.
- 트레이스(Traces): "요청이 어디서 막혔나?" 요청 하나가 여러 서비스를 거쳐 가는 전체 경로를 타임라인으로 이어, 병목이 생긴 구간을 보여줍니다.
메트릭으로 숲을 보고, 로그로 사건을 확인하고, 트레이스로 경로를 따라갑니다. 아래 사례가 이 순서를 어떻게 밟는지 따라가 보겠습니다.
타임세일 도중 주문 시스템이 멈췄다
여러 현장에서 반복해 본 유형을 대표적인 한 장면으로 모았습니다. 마케팅에서 준비한 선착순 할인 타임세일이 열리고 3분쯤 지나 주문 서비스가 멈췄습니다. 사용자들은 "결제 버튼을 눌렀는데 다음 화면으로 안 넘어간다"며 이탈하기 시작했고, 응답 시간과 에러율이 함께 튀었습니다.
그림 1. 타임세일이 시작되자 응답 시간이 타임아웃 상한에 붙어 포화됐고, 에러율도 같은 시점부터 급등했습니다. 가장 먼저 튄 지표가 진단의 출발점입니다.
당시 구조는 API 게이트웨이 뒤에 주문(Order), 결제(Payment), 쿠폰(Coupon) 서비스가 서로 호출을 주고받는 마이크로서비스(MSA) 환경이었습니다. 서비스가 여러 개로 쪼개져 있으면, 어디서부터 봐야 할지가 사실 제일 어렵습니다. 솔직히 저는 이런 상황에서도 반사적으로 주문 서비스 로그부터 열곤 했습니다. 그리고 몇 분을 흘려보냈습니다. 아래는 그 뒤에 순서를 바꿔 잡아 나간 과정입니다.
1단계 메트릭. 지금 어디가 아픈지부터 좁힌다
로그 검색을 접고 대시보드를 먼저 열었습니다. 메트릭은 CPU 사용량, 메모리 점유율, 호출 수처럼 일정 간격으로 시스템 상태를 숫자로 요약해 둔 데이터입니다. 마이크로서비스가 여러 개일 때 어느 지점에서 문제가 났는지 범위를 좁히는 데는 이만한 게 없습니다.
- 그때 본 것: 인프라 맵에서 주문 서비스 노드가 빨갛게 점멸하고 있었고, 에러율 그래프가 수직으로 튀어 있었습니다.
- 한 단계 더: 주문 서비스의 상세 지표를 파고들었습니다. CPU와 메모리는 의외로 여유가 있었는데, 톰캣 스레드 풀(Tomcat Thread Pool)이 가득 차 있었고 HikariCP의
Active Connection Count가 설정한 최대치에 붙어 빈자리가 없었습니다. - 여기서 좁혀진 것: 주문 서비스의 스레드들이 DB 커넥션을 잡으려고 대기에 빠졌고, 그 바람에 뒤이어 들어온 요청을 받지 못하고 있다고 판단했습니다. 조사 범위가 인프라 전체에서 "주문 서비스의 DB 커넥션 병목"으로 좁혀졌습니다. 로그부터 열었을 때와 달리, 여기까지는 클릭 몇 번이면 됩니다.
그림 2. 메트릭으로 전체를 먼저 봅니다. 복잡하게 얽힌 마이크로서비스 중 '주문 서비스의 DB 커넥션 풀 고갈'이라는 문제 지점을 먼저 찾아냅니다.
2단계 로그. 실패 원인이 적힌 문장을 확보한다
"주문 서비스가 DB 연결을 잡지 못하고 있다"는 데까지 왔으니, 이제 로그를 열 차례였습니다. 처음처럼 전체 로그를 새로고침하는 대신, 메트릭이 튀기 시작한 시간대와 주문 서비스 서버, 이 두 가지로 필터를 걸었습니다.
- 그때 본 것: 필터링한 주문 서비스 로그에 커넥션 획득 실패 예외가 밀리초 단위로 찍히고 있었습니다.
- 확정한 문장:
SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms.요청 처리 스레드가 커넥션을 달라고 풀에 요청했는데, 먼저 커넥션을 가져간 스레드들이 30초 동안 반납하지 않아 타임아웃이 난 것이었습니다. - 남은 의문: 실패 원인 문장은 확보했지만, 왜 평소 잘 반납되던 커넥션이 이번엔 계속 묶여 있는지는 로그가 답해 주지 않았습니다. 쿼리 지연인지, 코드 안 데드락인지. 로그는 개별 사건의 결과만 적기 때문에, 스레드가 왜 커넥션을 쥐고 안 놓는지 그 배후까지는 보여주지 못합니다.
15:04:22.105 [ERROR] [Tomcat-exec-42] c.w.order.OrderService - [TxID: 8a2f3b9c] 주문 생성 프로세스 진행 중 예외 발생
org.springframework.dao.DataAccessResourceFailureException: Unable to acquire JDBC Connection;
nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms.
at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:52)
at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:56)
3단계 트레이스. 진짜 진원지를 따라간다
예전 단일 애플리케이션(Monolith)이었다면 여기서 스레드 덤프를 뜨고 DB 락을 조회하며 오래 붙잡고 있었을 겁니다. 저도 그렇게 시간 보낸 적이 있습니다. 이번엔 트레이스가 있었습니다. 트레이스는 고유한 요청 ID(Trace ID)를 기준으로, 요청 하나가 게이트웨이를 넘어 주문, 결제, 쿠폰 서비스를 거쳐 가는 경로와 각 구간 소요 시간을 한 줄기로 이어 붙여 보여주는 데이터입니다.
- 그때 한 것: 커넥션 타임아웃으로 튕겨 나간 주문 요청의 Trace ID를 복사해 타임라인으로 펼쳤습니다.
- 진짜 원인: 주문 서비스 자체의 DB 인서트 쿼리와 비즈니스 로직은 0.005초 만에 끝나 있었습니다. 늘어진 건 주문 생성 로직 중간에서 할인 쿠폰(Coupon) 서비스 API를 동기(Sync)로 호출하는 구간(Span)이었습니다. 이 구간 하나가 10초 넘게 멈춰 있었습니다.
- 어떻게 커졌나: 타임세일이 시작되자 쿠폰 서비스에 트래픽이 몰려 응답이 느려졌고, 주문 서비스는 쿠폰 API 응답을 기다리는 동안 DB 커넥션을 쥔 채 대기했습니다. 앞선 스레드가 커넥션을 반납하지 않으니 뒤에 들어온 요청은 큐에 쌓였고, 그 요청들도 잇따라 타임아웃을 냈습니다. 앞이 막혀 뒤가 밀리는 이런 연쇄 포화를 리소스 고갈에 의한 연쇄 장애(cascading failure)라고 부릅니다. 이름을 알아 두면 다음에 비슷한 그래프를 볼 때 더 빨리 알아봅니다.
메트릭과 로그로는 주문 서비스가 원인처럼 보였지만, 트레이스가 보여준 진짜 원인은 쿠폰 서비스의 응답 지연이었습니다. 로그는 잘못이 없었습니다. 적힌 대로 출력했을 뿐입니다.
그림 3. 트레이스 타임라인은 주문 에러라는 표면 아래 숨어 있던 '쿠폰 서비스 호출 구간의 10초 지연'을 그대로 보여줍니다.
되짚어 보니, 순서 하나로 걸린 시간이 달라졌다
이 장애에서 세 신호는 서로 경쟁하지 않았습니다. 하나의 사건을 차례로 이어받아 좁혀 갔습니다.
- 메트릭으로 "주문 서비스의 DB 커넥션이 마비됐다"는 위치와 규모를 잡고,
- 로그로 "HikariCP 커넥션 획득 타임아웃"이라는 실패 원인 문장을 확정하고,
- 트레이스로 "쿠폰 API 지연이 주문 DB 커넥션을 붙잡고 있었다"는 진짜 진원지를 따라갔습니다.
만약 세 데이터를 서로 다른 툴에 흩어 놓고 봤다면 어땠을까요. 메트릭 차트를 보고, 시간대를 받아 적어 로그 시스템에서 검색하고, 다시 트레이스 시스템으로 옮겨 요청 ID를 넣는 동안 맥락은 끊깁니다. 저는 그렇게 조사하다 분 단위로 끝날 일을 시간 단위로 끌어 본 적이 있습니다.
메트릭 스파이크를 마우스로 긁으면 그 구간 로그로 넘어가고, 에러 로그 옆에서 바로 그 요청의 트레이스로 이어지는 환경. 세 신호가 한 화면에서 이어질 때 이 순서가 제대로 힘을 발휘합니다.
증상이 다르면 먼저 볼 신호도 다릅니다
위 사례는 에러율이 치솟은 경우였습니다. 하지만 장애 모습은 매번 다르고, 증상에 따라 가장 먼저 열어야 할 신호도 달라집니다. 제가 자주 마주친 세 가지를 정리했습니다.
- 서비스가 전반적으로 느려졌을 때: 메트릭에서 지연이 튄 시점과 엔드포인트를 먼저 잡습니다. 이어 트레이스로 느린 요청의 어느 구간(DB 쿼리, 외부 호출, 내부 연산)이 시간을 먹는지 보고, 마지막에 로그로 그 구간의 상세 원인을 확인합니다.
- 에러율이 갑자기 치솟을 때 (이번 사례): 메트릭으로 시점, 서버, 상태 코드를 잡습니다. 이어 로그로 가장 빈번한 예외의 클래스와 줄 번호를 특정하고, 필요하면 트레이스로 어느 호출이 그 에러를 촉발했는지 역추적합니다.
- 특정 사용자나 요청만 가끔 실패할 때: 전체 지표에는 잘 안 잡히니 메트릭은 건너뜁니다. 사용자 ID나 요청 ID로 트레이스를 직접 검색해 경로를 본 뒤, 해당 구간 로그로 잘못 들어온 입력값이나 조건 처리를 확인합니다.
세 흐름의 공통점은 하나입니다. 대개 메트릭이나 트레이스로 범위를 좁힌 뒤, 로그로 원인 문장을 확정합니다. 장애가 나자마자 로그창부터 여는 습관이 늘 늦는 이유가 여기 있습니다. 제가 그랬습니다.
자주 놓치는 함정
흐름을 알아도 사소한 설정 탓에 진단이 어긋납니다. 제가 실제로 놓쳤던 세 가지만 적어 둡니다.
- 평균 응답 시간만 보기: 평균은 소수의 심각한 지연을 가려 버립니다. 한동안 평균만 보다가 일부 사용자만 겪던 지연을 놓친 적이 있습니다. 대시보드 기본 화면에 p95, p99를 함께 띄워 두고부터 그런 지연을 일찍 잡습니다.
- 트레이스 샘플링에 걸리기: 비용 때문에 트레이스를 5~10%만 수집하게 걸어 두면, 정작 봐야 할 느린 요청이나 에러 요청이 표본에서 빠집니다. 저는 이걸 모르고 "왜 이 요청 트레이스가 없지"로 한동안 헤맸습니다. 에러 요청과 기준 시간(예: 1초)을 넘긴 요청은 100% 수집하는 규칙(테일 기반 샘플링)을 걸어 두는 편이 안전합니다.
- 서버 간 시간 불일치: 서비스마다 시스템 시간(NTP)이 어긋나 있으면 로그 시각과 메트릭 시각이 안 맞아 타임라인이 뒤틀립니다. 표준시로 주기적으로 동기화해 둬야 세 신호를 같은 시간축에서 겹쳐 볼 수 있습니다.
자주 묻는 질문
장애 상황에서 처음부터 트레이스만 필터링해서 보면 안 되나요?
대형 이벤트나 트래픽 폭주 때는 매초 수만 건이 몰려서 트레이스도 그만큼 쏟아집니다. 저도 급한 마음에 트레이스 리스트부터 열어 본 적이 있는데, 지금 보고 있는 요청이 흔한 정상 지연인지 전체를 무너뜨리는 병목인지 구분이 안 됐습니다. 메트릭으로 전체 상태를 먼저 보고, 로그와 트레이스로 개별 요청을 들여다보는 순서가 결국 더 빨랐습니다.
세 신호를 처음부터 다 갖춰야 하나요?
아닙니다. 서비스가 단일 애플리케이션(Monolith)이면 메트릭과 로그만으로도 대부분 진단됩니다. 서비스가 여러 개로 쪼개지고 서비스 간 원격 호출이 늘어나는 시점부터 트레이스를 더하는 걸 권합니다. 처음부터 완벽한 3종 세트를 갖추려다 지쳐 아무것도 못 보는 것보다, 지금 아키텍처에 필요한 신호부터 확실히 보는 편이 낫습니다.
세 신호가 서로 다른 도구에 흩어져 있으면 어떻게 하나요?
굳이 한 플랫폼으로 합치지 않아도 됩니다. 도구가 나뉘어 있어도 세 신호에 공통 요청 ID(Trace ID)가 심겨 있으면 같은 요청을 도구 사이로 따라갈 수 있습니다. 그래서 통합보다 먼저 할 일은 요청 ID 표준을 맞추는 것입니다. OpenTelemetry 같은 표준을 쓰면 이 ID가 신호마다 자동으로 전파됩니다. 도구 통합은 그 위에서 필요할 때 진행하면 됩니다.
마치며
돌아보면 장애 대응 속도를 좌우한 건 데이터를 여는 순서였습니다. 저는 이 순서를 익히기 전까지 로그창만 새로고침하며 시간을 보냈고, 순서를 바꾸고 나서야 조사 시간이 눈에 띄게 줄었습니다.
관건은 세 신호를 얼마나 매끄럽게 오갈 수 있느냐입니다. 요청 ID 하나로 메트릭에서 로그로, 로그에서 트레이스로 클릭 한 번에 이어질 때 이 순서가 비로소 속도를 냅니다.
세 신호를 요청 하나로 이어 한 화면에서 오가는 환경이 필요하다면, 와탭(WhaTap)에서 메트릭·로그·트레이스를 연결해 살펴볼 수 있습니다.
더 읽을거리
