《互联网产品的服务端架构·产品、流量与基础能力》11.3 一次线上问题定位复盘

复盘报告只写“数据库连接数打满”,解释不了为什么监控二十分钟后才报警。文章把线上问题拆成检测、确认、缓解、解决四段,用时间线还原每一段的耗时,给出可测试的分析实现,并说明缺阶段、乱序与时间回退为什么必须报错,避免半截报告误导结论与改进方向。

复盘报告只写了“连接池打满”

「回声」的订单服务在周三下午出现大面积超时。事后复盘报告只有一句话:数据库连接数打满,导致请求排队。修复项是“扩大连接池、增加连接数监控”。报告发出去后,有人问了一句:为什么监控二十分钟后才报警?没有人能回答。

连接池打满只是结果,不是过程。从问题发生到用户恢复,中间隔着一连串动作:有人先看到告警,有人确认不是误报,有人决定切流量,有人找到根因并修复。每一段都可能慢,慢的原因完全不同。只写最后那一个技术原因,等于把一段可以改进的流程压成了一个名词。

复盘的第一件事不是找根因,而是还原时间线。把“什么时候发生、什么时候发现、什么时候确认、什么时候缓解、什么时候解决”分开记录,才能看出瓶颈在检测、确认还是恢复。

这篇用一个案例假设的时间线,说明四段耗时怎么算、怎么测,以及为什么分析函数在阶段缺失时必须报错,而不是返回一个半截报告。

把处理过程拆成四段

线上问题的处理可以拆成四个阶段:检测(detect)、确认(ack)、缓解(mitigate)、解决(resolve)。四段回答四个不同的问题,改进手段也不同。

阶段回答的问题典型证据常见瓶颈改进方向
detect系统什么时候发现异常告警记录、监控曲线阈值太松、采集间隔太长调整 SLI 与告警窗口
ack人什么时候确认不是误报值班日志、聊天记录告警噪音、通知链路降噪、明确值班责任
mitigate用户什么时候恢复可用切流记录、回滚记录决策慢、开关不可用预演预案、自动化开关
resolve根因什么时候被消除修复提交、配置变更定位慢、依赖外部补信号、补关联键

表中的“检测”不等于“报警”。监控可能在 14:07 就采集到了异常,但告警规则要求连续五个周期超过阈值,直到 14:27 才发出通知;这二十分钟属于检测阶段,不属于确认阶段。把两者混在一起,就会得出“值班反应慢”的错误结论。

同样,“缓解”不等于“解决”。切走流量后用户恢复,但根因还在;回滚版本后错误消失,但代码问题没有修。复盘要分别记录这两个时间点,否则无法判断恢复手段是否可持续。

四段时间相加,才是用户实际受影响的总时长。很多团队只统计“从报警到恢复”,漏掉了检测前的沉默期,也漏掉了解决后的观察期,导致改进项总是偏向值班流程,而忽略了监控口径。

失败场景:二十分钟才发现,四十分钟才缓解

把那次事故的时间线展开,数字都是案例假设值,用来演示分析方法。

14:02,新版本发布,连接池上限从 200 调到 120,配置随代码一起上线。14:07,流量进入高峰,连接数达到 120,请求开始排队。14:08,部分接口超时,用户看到转圈。

监控在 14:07 就采集到了连接数 120,但告警规则是“连接数使用率超过 95% 持续 10 分钟”。使用率按上限计算是 100%,规则本身没问题;问题是指标每 60 秒采集一次,告警每 5 分钟评估一次,两个窗口叠加,第一次评估要等到 14:12,连续两个周期满足才触发,实际通知在 14:27。

14:27,告警发到值班群。值班同学先怀疑是误报,因为同一时间另一套面板显示数据库 CPU 只有 40%。他花了十五分钟对比两套面板,14:42 才确认问题存在。这段是确认阶段,瓶颈是告警缺少上下文:告警只发了“连接数高”,没有附带受影响接口、错误率和最近变更。

14:42,值班同学决定切走一半流量。切流开关在配置中心,但订单服务的开关是全局的,切一半需要改权重并重启两个实例。14:55 改完,15:05 实例重启完成,15:22 用户错误率回到基线。这段是缓解阶段,瓶颈是开关粒度太粗、重启太慢。

15:22 之后,团队开始定位根因。连接池配置在代码里,发布记录里能看到变更,但发布系统与监控系统没有关联,值班同学只能逐个翻提交。17:40 找到配置变更,18:10 回滚并确认连接数恢复。这段是解决阶段,瓶颈是变更记录没有进入告警上下文。

整段事故里,检测用了 20 分钟,确认用了 15 分钟,缓解用了 40 分钟,解决用了 168 分钟。如果复盘只写“连接池打满”,改进项只会是“扩大连接池”;而真正能缩短下次事故的,是缩短检测窗口、把变更记录带进告警、把切流开关做细。

用 Analyze 还原时间线

时间线分析可以写成纯函数:输入事件序列,输出三段耗时。纯函数的好处是边界可以穷举,复盘模板调整时不需要改值班流程。

// file: internal/obs/incident.go
// tier: L1
// verify: go test ./internal/obs/

package obs

import "fmt"

// Phase 是线上问题处理时间线上的四个阶段。
type Phase string

const (
	PhaseDetect   Phase = "detect"
	PhaseAck      Phase = "ack"
	PhaseMitigate Phase = "mitigate"
	PhaseResolve  Phase = "resolve"
)

// Event 是时间线上的一次状态变化,At 是 Unix 秒。
type Event struct {
	At    int64
	Phase Phase
	Note  string
}

// Report 把一次问题的处理过程拆成三段耗时,单位与 Event.At 一致。
type Report struct {
	DetectToAck       int64
	AckToMitigate     int64
	MitigateToResolve int64
}

// Analyze 从事件序列还原处理时间线。
// 四个阶段必须各出现一次且顺序正确,时间必须非递减;
// 任一条件不满足都返回错误和空的 Report,不返回半截结果。
func Analyze(events []Event) (Report, error) {
	order := []Phase{PhaseDetect, PhaseAck, PhaseMitigate, PhaseResolve}
	position := make(map[Phase]int, len(order))

	var prev int64
	for i, ev := range events {
		if i > 0 && ev.At < prev {
			return Report{}, fmt.Errorf("obs: event %d goes back in time: %d < %d", i, ev.At, prev)
		}
		prev = ev.At

		if !validPhase(ev.Phase) {
			return Report{}, fmt.Errorf("obs: event %d has unknown phase %q", i, ev.Phase)
		}
		if _, ok := position[ev.Phase]; ok {
			return Report{}, fmt.Errorf("obs: phase %q appears more than once", ev.Phase)
		}
		position[ev.Phase] = i
	}

	for _, p := range order {
		if _, ok := position[p]; !ok {
			return Report{}, fmt.Errorf("obs: phase %q missing", p)
		}
	}
	for i := 1; i < len(order); i++ {
		if position[order[i]] < position[order[i-1]] {
			return Report{}, fmt.Errorf("obs: phase %q appears before %q", order[i], order[i-1])
		}
	}

	detect := events[position[PhaseDetect]].At
	ack := events[position[PhaseAck]].At
	mitigate := events[position[PhaseMitigate]].At
	resolve := events[position[PhaseResolve]].At

	return Report{
		DetectToAck:       ack - detect,
		AckToMitigate:     mitigate - ack,
		MitigateToResolve: resolve - mitigate,
	}, nil
}

func validPhase(p Phase) bool {
	switch p {
	case PhaseDetect, PhaseAck, PhaseMitigate, PhaseResolve:
		return true
	default:
		return false
	}
}

Analyze 要求四个阶段各出现一次,顺序必须是 detect、ack、mitigate、resolve。顺序不是靠事件时间排序推出来的,而是靠阶段在序列中的位置判断;时间只负责非递减校验。这样即使两个事件时间相同,阶段顺序仍然明确。

时间必须非递减,是因为时间线代表真实发生顺序。时间回退通常来自时钟不同步、手工补录错误或日志时区混用。如果允许回退,算出来的耗时会变成负数,报告看起来“很快”,实际却掩盖了数据质量问题。

重复阶段直接报错,而不是取第一次或最后一次。重复通常意味着有两套流程在同时记录,或者事件被重复投递;无论哪种,时间线都不可信。静默取一个值会让报告看起来完整,但结论可能完全相反。

缺少任一阶段时返回错误和空的 Report,不返回半截结果。这是本实现最重要的约束:如果只算到缓解,MitigateToResolve 就是 0,读者会误以为解决耗时为零。空报告让调用方必须显式处理“还没解决”的情况,而不是把未知当成已知。

Note 字段不参与计算,只用于人工阅读。把备注塞进计算逻辑,会让函数依赖自由文本,测试变得脆弱。备注适合放在复盘文档里,计算只关心时间和阶段。

测试:缺阶段、乱序与时间回退

测试要覆盖正常时间线、相同时间戳、缺阶段、乱序、重复阶段、时间回退和未知阶段。前两个确认计算正确,后五个确认错误被拦住。

// file: internal/obs/incident_test.go
// tier: L1
// verify: go test ./internal/obs/

package obs

import (
	"reflect"
	"testing"
)

func TestAnalyzeBuildsTimeline(t *testing.T) {
	events := []Event{
		{At: 1000, Phase: PhaseDetect, Note: "告警触发"},
		{At: 1120, Phase: PhaseAck, Note: "值班确认"},
		{At: 1900, Phase: PhaseMitigate, Note: "切流量"},
		{At: 2800, Phase: PhaseResolve, Note: "索引重建完成"},
	}

	got, err := Analyze(events)
	if err != nil {
		t.Fatal(err)
	}
	want := Report{DetectToAck: 120, AckToMitigate: 780, MitigateToResolve: 900}
	if !reflect.DeepEqual(got, want) {
		t.Fatalf("report = %+v, want %+v", got, want)
	}
}

func TestAnalyzeAllowsEqualTimestamps(t *testing.T) {
	events := []Event{
		{At: 10, Phase: PhaseDetect},
		{At: 10, Phase: PhaseAck},
		{At: 20, Phase: PhaseMitigate},
		{At: 20, Phase: PhaseResolve},
	}
	got, err := Analyze(events)
	if err != nil {
		t.Fatal(err)
	}
	want := Report{DetectToAck: 0, AckToMitigate: 10, MitigateToResolve: 0}
	if !reflect.DeepEqual(got, want) {
		t.Fatalf("report = %+v, want %+v", got, want)
	}
}

func TestAnalyzeRejectsIncompleteOrDisorderedTimeline(t *testing.T) {
	cases := []struct {
		name   string
		events []Event
	}{
		{
			name: "missing resolve",
			events: []Event{
				{At: 1, Phase: PhaseDetect},
				{At: 2, Phase: PhaseAck},
				{At: 3, Phase: PhaseMitigate},
			},
		},
		{
			name: "wrong order",
			events: []Event{
				{At: 1, Phase: PhaseDetect},
				{At: 2, Phase: PhaseMitigate},
				{At: 3, Phase: PhaseAck},
				{At: 4, Phase: PhaseResolve},
			},
		},
		{
			name: "duplicate phase",
			events: []Event{
				{At: 1, Phase: PhaseDetect},
				{At: 2, Phase: PhaseAck},
				{At: 3, Phase: PhaseAck},
				{At: 4, Phase: PhaseMitigate},
				{At: 5, Phase: PhaseResolve},
			},
		},
		{
			name: "time goes back",
			events: []Event{
				{At: 5, Phase: PhaseDetect},
				{At: 4, Phase: PhaseAck},
				{At: 6, Phase: PhaseMitigate},
				{At: 7, Phase: PhaseResolve},
			},
		},
		{
			name: "unknown phase",
			events: []Event{
				{At: 1, Phase: PhaseDetect},
				{At: 2, Phase: Phase("diagnose")},
				{At: 3, Phase: PhaseResolve},
			},
		},
	}

	for _, tc := range cases {
		t.Run(tc.name, func(t *testing.T) {
			got, err := Analyze(tc.events)
			if err == nil {
				t.Fatal("want error")
			}
			if got != (Report{}) {
				t.Fatalf("report = %+v, want zero report on error", got)
			}
		})
	}
}

TestAnalyzeBuildsTimeline 用 1000、1120、1900、2800 四个时间点,期望三段分别是 120、780、900。这个测试同时固定了字段含义:DetectToAck 是确认减检测,不是检测减确认。

TestAnalyzeAllowsEqualTimestamps 确认相同时间戳是合法的。现实中检测和确认可能在同一分钟完成,强行要求严格递增会把正常流程判成错误。只要阶段顺序正确、时间不倒退,耗时为 0 是有效结果。

TestAnalyzeRejectsIncompleteOrDisorderedTimeline 用表驱动覆盖五种错误:缺 resolve、顺序错误、重复 ack、时间回退、未知阶段。每个子测试都检查两件事:返回错误,且报告为零值。只检查错误不够,因为半截报告比没有报告更危险。

表驱动的好处是新增边界时只加一行,不用复制测试函数。子测试名字会出现在 go test -v 输出里,失败时能直接定位是哪一种时间线。

运行命令与输出

在 lab 目录执行本章的测试命令:

cd .local/checks/webapp-lab
go test ./internal/obs/ -run 'TestAnalyze' -count=1 -v

一次本机运行的真实输出如下,耗时随机器变化:

=== RUN   TestAnalyzeBuildsTimeline
--- PASS: TestAnalyzeBuildsTimeline (0.00s)
=== RUN   TestAnalyzeAllowsEqualTimestamps
--- PASS: TestAnalyzeAllowsEqualTimestamps (0.00s)
=== RUN   TestAnalyzeRejectsIncompleteOrDisorderedTimeline
=== RUN   TestAnalyzeRejectsIncompleteOrDisorderedTimeline/missing_resolve
=== RUN   TestAnalyzeRejectsIncompleteOrDisorderedTimeline/wrong_order
=== RUN   TestAnalyzeRejectsIncompleteOrDisorderedTimeline/duplicate_phase
=== RUN   TestAnalyzeRejectsIncompleteOrDisorderedTimeline/time_goes_back
=== RUN   TestAnalyzeRejectsIncompleteOrDisorderedTimeline/unknown_phase
--- PASS: TestAnalyzeRejectsIncompleteOrDisorderedTimeline (0.00s)
    --- PASS: TestAnalyzeRejectsIncompleteOrDisorderedTimeline/missing_resolve (0.00s)
    --- PASS: TestAnalyzeRejectsIncompleteOrDisorderedTimeline/wrong_order (0.00s)
    --- PASS: TestAnalyzeRejectsIncompleteOrDisorderedTimeline/duplicate_phase (0.00s)
    --- PASS: TestAnalyzeRejectsIncompleteOrDisorderedTimeline/time_goes_back (0.00s)
    --- PASS: TestAnalyzeRejectsIncompleteOrDisorderedTimeline/unknown_phase (0.00s)
PASS
ok  	webapp/internal/obs	0.219s

输出里的子测试名对应五种错误时间线。实际复盘时,可以把事件序列存成 JSON 或表格,由脚本调用同样的分析逻辑,生成统一格式的耗时报告,减少手工计算错误。

小结

复盘先还原时间线,再谈根因。检测、确认、缓解、解决是四件不同的事,混在一起会把流程问题误判成技术问题。

连接池打满只是结果。为什么二十分钟才发现、为什么四十分钟才缓解,需要分别从监控口径、告警上下文、切流开关和变更关联里找答案。

Analyze 用四阶段、非递减时间和全有或全无的报告,把时间线约束写成可测试的代码。缺阶段时返回错误,比返回半截报告更安全。

阅读导航:上一节:11.2 日志、指标与追踪的最小集 · 下一节:12.1 DAU 到 QPS 的估算 。

常见错误与边界

  • 只写根因不写时间线:无法区分检测慢、确认慢和恢复慢,改进项只能靠猜。
  • 把检测和确认混为一谈:采集到异常不等于人已经知道,容易错怪值班同学。
  • 把缓解当成解决:用户恢复不代表根因消除,同类问题还会再来。
  • 只统计报警之后的时间:漏掉检测前的沉默期,报告系统性偏乐观。
  • 允许时间回退并算出负耗时:时钟或补录问题被藏起来,报告看起来更快。
  • 重复阶段静默取一个值:两套流程同时记录时,时间线不可信。
  • 缺阶段时返回半截报告:未解决被显示成解决耗时为 0,读者会误判。
  • 把备注文本塞进计算逻辑:函数依赖自由文本,测试脆弱且难以复现。

继续阅读

探索更多技术文章

浏览归档,发现更多关于系统设计、工具链和工程实践的内容。

全部文章 返回首页

「books」更多文章

  1. 《互联网产品的 AI 架构·平台化与治理》附录 C 平台化评审清单
  2. 《互联网产品的 AI 架构·平台化与治理》附录 B 能力目录与配额字段速查
  3. 《互联网产品的 AI 架构·平台化与治理》附录 A 治理角色与职责速查