1. 程式人生 > >golang逃逸分析和競爭檢測

golang逃逸分析和競爭檢測

最近在線上發現一塊程式碼邏輯在執行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)
}