一次真实的 API 排障实录：从乱码 JSON 到根因定位

故事的开端，跟所有这类故事一样——一条几乎没什么信息量的 Slack 消息。

“嗨，订单同步好像挂了。最近一小时下的单都没出现。”

没有 stack trace，没有错误码，连”挂在哪一段”都不告诉你。就这么一句：订单没出现。

下面是几次真实排障经历的合成版——化名、简化业务背景，但流程和工具都来自实战。跟我走一遍。

第 1 步：先把”挂了”翻译成可定位的描述

大多数开发者的第一反应是冲进代码。打住。第一反应应该是搞清楚问题在管道的哪一段。

涉事系统有三段：

外部支付方往我们的 endpoint 推订单 webhook
后端处理 webhook，写入数据库
前端 dashboard 从数据库读取并展示订单

“没出现”可能意味着：webhook 根本没收到、收到了但悄悄失败、写入了但写错了、写对了但显示出错。这是四种完全不同的 bug，对应四种完全不同的修复。

从最前端开始查。先翻相关时间窗内的入站 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 了，endpoint 返回 200。看上去都正常——可订单就是不在数据库里。问题落在第 2 步：webhook 收到了，但处理过程悄悄失败了。

200 是在处理完成之前就返回的。经典操作。先 ack 再干活的 webhook handler，在支付方眼里你永远是健康的，他们的重试机制不会触发；与此同时你给自己留了一个完美的”静默失败”模式。

第 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 没法读。第一件事永远是丢进 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），跟 item 价格自洽（4999 = $49.99，1299 = $12.99，2×4999+1299 = 11297）。OK。
customer 里多了个 metadata 字段。值得记一笔——这是个非标准结构，schema 校验环节有可能因此卡住。

第 3 步：检查 auth token

webhook handler 会验证 Authorization 头，确认 payload 来自支付方。从日志里抓出 auth header：

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"
  }
}

token 合法，issuer 正确，audience 是 api.ourapp.com。exp: 1705332795——签发后 60 秒过期。webhook 在 1705332738 收到，token 在 1705332735 签发。仅 3 秒，妥妥在窗口内。

token 验证不是问题。

第 4 步：对比 handler 期待的 vs. 实际收到的

到这里基本能确定问题出在处理逻辑。该把 handler 期待的样子和实际收到的样子摆一起看了。

先把 handler 用来校验的 JSON Schema 拉出来：

{
  "$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
        }
      }
    }
  }
}

罪魁祸首找到了。schema 里 customer 对象写着 "additionalProperties": false，而实际 payload 的 customer 上多了个 metadata。schema 校验在拒绝 payload——而错误被 webhook handler 静默吞掉了，没有抛上来。

把实际 payload 配上这份 schema 跑一遍 JSON Schema 验证器确认了猜测：Additional properties are not allowed ('metadata' was unexpected)。

两个 bug 同框：

支付方更新了 webhook 格式、塞进了 customer metadata，没人同步更新 schema
校验错误被 catch 之后默默丢弃了，连日志都没记

第 5 步：用 diff 坐实”格式确实变了”

为了确认这是新出现的变化、不是历史遗留，把当前 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：修 schema。 把 customer 对象上的 "additionalProperties": false 去掉，或者把 metadata 显式声明为可选属性。前者更省事，对未来供应商的字段变更也更鲁棒。

Part 2：修错误处理。 webhook handler 的 catch 块把日志塞进了一个没人盯着的 metrics sink。改写到应用日志里，并且对处理错误超阈值时配一条告警。

修复花了大约 20 分钟写加测。排查花了大约 45 分钟。对一个完全没有错误信息的静默失败来说，这个比例算很不错了。

工具箱省下了多少时间

把浏览器小工具帮我提速的环节标一下：

步骤	用到的工具	节省时间
读 payload	JSON 格式化	比手工解析省 ~8 分钟
验证时间戳	时间戳转换器	比写转换代码省 ~2 分钟
检查 auth token	JWT 解码器	比 base64 + 手动解析省 ~5 分钟
用 schema 校验 payload	JSON Schema 验证器	比写一段测试脚本省 ~10 分钟
确认 schema 变化	文本对比	比肉眼对比省 ~5 分钟

总计：在一次 45 分钟的排障里，工具加速了大约 30 分钟。剩下的部分——读日志、形成假设、写修复代码——没法自动化。但结构化数据的检查环节可以。

永远适用的那个套路

回头看这次排障，可以抽出一套通用模式：

先定位管道阶段。 别拍脑袋猜问题在哪。从入口往下，一段一段排除。
读真实数据。 别凭印象推测数据”应该长什么样”。把真实 payload 取出来，配合好工具去读。
检查 auth。 大量”处理失败”其实是 auth 失败被吞了。在 debug 业务逻辑前，先验 token。
拿 schema 跑一遍。 如果 handler 会校验入参，就用真实输入跑一次真实 schema，别靠肉眼。
跟已知正常的版本 diff。 怀疑某处变了的时候，用 diff 证明，别靠记忆和甩锅。

这个序列适用于绝大多数 API 排障。payload 格式和 auth 机制会变，工具会换，思维模型不变。

这次的静默失败之所以特别恼人，就在于 endpoint 返回了 200——从外面看一切正常。集成外部 webhook 的时候，错误处理一定要发声音。集成里的静默失败浮出水面慢，排障成本高。

真要 debug 它们的时候——先格式化 payload。无一例外。