GCash 支付通知延迟怎么排查?从钱包到商户服务器的回调链路分段诊断(2026)

2026-10-19 11:00:00

我在马尼拉负责一家做本地电商与游戏充值公司的支付技术,GCash 是我们单量最大的通道。今年年中有两周,客服每天都收到同一类投诉:用户在 GCash 里付完款,订单页要等很久才变成已支付。我们第一反应是通道慢,拉了网关的投递日志才发现,通知其实在支付成功后不久就发出了,时间大部分耗在我们自己这一侧:边缘的 WAF 对回调路径做了机器人挑战,网关第一次推送被挡,等它按退避重试,已经过去好几分钟。这件事之后,我们把回调链路切成段、每段打时间戳、做成常态监控,后来再遇到延迟,十分钟内就能说清是哪一段的问题。这篇文章讲的就是这套分段诊断方法。它只处理「通知来了但来晚了」;「通知根本没来」属于重试、幂等与补偿的问题,见GCash 支付 Webhook 重试机制怎么设计,本文不展开。

先分清「晚了」和「丢了」,再决定查什么

延迟和丢失在表面上很像:用户都在等。但两者的排查路径完全不同。判断标准只有一条:在网关投递记录或你的接收日志里,这条通知最终是否出现过。出现过,且出现时间明显晚于支付成功时间,这是延迟;一直没出现,而主动查询显示支付已成功,这是丢失。还有第三种容易被混淆的情况:通知按时到了,但订单状态更新得晚,用户看到的仍然是「等待支付」。这是应用内部的问题,和网络无关,却经常被归咎于通道。

所以排查第一步不是看网络,而是把三个时间点并排放在一起:支付成功时间、通知到达时间、订单状态更新时间。三个时间点一摆出来,问题在前半段还是后半段就清楚了。前半段(支付成功到通知到达)涉及钱包、网关与你的网络边缘;后半段(通知到达到订单更新)完全在你的应用里。本文的分段方法就是在这个基础上继续细分。

另一个前提是「晚」要有基准。不同通道、不同时段的正常延迟量级不一样,没有历史分位数据,就说不清今天是不是真的变慢了。如果你还没有记录过每笔通知的各段耗时,先按下文的方式把时间戳埋进去,跑一到两周,再来定义什么叫异常。

把回调链路切成六段

一笔 GCash 支付从用户确认到你的订单变成已支付,大致经过下面六段。每一段都有自己的时间戳来源,这是分段诊断的基础。

第一段:付款人 App 到 GCash 侧完成扣款。用户网络、OTP、钱包余额校验都在这里。时间戳来源是 GCash 侧的交易时间,通常会出现在通知报文和查询接口的返回里。
第二段:GCash 到网关或服务商。网关收到上游结果、生成面向商户的通知。时间戳来源是网关投递日志里的「通知生成时间」或「首次发送时间」。
第三段:网关到你的网络边缘。包括 DNS 解析、TCP 建连、TLS 握手、防火墙与 WAF 的放行、负载均衡转发、CDN 或反向代理的缓冲。时间戳来源是边缘(Nginx、负载均衡)的 access log。
第四段:边缘到应用处理函数。请求在代理与应用之间排队、worker 池是否有空闲、应用进程是否在 GC 或冷启动。时间戳来源是应用进入处理函数的那一刻。
第五段:处理函数内部。验签、落盘、更新订单、调用下游(ERP、短信、发货)。时间戳来源是处理完成时间。
第六段:订单状态对用户可见。缓存刷新、前端轮询周期、消息推送。时间戳来源是订单表的更新时间与前端拉取时间。

六段里,第一、二段在你的控制之外,但可以用网关的投递记录和查询接口做证据;第三段是网络边缘,最容易被忽略也最容易出问题;第四到六段全在你的代码与基础设施里。网关的基本回调设计(触发时机、验签、应答)在GCash 商户回调怎么做里讲过,这里默认你已经有一个能正常工作的回调端点。

做分段诊断的一个前提,是你的服务商能提供逐条的投递记录(发送时间、每次尝试的响应码与耗时)和可随时调用的交易状态查询接口。持有 BSP OPS/EMI 资质的持牌支付机构通常把这两样作为商户后台的标准能力;没有投递记录,第二、三段的边界就无从判断,只能靠猜。

时间戳从哪里取:时钟不对齐,所有结论都是错的

分段诊断的全部依据是时间差,所以时间戳本身必须可信。我们踩过的第一个坑是时区:网关日志用马尼拉时间,我们的服务器用 UTC,数据库字段没带时区,算出来的「延迟」相差整整八小时。第二个坑是时钟漂移:一台实例的 NTP 服务停了,慢了十几秒,这台实例处理的通知在报表里全部显示「负延迟」。所以在埋时间戳之前先做三件事:所有服务器启用 NTP 并监控偏移;所有时间统一用带时区偏移的 ISO 8601 格式存储;网关侧时间与本地时间做一次人工校准,确认口径一致。

具体要采集的时间点和来源如下:

paid_at:GCash 侧交易成功时间,取自通知报文或查询接口返回;
sent_at:网关首次发送通知的时间,取自网关投递日志或通知报文里的通知时间字段;
edge_at:你的边缘收到请求的时间,取自 Nginx 的 msec 变量或负载均衡日志,并通过请求头透传给应用;
received_at:应用进入处理函数的时间;
handled_at:订单更新完成的时间;
visible_at:前端拿到新状态的时间,只在排查第六段时需要。

相邻两个时间点之差就是对应段的耗时:sent_at - paid_at 是上游段,edge_at - sent_at 是网络边缘段,received_at - edge_at 是代理到应用的排队段,handled_at - received_at 是处理段。把这几个差值连同事件 ID 一起存进 webhook 事件表,后面的监控和复盘都靠它。

网络边缘段怎么测:DNS、TLS、白名单与代理缓冲

第三段是最容易出问题却最少被埋点的一段,因为请求还没进应用,应用日志里什么都没有。它的典型故障有五类。

DNS。回调域名刚换过解析、TTL 设得很长,或者权威 DNS 响应慢,网关侧的解析器就可能拿到旧地址或等待超时。用 dig 从多个外部位置查询回调域名,看返回地址与查询耗时是否一致。

TLS。证书链不完整、中间证书缺失、只支持过旧的协议版本,都会让握手变慢甚至失败后重试。用 openssl 的 s_client 从外部连一次,看握手是否一次完成、链是否齐全。

防火墙与 WAF。这是我们当时的病因。网关的出口 IP 变更后白名单没更新,或者 WAF 对回调路径启用了机器人挑战、速率限制,请求会被拦下或返回挑战页面。网关看到的是非成功响应,于是按退避重试,表面现象就是「通知晚了几分钟」。处置是把回调路径加入 WAF 例外,白名单改为按网关公布的地址段定期核对。

负载均衡与健康检查。某台实例被判定不健康时,连接会被转到其他实例,期间请求可能排队;实例滚动发布时的连接排空也会拉长响应。看负载均衡的按实例日志就能定位。

CDN 与反向代理。回调路径走 CDN 没有必要,反而引入缓冲与额外跳数;反向代理的读超时、请求体缓冲、与上游的 keepalive 配置,都可能让一个本来很快的请求多等一轮。

测这一段最直接的办法,是从一台外部主机(最好和网关在同一地区,比如马尼拉或新加坡的云主机)对回调地址做分段计时。curl 自带的 write-out 模板可以输出 time_namelookup、time_connect、time_appconnect、time_starttransfer、time_total 这几个变量,分别对应 DNS、TCP、TLS、首字节与总耗时;如果你想把探测做成定时任务并写入监控,用 Node 监听 socket 事件更方便:

// probe-callback.js:从外部主机对回调地址做分段计时(DNS / TCP / TLS / 首字节 / 完成)
const https = require('https');
const { performance } = require('perf_hooks');

function probe(url) {
  const t = { start: performance.now() };
  const req = https.request(url, { method: 'POST', headers: { 'Content-Type': 'application/json' } }, (res) => {
    t.firstByte = performance.now();
    res.on('data', () => {});
    res.on('end', () => {
      t.end = performance.now();
      console.log(JSON.stringify({
        status: res.statusCode,
        dns_ms: Math.round(t.lookup - t.start),
        tcp_ms: Math.round(t.connect - t.lookup),
        tls_ms: Math.round(t.secure - t.connect),
        wait_ms: Math.round(t.firstByte - t.secure),   // 服务器从收到请求到吐出首字节,主要是代理排队与应用处理
        total_ms: Math.round(t.end - t.start)
      }));
    });
  });
  req.on('socket', (s) => {
    s.on('lookup', () => { t.lookup = performance.now(); });
    s.on('connect', () => { t.connect = performance.now(); });
    s.on('secureConnect', () => { t.secure = performance.now(); });
  });
  req.on('error', (e) => console.error('probe error:', e.message));
  req.end(JSON.stringify({ probe: true, ts: new Date().toISOString() }));
}

probe('https://pay.example.com/callbacks/gcash');

探测请求会因为没有合法签名被你的端点拒绝,但这不影响计时:DNS、TCP、TLS 与首字节的耗时在拒绝之前就已经发生。也可以在同一主机、同一 WAF 规则下单独开一个探测路径,只做验签和落盘、不做业务处理,这样 wait_ms 直接反映第四、五段的开销。探测频率按分钟级设置,把结果写入你的监控系统,延迟一上升就能看到是哪个分量在涨。

应用段怎么测:先落盘再应答,把处理时间从响应时间里剥离

第四、五段的问题几乎都源于一个设计:在应答网关之前做了太多事。验签之后同步调用 ERP、发短信、写三张表、再更新缓存,任何一个下游慢,网关看到的响应时间就跟着慢,超过它的等待阈值就会被判为失败并重试。结果是同一条通知来两次、三次,每次都慢,而真正的原因是你的处理函数在等别人。

正确的顺序是:验签、把原始报文连同 received_at 写进事件表、立即应答、把处理交给队列。这样网关看到的响应时间只包含验签与一次写入,处理耗时单独记录在 handled_at 里,两者不再互相污染。Webhook 重试机制那篇讲过这个顺序对防丢单的意义,这里强调它对计时的意义:只有把应答和处理拆开,第四段与第五段的耗时才能分别测量。

// callback-handler.js:先记录 received_at 并落盘,立即应答,处理放到队列;每一步都带时间戳
// Nginx 转发时加一行:proxy_set_header X-Request-Start "t=${msec}";  边缘接收时间就能透传进来
const express = require('express');
const app = express();
app.use(express.json({ limit: '256kb' }));

app.post('/callbacks/gcash', async (req, res) => {
  const receivedAt = new Date();                       // T_app_received
  const edgeAt = req.get('X-Request-Start');           // 边缘接收时间(由 Nginx 注入)
  const body = req.body;
  if (!verifySignature(req)) {
    return res.status(401).json({ ok: false });
  }
  await db.run(
    'INSERT INTO webhook_events (event_id, order_no, paid_at, sent_at, edge_at, received_at, payload) VALUES (?,?,?,?,?,?,?) ON CONFLICT (event_id) DO NOTHING',
    [body.event_id, body.order_no, body.paid_time, body.notify_time, edgeAt, receivedAt.toISOString(), JSON.stringify(body)]
  );
  res.status(200).json({ ok: true });                  // 先应答,处理时间不计入网关看到的响应时间
  queue.push({ eventId: body.event_id });              // 异步处理
});

// worker 侧:处理完成后回写 handled_at,并算出各段耗时
async function handle(eventId) {
  const ev = await db.get('SELECT * FROM webhook_events WHERE event_id = ?', [eventId]);
  await updateOrder(ev);                                // 更新订单、触发发货(幂等)
  const handledAt = new Date();
  const ms = (a, b) => (new Date(b) - new Date(a));
  await db.run(
    'UPDATE webhook_events SET handled_at = ?, lag_upstream_ms = ?, lag_edge_ms = ?, lag_app_ms = ?, lag_handle_ms = ? WHERE event_id = ?',
    [handledAt.toISOString(), ms(ev.paid_at, ev.sent_at), ms(ev.sent_at, ev.edge_at), ms(ev.edge_at, ev.received_at), ms(ev.received_at, handledAt), eventId]
  );
}

有了这张事件表,排查就变成一条 SQL:按小时统计四个 lag 字段的分位数,哪一段突然变宽,问题就在哪一段。第四、五段常见的慢因有:处理函数里有同步的外部调用;订单表上的行锁被前端轮询或其他写入占着;队列只有一个消费者,促销高峰时积压;Serverless 冷启动;数据库连接池耗尽。这些在事件表的 lag_app_ms 与 lag_handle_ms 上会有不同的形状,结合应用的慢查询日志与队列深度指标就能区分。错误码层面的排查思路在GCash 支付对接常见错误码里有汇总。

诊断表:现象、最可能的段、验证方法与处置

下面这张表的用法是从「现象」一列找最接近的描述,先验证对应的段,验证不成立再往相邻段走。多数情况下一两轮就能定位。

现象	最可能的段	验证方法	处置
所有通知整体变慢,主动查询显示支付早已成功	第二、三段(网关到边缘)	比对网关投递日志的 sent_at 与边缘 access log 的接收时间	差值出现在 sent_at 之前找服务商,之后查边缘
网关投递记录显示同一通知多次尝试,首次尝试响应码非成功或超时	第三段(WAF、白名单、代理超时)	查 WAF 日志与白名单;外部探测看首字节耗时	回调路径加入 WAF 例外,核对网关出口地址段,放宽代理读超时
只在促销高峰变慢,平时正常	第四、五段(队列积压、数据库锁)	看队列深度、慢查询日志、lag_handle_ms 分位数	增加消费者,拆分订单行锁,下游调用异步化
只有某台实例的通知慢	第三、四段(负载均衡、实例健康)	负载均衡按实例日志;对比各实例 NTP 偏移	剔除或重启该实例,修复时钟同步
更换域名或证书之后开始变慢	第三段(DNS、TLS)	多地 dig 查询耗时与返回地址;openssl 检查证书链	缩短切换期 TTL,补齐中间证书
通知按时到达,订单状态却晚	第五、六段(下游调用、缓存、前端轮询)	比对 received_at、handled_at 与订单 updated_at	下游异步化,缩短前端轮询周期或改为推送
用户说付了很久才显示,但各段耗时都正常	第一段(用户侧、钱包侧)	比对 paid_at 与用户描述的操作时间	页面提示用户等待,主动查询兜底,不在商户侧做无效优化

如果想按「原因」而不是「现象」入手,下面这张对比表列出了我们实际遇到过的慢因、它们在哪一段、典型信号与自查手段。

原因	所在段	典型信号	自查手段
DNS 解析慢或指向旧地址	第三段	dns_ms 偏高,或不同地区解析结果不一致	dig 多地查询,核对 TTL
证书链不完整	第三段	tls_ms 偏高,部分客户端握手失败	openssl s_client 查看链
WAF 挑战或速率限制	第三段	首次尝试返回挑战页或限流响应,随后重试成功	WAF 日志按路径过滤
白名单未更新	第三段	某个时间点后所有首次尝试被拒	核对网关公布的出口地址段
代理缓冲与读超时	第三、四段	wait_ms 高,但 received_at 与 handled_at 间隔短	查代理超时与缓冲配置
处理函数同步调用下游	第五段	lag_handle_ms 随下游服务波动	链路追踪看下游耗时
订单行锁争用	第五段	高峰期 lag_handle_ms 分布出现长尾	数据库锁等待统计
队列消费者不足	第四、五段	队列深度与 lag_app_ms 同步上升	队列监控
服务器时钟漂移	所有段	出现负耗时或单实例异常	NTP 偏移监控

从一次排查到常态监控

排查一次只能解决一次。把分段耗时做成常态监控之后,延迟会在用户投诉之前被发现。我们现在固定做四件事:事件表里的四个 lag 字段按小时聚合出分位数并画成图;对每个分量设告警阈值,阈值取自前两周的基线而不是拍脑袋;外部探测每分钟跑一次,DNS、TLS、首字节分开告警;每周把网关投递记录导出一份,与事件表对一遍,确认 sent_at 口径没有漂移。

监控之外还有两道兜底。一是主动查询:无论通知快慢,对超过基线仍未收到通知的订单,按固定间隔调用网关的交易状态查询,查到成功就先推进订单,通知后到时按幂等处理;二是对账:日终把网关交易明细与本地订单表核对,延迟或丢失的通知在这里会被最终发现,方法见GCash 商户对账怎么做。如果你的业务对延迟特别敏感,比如游戏充值,还可以把回调端点与主动查询部署在不同的可用区,这属于支付系统灾备与高可用的范畴。

通知延迟的排查质量,很大程度上取决于服务商愿意给你多少可观测性。SMARTPAY 作为持有 BSP OPS/EMI 资质的持牌支付机构,在商户后台提供逐条投递记录、每次尝试的响应码与耗时,以及交易状态查询接口;本文的分段方法可以直接套用在这些数据上。

常见问题

通知延迟到底是 GCash 的问题还是我们的问题,怎么证明?

看两个时间差:paid_at 到 sent_at 是钱包与网关一侧,sent_at 到 edge_at 之后都是你这一侧。前者大,把事件 ID 与时间点交给服务商查;后者大,按本文的段往下找。没有 sent_at 就无法划清责任,所以先确认服务商能提供投递记录。

网关投递日志显示已发送成功,但我们的 access log 里没有同一时间的记录,怎么回事?

三种可能:时钟或时区不一致,按本文校准后再比;请求在 CDN 或 WAF 层被吸收,没有到达源站的 access log,去那一层的日志找;负载均衡把请求转到了你没查的那台实例。按这个顺序排除。

回调地址要不要走 CDN?

不建议。回调是服务器到服务器的少量请求,CDN 的缓存与加速对它没有价值,反而增加一跳、带来缓冲与规则差异。把回调域名直接解析到负载均衡或源站,WAF 规则单独为回调路径配置。

服务器之间时钟差几秒要紧吗?

要紧。分段耗时本来就在秒级甚至亚秒级,几秒的偏移足以让结论反转,还会让部分事件出现负耗时。所有参与计时的机器都要启用 NTP 并监控偏移,偏移超过阈值就告警。

回调处理函数应该多快应答?

以服务商文档里的等待阈值为上限,目标是只做验签与一次写入后立即应答,把其余处理全部放到队列。这样应答时间稳定在亚秒级,不随下游波动,网关也不会因超时而重试。

延迟期间用户催发货,能不能按主动查询的结果先发?

可以,前提是主动查询返回的是网关或钱包的终态「成功」,并且你的订单更新逻辑是幂等的:通知后到时发现订单已是已支付,直接忽略即可。主动查询本来就是通知的兜底。

用了聚合网关,还需要自己做这些测量吗?

需要。网关能替你处理与钱包之间的第一、二段,但第三段起的边缘与应用都在你这里,网关看不到。网关提供的投递记录是你划定责任边界的证据,本地的事件表与探测是你定位自身问题的工具,两者缺一不可。

促销期间延迟变大,直接扩容就能解决吗?

不一定。先看事件表里是哪一段变宽:队列积压扩消费者有效,数据库锁争用要改写法,WAF 限流要改规则,后两种扩容都解决不了。先定位再扩容,否则钱花了问题还在。

写在最后

通知延迟的排查没有魔法,就是把链路切开、每段打时间戳、用数据说话。做到这一步之后,「是不是 GCash 慢了」这种争论基本就消失了,取而代之的是一张图上哪个分量在涨。如果你正在接入 GCash,或者想看看持牌网关的投递记录与查询接口长什么样,欢迎通过 Telegram 联系@LouisSMARTPAY,或邮件联系[email protected]。