标题:goroutine调度"导致"的一次事故 出处:Felix021 时间:Sat, 10 Aug 2019 13:10:31 +0000 作者:felix021 地址:https://www.felix021.com/blog/read.php?2208 内容: 1. 现象 某日线上服务报警(基于时序数据库做的),请求量大幅下滑。 观察ganglia监控图表,发现有部分机器CPU占用率断崖式下跌,从原先的1000%+下降到100%(20核40线程的CPU),通过内存监控可以确认服务本身并未重启。 登录异常机器,用 lsof -i :PORT1 也可以看到端口号仍被占用,但是却无法接受请求;同样,该服务的 pprof 监听端口 PORT2 能接受请求,但无响应请求。 2. 排查 在异常机器上通过 "netstat -antpl | grep CLOSE_WAIT | grep PORT1 | wc -l" 可以看到有大量连接等待关闭,达到连接上限,所以无法接受请求,PORT2 则正常。 挑一台机器重启后服务恢复正常。为了恢复业务,重启了大部分异常机器上的服务,保留两台持续排查。 使用 top 查看cpu占用率,如上所述,始终保持在 100% 左右,说明有一个线程在全速运行。 通过 perf top (注:也可以使用pstack,能看到更详细的调用栈),发现是某一个二分查找的函数在占用cpu。 经过对代码的分析,发现是传入的值小于有效查找范围,代码实现不完善,导致出现了死循环。 进一步排查发现某个api未做好数据有效性保护,导致出现无效数据。 3. 分析 问题的直接原因已经定位,但是不明确的是,为什么一个 goroutine 死循环会导致进程整体hang住? cpu 占用率只有100%,说明只有一个 goroutine 死循环,根据 Go 的 GMP 模型,理论上应该可以schedule其他的 goroutine 继续接受请求。 查看该进程的线程数(cat /proc/PID/status),看到开启了80+系统线程,说明不是线程数量的问题。 尝试查看该进程的 goroutine 数,但 pprof 不可用,而负责这个 metrics 打点的 goroutine 自从异常以后也未再上报数据。 写了一个简单的样例代码,开启一个简单死循环的goroutine,并不会阻碍其他goroutine的执行。 func test1() { fmt.Println("test1") i := 0 for { i++ } } func main() { go test1() for i := 0; i < 100; i++ { time.Sleep(1 * time.Second) fmt.Printf("i = %d\n", i) } } 有一位同学根据现象搜到了这篇文章: 如何定位 golang 进程 hang 死的 bug 根据这篇文章的分析,在有死循环goroutine的情况下,其他goroutine主动调用 runtime.GC() 会出现 hang 住的情况。 验证代码如下,确实符合预期,和前述事故的表现一致。 func test1() { fmt.Println("test1") i := 0 for { i++ } } func main() { go test1() for i := 0; i < 100; i++ { time.Sleep(1 * time.Second) fmt.Printf("i = %d\n", i) if i == 3 { runtime.GC() } } } 综合以上分析可知,当 golang 中出现一个死循环的 goroutine、该 goroutine 就会一直占用 cpu,无法被调度;而需要 STW 的 gc 又无法暂停该 goroutine,因此出现了一个调度上的死锁。 另外,根据那篇文章的说法,在 for 循环中没有函数调用的话,编译器不会插入调度代码,所以无法完成抢占式调用。《深入解析Go - 抢占式调度》中也有具体的说明 https://tiancaiamao.gitbooks.io/go-internals/content/zh/05.5.html 实际测试发现,如果是调用自己写的另外一个简单函数,仍然会出现死锁,而调用注入 fmt.Println 之类的函数,则不会出现死锁,说明Go并不是在函数调用的时候插入调度检测代码(这也不符合直觉,每次函数调用都有额外性能开销,不太划算),而是在某些库函数中增加了调度检测。 完。 Generated by Bo-blog 2.1.0