map 并发崩溃一例：顺便吐槽 Go 打印堆栈不友好（map医学上）

map 并发崩溃一例：顺便吐槽 Go 打印堆栈不友好（map医学上）

某系统中有类似下面这样的代码：

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 <-c: return false // completed normally case <-time.After(timeout): 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 就更费劲一些。

版权声明：本文内容由网络用户投稿，版权归原作者所有，本站不拥有其著作权，亦不承担相应法律责任。如果您发现本站中有涉嫌抄袭或描述失实的内容，请联系我们jiasou666@gmail.com 处理，核实后本网站将在24小时内删除侵权内容。