共计 3515 个字符，预计需要花费 9 分钟才能阅读完成。
再挖个坟，讲讲去年踩的另一个坑。
前方低能
那是去年 7 月的一天，被透过落地玻璃的宇宙中心五道口的夕阳照着的正在工位搬砖的我，突然听到一阵骚乱，转头一看，收到夺命连环 call 的 D 同学反馈，流量严重异常。
点开报警群，一串异常赫然在目：
[规则]：「流量波动过大 (严重)」
[报警上下文]：change：-70.38%
值班人：D（不是我）
报警方式：电话 &Lark
报警 URL：报警详情页
再点开报警详情页一看：
排爆
解释一下：在字节跳动，我们有一个基于 OpenTSDB 的 metrics 平台（时序数据库），用于采集和查询各项监控指标。
图中是一个流量源的请求 QPS，在短时间内从 7k 暴降至 2k，从而触发了报警规则。
除了流量源之外，在这个指标上我们还有机房、Server IP 等其他 tag；通过这些 tag，我们发现：
- 来自所有流量源的 QPS 都在暴降
- 所有机房的 QPS 都在暴降
- 按 IP 看，许多机器的 QPS 降到 0，但部分机器仍在正常接客
对于异常的机器，从监控上可以看到，其 CPU 占用陡降至很低的值（约 2.5%）：
于是这条线索让我们把问题范围缩小到某台机器上。
进一步的排查情况情况是：
- ssh 可以正常登录，看起来 OS 没啥问题
- 通过 lsof 可以看到，进程仍然在监听业务端口，只是不响应请求
-
top 看到该进程在第一位，占了 99.8% 的 cpu，有点奇怪
- 注：这是一台 40 核的物理机，top 里 99.8% cpu 表示进程占满了 1 个核心，和前面的 CPU 监控遥相呼应。
PID USER RES %CPU COMMAND
316 user 968497 99.8 ./service
1 root 3796 0.0 systemd虽然尚未定位到问题，但至少进一步把问题缩小到进程级别了。
既然是 go 程序的问题，那当然是要搬出神器 pprof 了，只可惜很快就装逼失败 —— 因为这个进程已经不响应任何请求了。
减压
此时距故障发生已经过了 15 分钟，对于广告业务，不能正常处理请求，对应的就是真金白银的损失。
但这个 case 以前没出现过，一时半会又定位不了病根，大家都压力山大。
在这种情况下，经验丰富的老司机们一定不会忘记的，就是压箱底的大招 —— 重启大法。
由于线上是大面积机器异常，我们随便找了一台机器重启该进程，很快，这台机器就开始正常接客了。
于是我们留下几台异常机器（保留现场备查）、从服务注册中摘掉，并将其余异常机器全部重启，暂时恢复了业务。
但病根未除，问题随时可能复辟，还得继续。
深挖
前面说到，在 top 中看到，D 项目的进程 CPU 占用率是 100%，跑满了一个 CPU。
这是一个奇怪的现象，说明它并不是简单地陷入死锁，而是在反复执行一些任务，这意味着，如果我们知道它在跑什么，可能就找到病因了。
这时候老司机 W 同学祭出了 linux 的 perf 命令
$ sudo perf top
幸福来的太突然，连函数名都给出来了，送命题秒变送分题[doge]
捞了一下代码，这个 GetXXX 是一个二分查找的函数，根据输入的价格，查询对应价格区间的相关配置，大概长这样：
type Item struct {
left int
right int
value int
}
var config = []*Item{{0, 10, 1},
{10, 20, 2},
{20,100, 8},
{100, 1<<31, 10},
}
func GetXXX(price int) int {start, end := 0, len(config)
mid := (start + end) / 2
for mid >= 0 && price < len(config) {if price < config[mid].left {end = mid - 1} else if price >= config[mid].right {start = mid + 1} else {return config[mid].value
}
mid = (start + end) / 2
}
return -1
}按说这么简单的代码，线上跑了至少也几个月了，不应该有啥 BUG，按照胡尔莫斯·柯南的教诲，排除一切不可能的，真相只有一个，那就是：输入的价格是个负数。
负的价格？这不由得让我想起了 中行的某款理财产品……
当然这还只是个推论，在日记里三省吾身的胡适告诉我们，要大胆假设，小心求证。
实锤起来倒也很简单，到上游的数据库去查了一下，确实出现了了负的价格。
再后面就是上游系统的 BUG 了，通过日志记录发现在 17:44 确实有价格被改成负数，排查代码确认，Web UI 及对应的后端代码是有合法性校验的，但是提供的 API 漏了，最终导致了这次事故。
既然找到了病根，修复起来就简单了：
- 修复 API 代码，加上合法性校验
- 修复数据库里的无效数据
- GetXXX 里加上无效价格检测（防御性编程）
填坑
业务的坑是填完了，但是技术的坑还没：为什么一个死循环会导致进程卡死呢？
按照调度的常识来推理，一个线程（或 goroutine）不应该阻塞其他线程的执行。
比如运行下面这段代码，可以看到，进程并没有卡死，第一个 for 循环确实会不断输出 i 的值。
var i int64 = 0
func main() {go func() {
for {fmt.Println(atomic.LoadInt64(&i))
time.Sleep(time.Millisecond * 500)
}
}()
for {atomic.AddInt64(&i, 1)
}
}这说明“卡死”的原因还没有这么简单。
这样简单的代码无法复现前面的问题，还是要把死循环放到复杂场景下才能复现，比如加入前述 D 项目的代码里，简单粗暴直接有效。
通过加上 GODEBUG 环境变量：
$ GODEBUG="schedtrace=2000,scheddetail=1" ./service可以看到有一个线索：gcwaiting=1
SCHED 2006ms: gomaxprocs=64 idleprocs=0 threads=8 spinningthreads=0 idlethreads=5 runqueue=0 gcwaiting=1 nmidlelocked=0 stopwait=1 sysmonwait=0
这就形成了闭环：gc 需要 STW，但是这个 goroutine 在死循环，无法被中断，而其他 goroutine 已经被中断、等待 gc 完成，最终导致了这个局面。
可以在前述代码里手动触发 gc 实锤一下：现象和线上完全一致。
var i int64 = 0
func main() {go func() {
for {fmt.Println(atomic.LoadInt64(&i))
time.Sleep(time.Millisecond * 500)
runtime.GC() // 手动触发 GC}
}()
for {atomic.AddInt64(&i, 1)
}
}但还没完 —— 以上现象似乎并不符合 go 宣称的“抢占式调度”啊！
实际上 Go 实现的是一个 Cooperating Scheduler（协作式调度器）。一般而言，协作式调度器需要线程（准确地说是协程）主动放弃 CPU 来实现调度（runtime.Gosched()，对应 python/java 的 yield），但 Go 的 runtime 会在函数调用判断是否要扩展栈空间的同时，检测 G 的抢占 flag，从而实现了一个 看起来像 是抢占式调度的 scheduler。
这还有个小问题 —— 上面的代码里不是调用了 atomic.AddInt64 么？这个倒是简单，通过 go tool compile -S main.go 可以看到，AddInt64 已经被 inline 了；但只要在这里再加上个 fmt.Println 就可以破功了（试试看？）。
（被 inline 了的 AddInt64）
收尾
最后，如果你发现前面的代码怎么都不能复现 —— 那你一定是在用 go 1.14+ 了，这个版本实现了一个基于 SIGURG 信号的抢占式调度，再也不怕死循环 / 密集计算搞死 gc 了（不过代价是，出现死循环导致的性能下降问题更难排查了），对此感兴趣的同学推荐学习《Go 语言原本：6.7 协作与抢占》。
简单总结一下：
- 二分查找可能会死循环；
- 在 go 1.13 及以下版本，死循环 / 密集计算会导致调度问题；
- 特别是遇到 gc 的情况，可能会锁死进程；
- 在 Linux 下可以用 perf top 可以用来做 profiling；
学了这么多，感觉又无用武之地？快来穿山甲，百万级的 QPS，各种酸爽的问题等着你。
~ 投递链接 ~
投放研发工程师（上海）
https://job.toutiao.com/s/J8D…
高级广告研发工程师（北京）
https://job.toutiao.com/s/J8D…
欢迎关注
参考链接
- 如何定位 golang 进程 hang 死的 bug
- 关于 Go1.14，你一定想知道的性能提升与新特性
- Go 语言原本：6.7 协作与抢占
