golang逃逸分析和競爭檢測
阿新 • • 發佈:2018-12-08
最近在線上發現一塊程式碼邏輯在執行N次耗時波動很大1ms~800ms,最開始以為是gc的問題,對程式碼進行逃逸分析,看哪些變數被分配到堆上了,後來發現是併發程式設計時對一個切片併發的寫,導致存在競爭,類似下面的程式碼
func main() { //var count int array := make([]int, 100000) wg := new(sync.WaitGroup) for i := 0; i < 10; i++ { wg.Add(1) go func(a []int) { now := time.Now() print(a) fmt.Println("耗時:", time.Since(now)) wg.Done() }(array) } wg.Wait() } func print(array []int) { array[0] = 1 array[1] = 1 for i := 0; i < len(array); i++ { } //fmt.Println(array) }
output:
耗時: 85.532µs
耗時: 49.543µs
耗時: 53.306µs
耗時: 53.365µs
耗時: 47.73µs
耗時: 48.098µs
耗時: 70.815µs
耗時: 71.15µs
耗時: 89.213µs
耗時: 60.797µs
首先試一試逃逸分析:
go build -gcflags '-m -l' main.go
./main.go:27:20: print array does not escape ./main.go:11:15: make([]int, 100000) escapes to heap ./main.go:12:11: new(sync.WaitGroup) escapes to heap ./main.go:15:13: make([]int, 100000) escapes to heap ./main.go:17:6: func literal escapes to heap ./main.go:17:6: func literal escapes to heap ./main.go:20:16: "耗時:" escapes to heap ./main.go:20:37: time.Since(now) escapes to heap ./main.go:21:4: leaking closure reference wg ./main.go:17:15: main.func1 a does not escape ./main.go:20:15: main.func1 ... argument does not escape
結論:切片array由於size太大了被分配到堆上了,字串"耗時:"被分配到堆上,這裡分配到堆上的變數被頻繁建立地有newA和字串"耗時:",newA可以採用變數池sync.Pool解決,字串應該寫成常量形式
耗時47us~89us,很不穩定,對其進行競爭檢測
執行命令
go run -race main.go
output:
================== WARNING: DATA RACE Write at 0x00c420092000 by goroutine 7: main.print() /Users/qianxiaoli/work/mygopath/src/testpprof/bug/main.go:26 +0x49 main.main.func1() /Users/qianxiaoli/work/mygopath/src/testpprof/bug/main.go:17 +0x8c Previous write at 0x00c420092000 by goroutine 6: main.print() /Users/qianxiaoli/work/mygopath/src/testpprof/bug/main.go:26 +0x49 main.main.func1() /Users/qianxiaoli/work/mygopath/src/testpprof/bug/main.go:17 +0x8c Goroutine 7 (running) created at: main.main() /Users/qianxiaoli/work/mygopath/src/testpprof/bug/main.go:15 +0xe3 Goroutine 6 (running) created at: main.main() /Users/qianxiaoli/work/mygopath/src/testpprof/bug/main.go:15 +0xe3 ================== 耗時: 58.625µs ================== WARNING: DATA RACE Write at 0x00c420092008 by goroutine 7: main.print() /Users/qianxiaoli/work/mygopath/src/testpprof/bug/main.go:27 +0x6d main.main.func1() /Users/qianxiaoli/work/mygopath/src/testpprof/bug/main.go:17 +0x8c Previous write at 0x00c420092008 by goroutine 6: main.print() /Users/qianxiaoli/work/mygopath/src/testpprof/bug/main.go:27 +0x6d main.main.func1() /Users/qianxiaoli/work/mygopath/src/testpprof/bug/main.go:17 +0x8c Goroutine 7 (running) created at: main.main() /Users/qianxiaoli/work/mygopath/src/testpprof/bug/main.go:15 +0xe3 Goroutine 6 (running) created at: main.main() /Users/qianxiaoli/work/mygopath/src/testpprof/bug/main.go:15 +0xe3 ==================
結論:
顯然併發程式碼存在競爭,print函式對array併發寫操作導致競爭,執行耗時變長。由於切片在拷貝時,底層的陣列還是同一個,所以併發寫同一個陣列會產生競爭。
將程式碼加入變數池及切片拷貝
var arrayPool = sync.Pool{
New: func() interface{} {
a := make([]int, 2)
return a
},
}
func main() {
array := make([]int, 2)
wg := new(sync.WaitGroup)
for i := 0; i < 10000; i++ {
wg.Add(1)
newA := arrayPool.Get().([]int)
copy(newA, array)
go func(a []int) {
now := time.Now()
print(a)
fmt.Println("耗時:", time.Since(now))
wg.Done()
}(newA)
}
wg.Wait()
}
func print(array []int) {
array[0] = 1
array[1] = 1
for i := 0; i < len(array); i++ {
}
arrayPool.Put(array)
//fmt.Println(array)
}