最近在線上發現一塊代碼邏輯在執行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,很不穩定,對其進行競爭檢測ui
運行命令code
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併發寫操做致使競爭,執行耗時變長。因爲切片在拷貝時,底層的數組仍是同一個,因此併發寫同一個數組會產生競爭。it
將代碼加入變量池及切片拷貝io
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) }