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