点击上方蓝色“Go语言中文网”关注我们,领全套Go资料,每天学习 Go 语言
本文作者:曹春晖
原文链接:https://xargin.com/map-concurrent-throw/
某系统中有类似下面这样的代码:
package main
import (
"sync"
"time"
)
type resp struct {
k string
v string
}
func main() {
res := fetchData()
log.Print(res)
}
func rpcwork() resp {
// do some rpc work
return resp{}
}
func fetchData() (map[string]string, error) {
var result = map[string]string{} // result is k -> v
var keys = []string{"a", "b", "c"}
var wg sync.WaitGroup
var m sync.Mutex
for i := 0; i < len(keys); i++ {
wg.Add(1)
go func() {
m.Lock()
defer m.Unlock()
defer wg.Done()
// do some rpc
resp := rpcwork()
result[resp.k] = resp.v
}()
}
waitTimeout(&wg, time.Second)
return result, nil
}
func waitTimeout(wg *sync.WaitGroup, timeout time.Duration) bool {
c := make(chan struct{})
go func() {
defer close(c)
wg.Wait()
}()
select {
case return false // completed normally
case return true // timed out
}
}
线上会偶现崩溃(concurrent write and iteration),但其负责人声称一定是离职员工的锅,连代码都不愿意看。
这里的代码我已经简化过了,相信你大概可以看出来,这里的 waitgroup 使用不恰当,若下游系统发生超时时,该 waitgroup 其实并没有完成,这也就意味着,其子任务也并没有全部完成。虽然在 fetchData 内部对 map 的修改加了写锁,但若下游超时,在 fetchData 返回后,fetchData 内部启动的 goroutine 仍然可能对返回的 map 进行修改。
当 map 对象同时进行加锁的 write 和不加锁的读取时,也会发生崩溃。不加锁的读取发生在什么地方呢?其实就是这里例子的 log.Print。如果你做个 json.Marshal 之类的,效果也差不多。
至于为什么是偶发,超时本来也不是经常发生的,看起来这个 bug 就变成了一个偶现 bug。
和这个 bug 类似的还有在打印 context 对象的时候,参考这里[1]。
我们再顺便控诉一下 Go 本身,这种 map 并发崩溃的 bug 对很多人造成了困扰,按说崩溃的时候会打印导致崩溃的 goroutine 栈,但为什么还是一个值得总结的问题呢?
是因为 Go 在崩溃时,其实并不能完整地打印导致崩溃的因果关系,参考这里[2]。
这个 issue 中同时也给了下面这段代码,只有在 go run -race 时,才能看到导致 throw 的真正原因。
package main
import (
"sync"
)
var x map[int]string = make(map[int]string)
func f(s string, wg *sync.WaitGroup) {
x[0] = s
wg.Done()
}
func g(s string, wg *sync.WaitGroup) {
x[1] = s
wg.Done()
}
func main() {
for {
var wg sync.WaitGroup
wg.Add(2)
go f("Hello", &wg)
go g("Playground", &wg)
wg.Wait()
}
}
下面这个崩溃栈只能看到 main.g(你运行的时候,也可能只能看到 main.f)。
~/test ❯❯❯ go run mmmm.go
fatal error: concurrent map writes
goroutine 48 [running]:
runtime.throw(0x1074091, 0x15)
/usr/local/go/src/runtime/panic.go:774 +0x72 fp=0xc000030758 sp=0xc000030728 pc=0x1024fb2
runtime.mapassign_fast64(0x1060d00, 0xc000064000, 0x1, 0xc000066048)
/usr/local/go/src/runtime/map_fast64.go:101 +0x350 fp=0xc000030798 sp=0xc000030758 pc=0x100dcd0
main.g(0x1072f92, 0xa, 0xc0000680f0)
/Users/didi/test/mmmm.go:15 +0x46 fp=0xc0000307c8 sp=0xc000030798 pc=0x10525f6
runtime.goexit()
/usr/local/go/src/runtime/asm_amd64.s:1357 +0x1 fp=0xc0000307d0 sp=0xc0000307c8 pc=0x104c001
created by main.main
/Users/didi/test/mmmm.go:24 +0xbb
goroutine 1 [semacquire]:
sync.runtime_Semacquire(0xc0000680f8)
/usr/local/go/src/runtime/sema.go:56 +0x42
sync.(*WaitGroup).Wait(0xc0000680f0)
/usr/local/go/src/sync/waitgroup.go:130 +0x64
main.main()
/Users/didi/test/mmmm.go:25 +0xc9
exit status 2
下面这样才能看到真正的原因:
~/test ❯❯❯ go run -race mmmm.go
==================
WARNING: DATA RACE
Write at 0x00c00008c000 by goroutine 7:
runtime.mapassign_fast64()
/usr/local/go/src/runtime/map_fast64.go:92 +0x0
main.g()
/Users/didi/test/mmmm.go:15 +0x63
Previous write at 0x00c00008c000 by goroutine 6:
runtime.mapassign_fast64()
/usr/local/go/src/runtime/map_fast64.go:92 +0x0
main.f()
/Users/didi/test/mmmm.go:10 +0x63
Goroutine 7 (running) created at:
main.main()
/Users/didi/test/mmmm.go:24 +0xee
Goroutine 6 (finished) created at:
main.main()
/Users/didi/test/mmmm.go:23 +0xb7
==================
fatal error: concurrent map writes
goroutine 67286 [running]:
runtime.throw(0x10ad440, 0x15)
/usr/local/go/src/runtime/panic.go:774 +0x72 fp=0xc000094750 sp=0xc000094720 pc=0x105c272
runtime.mapassign_fast64(0x1099c20, 0xc00008c000, 0x0, 0x0)
/usr/local/go/src/runtime/map_fast64.go:176 +0x364 fp=0xc000094790 sp=0xc000094750 pc=0x1044ed4
main.f(0x10abea9, 0x5, 0xc00017ffa0)
/Users/didi/test/mmmm.go:10 +0x64 fp=0xc0000947c8 sp=0xc000094790 pc=0x108b184
runtime.goexit()
/usr/local/go/src/runtime/asm_amd64.s:1357 +0x1 fp=0xc0000947d0 sp=0xc0000947c8 pc=0x1084651
created by main.main
/Users/didi/test/mmmm.go:23 +0xb8
goroutine 1 [semacquire]:
sync.runtime_Semacquire(0xc00017ffa8)
/usr/local/go/src/runtime/sema.go:56 +0x42
sync.(*WaitGroup).Wait(0xc00017ffa0)
/usr/local/go/src/sync/waitgroup.go:130 +0xb1
main.main()
/Users/didi/test/mmmm.go:25 +0xfd
exit status 2
如若在实践中碰到了类似的 bug,只能好好读代码,别无他法,甩锅给离职员工是解决不了问题的。
如果你手边的代码抽象程度比较高,比如函数的参数都是一些 interface,由运行期来决定,那可能要定位这种 bug 就更费劲一些。
参考资料
[1]这里: http://xiaorui.cc/2019/06/26/golang-net-http输出context引起的map-panic/
[2]这里: https://github.com/golang/go/issues/26703
推荐阅读
两位Go大佬的对话引发的对 Race 的思考总结
谈谈 Golang 中的 Data Race
喜欢本文的朋友,欢迎关注“Go语言中文网”:
Go语言中文网启用微信学习交流群,欢迎加微信:274768166,投稿亦欢迎