注:本文章仅用来记录问题分析的过程,从实际使用上来说,该例子存在data race,不应该依赖其执行结果。
该例子是在饶大的一次夜读分享中所展示的。
package main
import (
"fmt"
"runtime"
"time"
)
func main() {
runtime.GOMAXPROCS(8)
var x int64 = 0
for i := 0; i < 8; i++ {
go func() { // 后续中没有特殊说明的goroutine都是该goroutine
for {
x++
}
}()
}
time.Sleep(time.Second)
fmt.Println(x)
}
该例子的本意是想验证Go的异步抢占机制。
在Go1.13版本中,由于设置了runtime.GOMAXPROCS(8)
,随后又启动了8个死循环的Goroutine,所以main goroutine在调用time.Sleep
“协作式”的让出执行权后,再无机会得到执行,会导致程序一直无法执行打印和退出。
在Go1.14版本中,由于加入了异步抢占,使得可以“暂停”死循环的Goroutine,使得main goroutine可以继续执行打印。
现象到这里都还符合预期,但是打印的值却稳定为0。
在main goroutine sleep的过程中,其他goroutine是会执行的,那为什么x的值没有变呢?
开始时,有以下几个怀疑点:
- goroutine 中的x是一个副本,与外层的x不是同一个变量
- goroutine 没有得到执行
- 硬件层面,Cpu cache导致,x的值还没有被刷新到内存中
那么如何确认呢?
goroutine 中的x是一个副本,与外层的x不是同一个变量?
go build -gcflags="-m=2" ./main.go
关注如下几点:
main.func1 capturing by ref: x
main.func1是main中的匿名函数,即例子中 main函数所启动的goroutine,x被捕获,且是被引用捕获的
x escapes to heap
x 逃逸到了堆上
./main.go:15:5: main.func1 capturing by ref: x (addr=true assign=true width=8)
./main.go:11:6: x escapes to heap:
./main.go:11:6: moved to heap: x
./main.go:20:13: x escapes to heap
x在goroutine中是被引用捕获的而非值捕获,所以并不是发生了拷贝导致的。
goroutine 没有得到执行?
这个其实确认的方式有很多,可以使用 go trace 进行确认,下图可以看出main.func1 是在多个P中并行执行的。
硬件层面,Cpu cache导致,x的值还没有被刷新到内存中?
这个其实细想下来原理上说不通,假如机器只有8个核心,那么8个goroutine占据了8个核心,main goroutine结束时总会在这8个核心中的一个,会公用同一个cache,也不会为0。
而且通过加大goroutine数量和加大睡眠时间,输出结果仍稳定为0。
看起来上述的怀疑点都不能说通,接下来搬出大杀器:汇编。
go build -gcflags="-m=2" ./main.go
或者先编译为二进制,再反汇编都可以。
仅关注main.func1 的汇编代码
"".main.func1 STEXT nosplit size=8 args=0x8 locals=0x0 funcid=0x0
0x0000 00000 (main.go:19) TEXT "".main.func1(SB), NOSPLIT|ABIInternal, $0-8
0x0000 00000 (main.go:19) FUNCDATA $0, gclocals·2a5305abe05176240e61b8620e19a815(SB)
0x0000 00000 (main.go:19) FUNCDATA $1, gclocals·33cdeccccebe80329f1fdbee7f5874cb(SB)
0x0000 00000 (main.go:20) JMP 2
0x0002 00002 (main.go:21) JMP 4
0x0004 00004 (main.go:21) JMP 6
0x0006 00006 (main.go:21) JMP 2
0x0000 eb 00 eb 00 eb 00 eb fa
FUNCDATA是编译器插入的GC相关的伪指令,不会被编译到二进制中,在反汇编代码中是不存在的,先忽略。
可以看到汇编代码中仅有4条跳转(JMP)指令,而没有任何执行加法(ADD)的汇编执行
大概的执行流程如下,第一行跳转到第二行,第二行跳转到第三行,第三行又跳转到第一行,如此往复。
0x0000 00000 (main.go:20) |---> JMP 2 ----
| |
0x0002 00002 (main.go:21) | JMP 4 <---
| | ----
| |
0x0004 00004 (main.go:21) | JMP 6 <---
| | ----
| |
0x0006 00006 (main.go:21) ---- JMP 2 <---
那么可以确定了,goroutine虽然在运行,但是却没有做”正经事“加法。
编译过程中将该加法操作优化掉了,所以和前面的现象也就对得上了。
至此,该问题的根因已经查清楚了,编译器做了优化,没有实际执行++操作,所以无论main goroutine等待多久,输出仍稳定为0。
问题后续:
作者认为这是一个“错误的”优化,官方的答复如下
A program with a data race in it is not a valid Go program and it could do anything. In this case, it look like the compiler decided that it is allowed to remove the writes to
x
, so the program will print 0. We usually don't consider this kind of issues (of a racy program) as bugs.
该例子存在数据竞争,即多个线程同时对x进行读写操作,但是没有做任何同步保证,Go项目中对于这种data rece不做任何保证,看起来编译器决定允许删除对x的写入,因此程序将输出0,这并不被认为是一个bug。
如何进行检测rece呢?Go中提供了 data race的检测机制,说明详见 https://blog.golang.org/race-detector
使用的方式有如下几种:
$ go test -race mypkg // test the package $ go run -race mysrc.go // compile and run the program $ go build -race mycmd // build the command $ go install -race mypkg // install the package
经检测,该例子确实存在 data race,但是由于插入了race检测的桩代码,所以输出结果也并不为0了。
go run -race ./main.go [49df10c]
==================
WARNING: DATA RACE
Read at 0x00c00013a058 by goroutine 9:
main.main.func1()
/Users/leonardwang//main.go:21 +0x38
Previous write at 0x00c00013a058 by goroutine 8:
main.main.func1()
/Users/leonardwang/main.go:21 +0x4e
Goroutine 9 (running) created at:
main.main()
/Users/leonardwang/main.go:19 +0x124
Goroutine 8 (running) created at:
main.main()
/Users/leonardwang/main.go:19 +0x124
==================
16328120
Found 1 data race(s)
exit status 66
本文由 LeonardWang 创作,采用 知识共享署名4.0
国际许可协议进行许可
本站文章除注明转载/出处外,均为本站原创或翻译,转载前请务必署名
最后编辑时间为: Feb 6,2022