TT Lab
博客 开始
学习 学习路径 课程

故障指挥与复盘

同样的 5xx,不同的元凶——对齐时钟,建立时间线

在 TT Lab 中继续学习

目标

把时区和时钟各不相同的记录(两份服务器日志、负载均衡器样本、git 部署记录、开关记录、告警和指标)对齐到同一个基准时钟, 建立时间线,并用数据确定首个错误、嫌疑变更、检测延迟和缓解时刻。最后,把同一症状的三个服务 按原因区分,只回滚该回滚的。

为什么重要

复盘的时间线错了,建立在其上的原因和措施就全错了。而让时间线出错的,通常不是什么大 失误,而是一个时区标记、一个偏差了几分钟的时钟。事故进行中,同样的错觉会导致“全部回滚”的决定 ——回滚无辜的变更等于又做了一次新的变更,而真正的原因依然存在。

步骤

  1. 用 python3 /opt/fixtures/ic/ickit.py open timeline 展开素材,阅读 /root/ic/timeline/README.txt。把 web-1.log 和 web-2.log 中状态码为 5xx 的行数相加,以一个数字写入 /root/ic/timeline/answers/errors.txt。
  2. 把 deploys.log(git log)中的部署和 flags.log 中的开关变更全部换算成 UTC,按从旧到新的顺序,每行一条 <utc-time>\t<change-id> 写入 /root/ic/timeline/answers/changes.tsv。时刻为 2026-11-04T05:12:03Z 形式;变更 id 对部署是提交 sha 的前 7 个字符,对开关是 flag:<name>。
  3. 把 lb-sample.log(基准时钟)与两份服务器日志中以同一 req id 记录的请求配对,为每台服务器以整数秒测量 server_time − reference_time,以 web-1=<seconds>、web-2=<seconds> 两行写入 /root/ic/timeline/answers/skew.txt(时钟快的为 +,慢的为 −)。
  4. 减去上一步的偏差,把两台服务器的 5xx 对齐到基准时钟,把最早一条的时刻(UTC,精确到秒)和服务器以 first_error_utc=<time>、host=<server> 两行写入 /root/ic/timeline/answers/first-error.txt。
  5. 把基准时钟下首个错误之前 30 分钟内(含首个错误时刻)进入的变更 id,每行一个写入 /root/ic/timeline/answers/suspects.txt。
  6. 把从基准时钟的首个错误到这起事故的告警(alerts.csv 中 api-5xx-rate 的 fired)所花的秒数,以及 README 中定义的缓解时刻(分钟的开始,UTC),以 detect_delay_sec=<seconds>、mitigated_utc=<time> 两行写入 /root/ic/timeline/answers/phases.txt。
  7. 运行 incident ic-error-spike 会触发故障事件。cart、search、pay 三个服务今天依次部署,三者从那时起都持续出现 5xx(记录:/srv/spike/,请先读 README)。为每个服务找出引发错误的东西,只把要回滚的以 <service> app=<previous-version> 或 <service> config=<previous-revision> 的形式写入 /srv/spike/rollback.conf(不需要回滚的服务不写)。在 /root/incident/ic-error-spike/report.txt 中写下 cart: <code>、search: <code>、pay: <code> 三行,以及为每个服务显示其原因的一行素材,写成 evidence-cart: <line>、evidence-search: <line>、evidence-pay: <line>(成为原因的变更行,或者依赖服务的指标、超时行)。再为每个服务写下对齐到基准时钟(负载均衡器)的首个 5xx 时刻,写成 start-cart: <utc-time>、start-search: <utc-time>、start-pay: <utc-time>(取两台服务器中较早的那个,允许 ±10 秒误差)。原因按服务分别确定,可能有多个服务原因相同。每个服务的代码是以下之一:bad-deploy(新应用版本的缺陷)、clock-skew(时钟偏差造成的错觉)、config-push(配置部署)、traffic-surge(请求激增)、upstream-timeout(下游依赖服务延迟)。

参考

展开素材——5xx 有几行

用 python3 /opt/fixtures/ic/ickit.py open timeline 展开素材,阅读 /root/ic/timeline/README.txt。把 web-1.log 和 web-2.log 中状态码为 5xx 的行数相加,以一个数字写入 /root/ic/timeline/answers/errors.txt。

状态码是行的第六栏。4xx 不是服务器的错,不计入。

把变更排成一行 UTC

把 deploys.log(git log)中的部署和 flags.log 中的开关变更全部换算成 UTC,按从旧到新的顺序,每行一条 <utc-time>\t<change-id> 写入 /root/ic/timeline/answers/changes.tsv。时刻为 2026-11-04T05:12:03Z 形式;变更 id 对部署是提交 sha 的前 7 个字符,对开关是 flag:<name>。

git 的 Date 以提交者的时区(+0900、-0800)打印,最新的在上面。这种形式 GNU date 读不了,请用 python 的 strptime("%a %b %d %H:%M:%S %Y %z")。必须按时刻而不是日期字面排序。

服务器时钟偏差了几秒

把 lb-sample.log(基准时钟)与两份服务器日志中以同一 req id 记录的请求配对,为每台服务器以整数秒测量 server_time − reference_time,以 web-1=<seconds>、web-2=<seconds> 两行写入 /root/ic/timeline/answers/skew.txt(时钟快的为 +,慢的为 −)。

先读时区标记(+09:00、Z),换算成同一时刻(纪元秒)后再相减。请求经过负载均衡器后 1 秒内到达服务器,所以把多对的中位数(median)四舍五入即可。

基准时钟下的首个错误

减去上一步的偏差,把两台服务器的 5xx 对齐到基准时钟,把最早一条的时刻(UTC,精确到秒)和服务器以 first_error_utc=<time>、host=<server> 两行写入 /root/ic/timeline/answers/first-error.txt。

对齐后的时刻 = 服务器记录的时刻 − 该服务器的偏差。直接读时钟慢的服务器的行,错误看起来就像发生在部署之前。

缩小嫌疑变更的范围

把基准时钟下首个错误之前 30 分钟内(含首个错误时刻)进入的变更 id,每行一个写入 /root/ic/timeline/answers/suspects.txt。

把前面两个产物(changes.tsv、first-error.txt)对照起来即可。用没有对齐的时钟的首个错误来划定窗口,触发变更就会被挤到窗口之外。

检测延迟与缓解时刻

把从基准时钟的首个错误到这起事故的告警(alerts.csv 中 api-5xx-rate 的 fired)所花的秒数,以及 README 中定义的缓解时刻(分钟的开始,UTC),以 detect_delay_sec=<seconds>、mitigated_utc=<time> 两行写入 /root/ic/timeline/answers/phases.txt。

缓解时刻按定义用 metrics.csv 中每分钟的错误率查找——在第一次达到 5% 以上的那一分钟之后,连续 5 分钟低于 1% 的第一分钟。注意不要选到事故之前的平静分钟。

故障事件——三个服务都在部署后出错,回滚什么

运行 incident ic-error-spike 会触发故障事件。cart、search、pay 三个服务今天依次部署,三者从那时起都持续出现 5xx(记录:/srv/spike/,请先读 README)。为每个服务找出引发错误的东西,只把要回滚的以 <service> app=<previous-version> 或 <service> config=<previous-revision> 的形式写入 /srv/spike/rollback.conf(不需要回滚的服务不写)。在 /root/incident/ic-error-spike/report.txt 中写下 cart: <code>、search: <code>、pay: <code> 三行,以及为每个服务显示其原因的一行素材,写成 evidence-cart: <line>、evidence-search: <line>、evidence-pay: <line>(成为原因的变更行,或者依赖服务的指标、超时行)。再为每个服务写下对齐到基准时钟(负载均衡器)的首个 5xx 时刻,写成 start-cart: <utc-time>、start-search: <utc-time>、start-pay: <utc-time>(取两台服务器中较早的那个,允许 ±10 秒误差)。原因按服务分别确定,可能有多个服务原因相同。每个服务的代码是以下之一:bad-deploy(新应用版本的缺陷)、clock-skew(时钟偏差造成的错觉)、config-push(配置部署)、traffic-surge(请求激增)、upstream-timeout(下游依赖服务延迟)。

方向:同样的症状,开始的模式也不同——是从装上新版本的服务器开始依次出现,是所有服务器同时出现,还是依赖服务的延迟先飙升。在对齐时钟之前,不要相信顺序。 工具:用 lb-sample.log 测量每台服务器的偏差、用 strptime 读 git log 的 Date、metrics 中的 dep_p99_ms、错误行的状态码和响应时间。 具体:为每个服务把两台服务器的首个 5xx 对齐到基准时钟,再把这个时刻与该服务的应用部署、配置部署时刻并排放在一起。如果要回滚,就回到引发错误的那次变更的上一个版本(修订)。