最近在线上发现一块代码逻辑在执行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) }