为什么一个for循环阻塞了所有协程

📚 故事背景

故事发生在不久前,那时我们还年轻,额…不是,其实我要说的是那时候Go语言的最新版本还是1.13,为什么要说这个呢,因为现在已经是1.14了,世界已经变得不一样,我会在以后的文章里讨论世界的变化。

那段时间组里入职了一位新同事,刚毕业的年轻人。按照传统,他的工作内容是一边熟悉业务一边学习编程语言,也就是我们后端团队的主要开发语言Go。

忽然有一天午饭后,他一副不可思议的表情跟我说,发现了一个非常奇怪的现象。原来他正在尝试使用channel在多个协程间传递数据,创建了一个生产者和一个消费者,可是运行不了多久就卡住了,多次尝试都是这样。听他越说越玄,就像发现了Go语言的Bug一样,我迫不及待地请他展示了那神奇的代码:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
package main

import (
"fmt"
)

func producer(ch chan<- int) {
i := 0
for {
ch<-i
i++
}
}

func consumer(ch <-chan int) {
for {
fmt.Println(<-ch)
}
}

func main() {
ch := make(chan int, 100)
go producer(ch)
go consumer(ch)
for {}
}

第一眼看到这个for循环我不禁一皱眉,强忍住没有夸奖他两句。让他演示运行了几次程序,果然每次都在循环个几十万次之后就卡住了,不再有任何输出。用top命令查看CPU使用率,单核100%,也就是for循环跑满了一个核,这个倒是符合预期。但是,程序不再有任何输出,也就说明生产者和消费者两个协程确实卡住了,这是为什么?

💣 发散尝试

按照以往的习惯,再深入分析研究之前,先发散思维做一些尝试,看看能不能触碰到问题的关键点。首先,我们基本上不会用for循环来进行等待,这个问题也肯定跟这个不寻常的写法脱不了干系,所以先把for拿掉,简单一点直接换成select,于是main函数变成了下面这个样子:

1
2
3
4
5
6
func main() {
ch := make(chan int, 100)
go producer(ch)
go consumer(ch)
select {}
}

重新编译运行程序,发现问题确实不见了。换成select带来了什么改变呢?它让主协程不再忙等待,而是彻底阻塞了主协程。为了判断是否和“主”协程相关,再次修改main函数,把for循环放到一个协程里,像下面这样:

1
2
3
4
5
6
7
8
9
func main() {
ch := make(chan int, 100)
go producer(ch)
go consumer(ch)
go func() {
for {}
}
select {}
}

重新编译运行程序,结果问题又复现了,也就是说只跟for循环有关,和主协程无关。把代码还原,还能不能再进行其他的尝试呢?

又仔细的看了一遍这20几行代码,最后我的注意力集中在consumer中的这个fmt.Println上面,因为这个函数是会在堆上分配内存的,如果和内存分配有关的话,可以用Go内置的println函数将其替代,后者会被编译器转换成调用runtime中针对具体类型实现的打印函数,不会有额外的内存分配。修改完后的consumer如下所示:

1
2
3
4
5
func consumer(ch <-chan int) {
for {
println(<-ch)
}
}

这次重新编译运行,很长时间都没有阻塞。为了进一步证明和内存分配的相关性,主动分配内存试一下:

1
2
3
4
5
6
func consumer(ch <-chan int) {
for {
b := make([]byte, 64*1024)
println(<-ch, b[0])
}
}

这次程序很快就卡住了,只输出了几十次。如果把分配的内存大小增大,程序会更快卡住。进行到这一步,可以进行一下总结,这个问题和忙等待、内存分配两者相关,缺一不可。

🎯 深入分析

现在已经有了大致的方向,要想了解背后的原理,只能进行更加深入的分析研究。如何研究呢?首先就是来调试一下,为了方便的查看协程状态,我们使用专门为Go语言开发的delve调试器。

把代码恢复到最开始的样子,并重新编译运行,直到程序卡住。然后通过attach命令连接到指定的pid进行调试:

1
2
$ dlv attach 32036
Type 'help' for list of commands.

接下来通过grs命令查看所有的协程:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
grs
* Goroutine 1 - User: C:/gopath/src/fengyoulin.com/research/block_all/main.go:25 main.main (0x49a961) (thread 26988)
Goroutine 2 - User: C:/go/src/runtime/proc.go:305 runtime.gopark (0x42ecd5)
Goroutine 3 - User: C:/go/src/runtime/proc.go:305 runtime.gopark (0x42ecd5)
Goroutine 4 - User: C:/go/src/runtime/proc.go:305 runtime.gopark (0x42ecd5)
Goroutine 5 - User: C:/go/src/runtime/proc.go:305 runtime.gopark (0x42ecd5)
Goroutine 6 - User: C:/gopath/src/fengyoulin.com/research/block_all/main.go:10 main.producer (0x49a7f8)
Goroutine 7 - User: C:/go/src/unicode/utf16/utf16.go:64 unicode/utf16.Encode (0x4846f1) (thread 27112)
Goroutine 18 - User: C:/go/src/runtime/proc.go:305 runtime.gopark (0x42ecd5)
Goroutine 19 - User: C:/go/src/runtime/proc.go:305 runtime.gopark (0x42ecd5)
Goroutine 20 - User: C:/go/src/runtime/proc.go:305 runtime.gopark (0x42ecd5)
Goroutine 21 - User: C:/go/src/runtime/proc.go:305 runtime.gopark (0x42ecd5)
Goroutine 34 - User: C:/go/src/runtime/proc.go:305 runtime.gopark (0x42ecd5)
Goroutine 35 - User: C:/go/src/runtime/proc.go:305 runtime.gopark (0x42ecd5)
Goroutine 36 - User: C:/go/src/runtime/proc.go:305 runtime.gopark (0x42ecd5)
Goroutine 50 - User: C:/go/src/runtime/proc.go:305 runtime.gopark (0x42ecd5)
[15 goroutines]

可以看到1号和7号协程有关联的thread,处于运行状态。而且通过源码文件路径和行号可以确定,1号协程正在运行main函数里的for循环,而6号协程就是我们的producer。前面有*标识的协程,表示当前被调试器选中,一些调试命令会在被选中协程的上下文中执行。可以通过gr命令加上协程号来选择协程,例如gr 1选择1号协程。

选中1号协程,然后用locals命令查看局部变量:

1
2
locals
ch = chan int 100/100

根据以上输出可以发现,通道ch的缓冲区已经写满数据,所以6号协程应该已经无法继续运行,这跟从协程列表看到的状态一致。接下来选择6号协程,然后通过bt命令查看一下调用栈:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
gr 6
Switched from 1 to 6 (thread 26988)
bt
0 0x000000000042ecd5 in runtime.gopark
at C:/go/src/runtime/proc.go:305
1 0x0000000000404b89 in runtime.goparkunlock
at C:/go/src/runtime/proc.go:310
2 0x0000000000404b89 in runtime.chansend
at C:/go/src/runtime/chan.go:236
3 0x0000000000404935 in runtime.chansend1
at C:/go/src/runtime/chan.go:127
4 0x000000000049a7f8 in main.producer
at C:/gopath/src/fengyoulin.com/research/block_all/main.go:10
5 0x00000000004550c1 in runtime.goexit
at C:/go/src/runtime/asm_amd64.s:1357

不出所料,6号协程确实正在ch的sendqueue中排队,等待被唤醒。

现在可以明确的是,程序之所以不再输出,应该是因为consumer不再继续消费ch中的数据,为了弄清楚原因,需要继续分析。选择7号协程并查看调用栈:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
gr 7
Switched from 6 to 7 (thread 27112)
bt
0 0x00007ffc8c0fcc14 in ???
at ?:-1
1 0x000000000042b197 in runtime.stdcall4
at C:/go/src/runtime/os_windows.go:926
2 0x000000000042a964 in runtime.semasleep
at C:/go/src/runtime/os_windows.go:679
3 0x000000000040a1f4 in runtime.notetsleep_internal
at C:/go/src/runtime/lock_sema.go:224
4 0x000000000040a3b6 in runtime.notetsleep
at C:/go/src/runtime/lock_sema.go:275
5 0x0000000000431204 in runtime.stopTheWorldWithSema
at C:/go/src/runtime/proc.go:1048
6 0x0000000000452ffb in runtime.systemstack
at C:/go/src/runtime/asm_amd64.s:370
7 0x00000000004314e0 in runtime.mstart
at C:/go/src/runtime/proc.go:1146
8 0x0000000000452f80 in runtime.systemstack_switch
at C:/go/src/runtime/asm_amd64.s:330
9 0x000000000041861c in runtime.gcStart
at C:/go/src/runtime/mgc.go:1287
10 0x000000000040b7d7 in runtime.mallocgc
at C:/go/src/runtime/malloc.go:1115
11 0x000000000043dc03 in runtime.makeslice
at C:/go/src/runtime/slice.go:49
12 0x00000000004846f1 in unicode/utf16.Encode
at C:/go/src/unicode/utf16/utf16.go:64
13 0x000000000048f4cc in internal/poll.(*FD).writeConsole
at C:/go/src/internal/poll/fd_windows.go:766
14 0x000000000048ee8a in internal/poll.(*FD).Write
at C:/go/src/internal/poll/fd_windows.go:704
15 0x00000000004904e8 in os.(*File).write
at C:/go/src/os/file_windows.go:230
16 0x00000000004904e8 in os.(*File).Write
at C:/go/src/os/file.go:153
17 0x0000000000494042 in fmt.Fprintln
at C:/go/src/fmt/print.go:265
18 0x000000000049a8bd in fmt.Println
at C:/go/src/fmt/print.go:274
19 0x000000000049a8bd in main.consumer
at C:/gopath/src/fengyoulin.com/research/block_all/main.go:17
20 0x00000000004550c1 in runtime.goexit
at C:/go/src/runtime/asm_amd64.s:1357

通过调用栈可以看出来,这就是我们的consumer协程,进一步看到mallocgc->gcStart->stopTheWorldWithSema这个调用路径,一切都清晰了。

根本原因就是:循环中不断分配堆内存,达到GC触发条件后,新的分配需要等待GC,而GC需要STW,而main函数中的for循环,就像一个未释放的自旋锁,一直在那里循环,阻止了STW完成,进而阻止了GC,所以程序就卡住了。

🚀 引申探索

继续向下追问的话,就需要搞清楚为什么一个for循环就阻止了STW,在这里只简单地做一下分析。

现在我们使用的操作系统,像Linux、macOS、Windows都是抢占式调度的,系统以时间片的形式将CPU时间分配到不同的线程,当线程时间片用尽后,操作系统会将其打断,然后调度其他就绪的线程。时间片机制依赖于硬件的时钟中断,是主动触发的抢占。

而现在主流的协程实现,比如Go和Lua中的协程,运行时并不会主动抢占,都是以协程主动让出CPU的方式来进行调度的,所以如果某个协程很长时间不让出CPU,就会对整体调度造成影响。

注:Go1.14已经实现了真正意义上的抢占,不用再担心for循环阻塞GC了,这个以后再聊。

协程主动让出CPU是通过运行时中的调度代码实现的,要求当前执行线程的指令流必须能够从用户编写的代码中跳出,回到运行时调度逻辑中,才能完成这一操作。Lua中的协程通过调用coroutine.yield来主动让出CPU,Go的运行时提供了runtime.Gosched来实现同样的功能。

Go语言gc执行STW时密切依赖协程调度,它会设置运行时中的gcwaiting标识,其他的执行线程在调度协程时会检测到该标识,然后主动暂停运行。当所有其他线程都暂停运行后,发起并等待STW完成的gc线程得以继续执行。上述main函数中的for循环把当前执行线程的指令流限制在了循环体内 ,无法回到Go runtime中执行调度代码,从而无法停止自己,进而影响到了STW。

话又说回来,我们也没有主动调用runtime.Gosched呀,Go语言又是如何合理的安排各个协程主动让出CPU的呢?如果了解过Go语言的运行时栈增长的话,应该知道编译器会在一些函数的入口处加入检测代码,按需进行栈增长。其实协程能够主动让出CPU,也依赖于这部分插入的代码。

下面就来做一个更有意思的尝试,来证明这一点。对,终于到了最精彩的部分。

做点什么呢?斐波那契数列大家应该都比较熟悉,就是1、1、2、3、5、8…,前两项为1,从第三项开始,每一项为之前两项之和。我们就在代码中加两个斐波那契函数,如下所示:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
func fib(i int) int {
m, n := 1, 0
for i > 0 {
m, n = m+n, m
i--
}
return m
}

func fibR(i int) int {
if i < 2 {
return 1
}
return fibR(i-1) + fibR(i-2)
}

其中fibR是递归版本,不考虑它的效率问题。为什么自己实现两个函数呢?请注意这两个函数都没用调用任何的库函数,也没有进行堆内存分配,这样就排除了不必要的干扰。就利用这两个函数来改造一下之前的代码,首先尝试在main函数的for循环中加上对fib的调用,如下所示:

1
2
3
4
5
6
7
8
func main() {
ch := make(chan int, 100)
go producer(ch)
go consumer(ch)
for {
fib(1)
}
}

重新编译运行程序,发现会在跟原来差不多的输出行数后卡住,也就是没有什么效果。

再尝试把for循环中换成调用fibR,然后重新编译运行,这次程序不再阻塞了,经过很长时间还在输出,这是为什么呢?

我们通过反汇编来比较一下这两个函数的不同,结果在fibR中发现了一个fib中不存在的函数调用:

1
2
0x49aa44              e89786fbff              CALL runtime.morestack_noctxt(SB)
0x49aa49 e972ffffff JMP main.fibR(SB)

这个runtime.morestack_noctxt就是编译器安插在函数入口处,用来按需进行栈增长的。因为fibR是递归函数,对栈空间有较大消耗,所以编译器插入了栈增长代码,在一些基本上不消耗栈空间的函数里是不会插入这个调用的,如fib。

继续追踪下去,最终在栈增长调用的runtime.newstack里发现了调度相关的逻辑,在进行栈增长的同时会判断是否需要进行协程调度,按需让出CPU。如果阅读这部分源码的话,会见到preempt关键字,需要注意这并不是真正的抢占,只是站在调度器的视角罢了。

最后,我们的问题得以解答,Go语言编译器在函数入口处插入的栈增长代码,同时被运行时用来执行协程调度。我们的新同学在弄清楚原委之后,也安心的回去继续写Bug了。噢,不对,回去写代码了。