继续 golang 数码世界大冒险，上次说到

Forwarded from Welcome to the Black Parade

继续 golang 数码世界大冒险，上次说到 https://go.dev/play/p/kfAeED2Q2mJ 这个程序里的 callback 版本和 direct 版本有巨大的性能差距，群友 Bo 指出这是由于 literal func 导致的，把闭包移动到循环外避免每次循环都创建就可以了：

@@ -65,12 +65,13 @@ func consumeCallback(ring eventRing) (int, uint64) {
                ops    int
                digest uint64
        )
+       f := func(chunk []byte) error {
+               digest += binary.LittleEndian.Uint64(chunk[:8])
+               ops++
+               return nil
+       }
        for range totalItems {
-               err := readFunc(ring, func(chunk []byte) error {
-                       digest += binary.LittleEndian.Uint64(chunk[:8])
-                       ops++
-                       return nil
-               })
+               err := readFunc(ring, f)
                if err != nil {
                        panic(err)
                }

That's a very sharp observation!

但是喜欢随地乱拉闭包的我也很想知道如何在没有参照物 baseline 的情况下单纯通过 perf/pprof 发现这样的性能问题。不要想得太复杂，用常识去思考就能发现。

随便做一次 perf record -g + perf report --stdio，发现热点栈是这样的：

      99.62%     0.00%  purego_callback  purego_callback_repro  [.] runtime.goexit.abi0
              |
              ---runtime.goexit.abi0
                 runtime.main
                 main.main
                 |
                  --98.72%--main.consumeCallback2
                            |
                            |--79.03%--runtime.newobject

稍微敏锐一点应该都能注意到那个 80% runtime.newobject 不对劲，用 gdb disas/m 一下 main.consumeCallback 可以看到:

   0x000000000049cb68 <+104>:   call   0x413f00 <runtime.newobject>
   0x000000000049cb6d <+109>:   lea    0x14c(%rip),%rcx        # 0x49ccc0 <main.consumeCallback.func1>

说明确实是每次循环都创建了闭包。

但是把闭包移出循环之外，再做一次 perf record，发现依然有 80% 的 runtime.newobject

再用 gdb 看一次，发现循环里还有另一个闭包：

   0x000000000049cbc0 <+192>:   call   0x413f00 <runtime.newobject>
   0x000000000049cbc5 <+197>:   lea    0x94(%rip),%rcx        # 0x49cc60 <main.consumeCallback.readFunc.readWithPoll.consumeCallback.readFunc.func2.func3>

这个闭包看名字就知道是来自：

func readFunc(ring eventRing, f func(chunk []byte) error) error {
  return readWithPoll(func() error {
    return ring.readRecordFunc(func(chunk []byte) error {
      return f(chunk)
    })
  })
}

想办法把这个闭包初始化 hack 掉，发现把 ring 显式传入而不是 capture、并且直接 forward closure 而不新创建 closure 就可以了：

@@ -24,12 +24,12 @@ func (r *Ring) readRecordFunc(f func(chunk []byte) error) error {
        return f(r.data[:chunkBytes])
 }
 
-func readWithPoll(read func() error) error {
+func readWithPoll(ring eventRing, read func() error) error {
        return read()
 }
 
 func readInto(ring eventRing, rec *[chunkBytes]byte) error {
-       return readWithPoll(func() error {
+       return readWithPoll(ring, func() error {
                return ring.readRecordFunc(func(chunk []byte) error {
                        copy(rec[:], chunk)
                        return nil
@@ -38,10 +38,8 @@ func readInto(ring eventRing, rec *[chunkBytes]byte) error {
 }
 
 func readFunc(ring eventRing, f func(chunk []byte) error) error {
-       return readWithPoll(func() error {
-               return ring.readRecordFunc(func(chunk []byte) error {
-                       return f(chunk)
-               })
+       return readWithPoll(ring, func() error {
+               return ring.readRecordFunc(f)
        })
 }

这下性能直接提升了十倍，从 40 Mops/s -> 400+ Mops/s，看 perf record 里也不再有 runtime.newobject，全是干净的业务代码栈：

               |--97.11%--main.main
               |          |          
               |          |--94.43%--main.consumeCallback
               |          |          |          
               |          |          |--48.08%--main.(*Ring).readRecordFunc
               |          |          |          |          
               |          |          |           --33.64%--main.consumeCallback.func1

我觉得教训还是比较深刻的，我之前确实不知道 go 闭包有这么悲痛的性能问题，真就随手 closure。但 perf 方法论依然可以让我们在不具备相关知识储备的情况下重新发现这个问题，perf 好！

go.dev

Go Playground - The Go Programming Language