이런 일은 늘 그렇듯, 거의 쓸모없는 Slack 메시지 한 줄로 시작됐다.

“저기, 주문 동기화가 깨진 것 같아요. 최근 한 시간에 들어온 주문이 안 보여요.”

스택 트레이스도 없고, 에러 코드도 없고, 인바운드인지 아웃바운드인지 그 사이 어딘가인지도 모른다. 그저 한 줄, 주문이 안 보인다.

아래는 여러 실제 디버깅 세션을 합성한 이야기다 — 이름은 바꿨고 도메인도 단순화했다. 다만 워크플로와 도구는 진짜다. 같이 따라가 보자.


1단계: “깨졌다”의 정확한 의미를 정의한다

대부분 개발자의 첫 충동은 코드로 직행하는 것이다. 멈춰라. 첫 충동은 파이프라인의 어디에서 문제가 생겼는지부터 좁히는 것이어야 한다.

문제의 시스템은 세 단계로 구성되어 있었다:

  1. 외부 결제 제공자가 주문 webhook을 우리 엔드포인트로 POST한다
  2. 백엔드가 webhook을 처리하고 DB에 기록한다
  3. 프론트엔드 대시보드가 DB에서 읽어 주문을 표시한다

“안 보인다”는 네 가지를 의미할 수 있다: webhook이 도달하지 않았다, 도달했지만 조용히 실패했다, 처리됐지만 잘못 기록됐다, 올바르게 기록됐지만 잘못 표시됐다. 이 네 가지는 완전히 다른 버그이고, 완전히 다른 수정이 필요하다.

처음부터 시작한다. 해당 시간 윈도우의 인바운드 webhook 로그부터 본다.

[2024-01-15 14:32:18] POST /webhooks/orders — 200 OK — 23ms
[2024-01-15 14:33:45] POST /webhooks/orders — 200 OK — 18ms
[2024-01-15 14:34:02] POST /webhooks/orders — 200 OK — 31ms

세 건의 webhook이 수신되어 ack까지 됐다. 엔드포인트는 200을 반환했다. 표면적으로는 문제없다 — 다만 주문은 DB에 없다. 문제는 2단계다: webhook은 받았지만 처리 과정이 조용히 실패했다.

200은 처리가 완료되기 전에 반환됐다. 전형적인 패턴이다. 본처리에 들어가기 전에 ack부터 보내는 webhook 핸들러는 결제 제공자의 시야에서 항상 정상으로 보인다. 그쪽의 재시도 문제는 해결해 주는 대신, 자기 쪽에 완벽한 사일런트 실패 모드를 만들어 둔 셈이다.


2단계: 실제 payload를 읽는다

다음 질문은 이거다: 그 webhook 안에 뭐가 들어 있었나? 로그 스토리지에서 한 건 끄집어낸다.

원본 payload (살짝 단순화):

{"event":"order.completed","data":{"id":"ord_8842","customer":{"id":"cus_2291","email":"[email protected]","metadata":{"tier":"premium","signup_source":"organic","feature_flags":{"beta_checkout":true,"legacy_discount":false}}},"items":[{"sku":"PRD-001","qty":2,"price":4999},{"sku":"PRD-007","qty":1,"price":1299}],"total":11297,"currency":"USD","created_at":1705332738,"payment_intent":"pi_3OT4h2LkZbh90","status":"paid","shipping":{"method":"express","address":{"line1":"123 Main St","city":"Portland","state":"OR","zip":"97201","country":"US"}}}}

한 줄로는 읽을 수 없다. 첫 번째로 할 일은 언제나 같다 — JSON 포매터에 넣는다. 정리하면:

{
  "event": "order.completed",
  "data": {
    "id": "ord_8842",
    "customer": {
      "id": "cus_2291",
      "email": "[email protected]",
      "metadata": {
        "tier": "premium",
        "signup_source": "organic",
        "feature_flags": {
          "beta_checkout": true,
          "legacy_discount": false
        }
      }
    },
    "items": [
      { "sku": "PRD-001", "qty": 2, "price": 4999 },
      { "sku": "PRD-007", "qty": 1, "price": 1299 }
    ],
    "total": 11297,
    "currency": "USD",
    "created_at": 1705332738,
    "payment_intent": "pi_3OT4h2LkZbh90",
    "status": "paid",
    "shipping": {
      "method": "express",
      "address": {
        "line1": "123 Main St",
        "city": "Portland",
        "state": "OR",
        "zip": "97201",
        "country": "US"
      }
    }
  }
}

이제 비로소 머리가 돌아간다. 곧바로 눈에 띄는 것들:

  • created_at은 Unix 타임스탬프(1705332738)다. 예상대로지만 확인은 해 본다. 타임스탬프 변환기에 붙여 넣는다: Jan 15, 2024, 14:32:18 UTC. 로그 시각과 일치. OK.
  • total은 센트 단위(11297 = $112.97)고, 아이템 가격과 일관됨(4999 = $49.99, 1299 = $12.99, 2×4999+1299 = 11297). OK.
  • customer 안에 metadata 필드가 있다. 메모해 둘 만하다 — 비표준 구조라서 스키마 검증 단계에서 막힐 가능성이 있다.

3단계: 인증 토큰을 확인한다

webhook 핸들러는 결제 제공자에게서 온 payload임을 Authorization 헤더로 확인한다. 로그에서 auth 헤더를 뽑는다:

Authorization: Bearer eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCJ9.eyJzdWIiOiJ3aH...

JWT 디코더에 붙여 넣는다:

{
  "header": {
    "alg": "RS256",
    "typ": "JWT"
  },
  "payload": {
    "sub": "webhook_processor",
    "iss": "payments.provider.com",
    "aud": "api.ourapp.com",
    "iat": 1705332735,
    "exp": 1705332795,
    "scope": "webhook:orders"
  }
}

토큰은 유효하다. issuer도 맞다. audience는 api.ourapp.com. exp: 1705332795 — 발급 60초 후 만료. webhook 수신은 1705332738, 토큰 발급은 1705332735. 3초 차이로 윈도우 안에 충분히 들어온다.

토큰 인증은 범인이 아니다.


4단계: 핸들러가 기대한 것과 실제 받은 것을 비교한다

여기쯤이면 문제가 처리 로직에 있다는 게 거의 확실해진다. 핸들러가 기대한 형태와 실제로 받은 형태를 나란히 놓을 차례다.

핸들러가 검증에 쓰는 JSON 스키마를 꺼낸다:

{
  "$schema": "http://json-schema.org/draft-07/schema",
  "type": "object",
  "required": ["event", "data"],
  "properties": {
    "event": { "type": "string" },
    "data": {
      "type": "object",
      "required": ["id", "customer", "items", "total", "status"],
      "properties": {
        "customer": {
          "type": "object",
          "required": ["id", "email"],
          "additionalProperties": false
        }
      }
    }
  }
}

찾았다. 스키마의 customer 객체에 "additionalProperties": false가 박혀 있다. 실제 payload의 customer에는 metadata 필드가 붙어 있다. 스키마 검증이 payload를 거부하고 있다 — 그런데 그 에러가 webhook 핸들러 안에서 묻혀 버려 표면으로 올라오지 않았다.

실제 payload를 이 스키마와 함께 JSON Schema 유효성 검사기에 돌려 확인: Additional properties are not allowed ('metadata' was unexpected).

버그는 두 개가 겹쳐 있었다:

  1. 결제 제공자가 webhook 포맷을 업데이트하면서 customer metadata를 추가했는데, 아무도 스키마를 갱신하지 않았다
  2. 검증 에러가 catch에서 잡힌 뒤 로그도 없이 조용히 버려졌다

5단계: diff로 스키마 변경을 입증한다

이게 기존 이슈가 아니라 최근의 변경이라는 걸 확실히 하기 위해, 현재 webhook payload를 지난주의 payload(아직 로그 스토리지에 있음)와 비교한다.

지난주의 customer 객체:

{
  "id": "cus_1987",
  "email": "[email protected]"
}

오늘의 customer 객체:

{
  "id": "cus_2291",
  "email": "[email protected]",
  "metadata": {
    "tier": "premium",
    "signup_source": "organic",
    "feature_flags": {
      "beta_checkout": true,
      "legacy_discount": false
    }
  }
}

텍스트 차이 비교기에 던진다. diff는 명백하다 — metadata는 신규 추가다. 결제 제공자가 버전 번호도 올리지 않고, 통합 측에 통보도 없이 필드를 추가했다. (프로덕션 통합에서 인정하기 싫을 만큼 자주 일어난다.)


6단계: 수정

두 단계 수정:

Part 1: 스키마 수정. customer 객체에서 "additionalProperties": false를 빼거나, metadata를 명시적으로 허용된 선택 속성으로 추가한다. 전자가 더 단순하고 향후 제공자 변경에도 더 견고하다.

Part 2: 에러 처리 수정. webhook 핸들러의 catch 블록은 아무도 감시하지 않는 metrics sink로 로그를 보내고 있었다. 애플리케이션 로그로 옮기고, 처리 에러가 임계치를 넘으면 알림이 발사되도록 트리거를 추가한다.

수정은 작성과 테스트까지 약 20분. 디버깅은 약 45분. 에러 메시지 하나 없는 사일런트 실패치고는 꽤 괜찮은 비율이다.


도구함이 기여한 부분

브라우저 도구가 이 세션을 얼마나 줄여 줬는지 표로 정리한다:

단계사용한 도구절약 시간
payload 읽기JSON 포매터수동 파싱 대비 ~8분
타임스탬프 검증타임스탬프 변환기변환 코드 작성 대비 ~2분
인증 토큰 검사JWT 디코더base64 디코딩+파싱 대비 ~5분
스키마 검증JSON Schema 유효성 검사기테스트 스크립트 작성 대비 ~10분
스키마 변경 확인텍스트 차이 비교기육안 비교 대비 ~5분

총합: 45분짜리 디버깅 세션 중 약 30분이 도구 가속분. 자동화할 수 없는 부분 — 로그 읽기, 가설 세우기, 수정 작성 — 은 그대로 남는다. 구조화된 데이터 검사는 자동화가 가능하다.


언제나 통하는 패턴

이번 세션을 되짚어 보면, 일반화할 수 있는 패턴이 보인다:

  1. 파이프라인 단계를 먼저 좁힌다. 어디가 문제인지 가정하지 마라. 진입점부터 차례차례 단계를 제거해 나간다.

  2. 실제 데이터를 읽는다. 데이터가 “이래야 한다”는 추론에 의존하지 마라. 실제 payload를 가져와 적절한 도구로 읽어라.

  3. 인증을 점검한다. “처리 실패”로 분류된 것 중 의외로 많은 비율이 묻혀 버린 인증 실패다. 로직을 디버깅하기 전에 토큰부터 확인하라.

  4. 스키마로 검증한다. 핸들러가 입력을 검증한다면, 실제 입력을 실제 스키마에 맞춰 돌려 봐라. 눈으로만 보지 마라.

  5. 알려진 정상본과 diff를 떠라. 뭔가 바뀌었다고 의심된다면, 기억이나 책임 추궁에 의존하지 말고 diff로 증명하라.

이 시퀀스는 대부분의 API 디버깅에 적용된다. payload 포맷과 인증 메커니즘이 바뀌면 도구도 바뀐다. 멘탈 모델은 그대로다.

이번 사일런트 실패가 특히 짜증났던 건 200이 반환됐다는 점이다 — 바깥에서 보면 모든 게 멀쩡해 보였다. 외부 webhook과 통합할 때는 에러 처리가 시끄럽게 굴도록 만들어라. 통합의 사일런트 실패는 표면화가 느리고 디버깅 비용이 비싸다.

그리고 실제로 디버깅할 때는 — payload를 먼저 포맷해라. 언제나.