pprof-内存信息查看

439 阅读12分钟

case

package main

import (
   "fmt"
   "net/http"
   _ "net/http/pprof"
   "runtime"
   "runtime/debug"
   "time"
)

var s0 string

func f(s1 string) {
   s0 = s1[:50] // s0 和 s1 共享底层内存
}

func demo() {
   s := make([]byte, 1<<20) // 1MB
   f(string(s))
}

func main() {
   runtime.GOMAXPROCS(1)
   debug.SetMemoryLimit(100 * 1024 * 1024)
   go func() {
      fmt.Println(http.ListenAndServe("localhost:6060", nil))
   }()

   go func() {
      for {
         var m runtime.MemStats
         runtime.ReadMemStats(&m)
         fmt.Printf("Alloc = %v MiB\tTotalAlloc = %v MiB\tSys = %v MiB\tNumGC = %v\n",
            bToMb(m.Alloc), bToMb(m.TotalAlloc), bToMb(m.Sys), m.NumGC)
         time.Sleep(5 * time.Second)
      }
   }()
   for i := 0; i < 100000; i++ {
      demo()
      //time.Sleep(time.Millisecond * 1) // 减慢速度方便观察
   }
   time.Sleep(20 * time.Minute)
}
func bToMb(b uint64) uint64 {
   return b / 1024 / 1024
}

查看内存调用图

预备知识

pprof 提供了四种主要的分析视图,对应着四种不同的指标:

  • alloc_objects: 自程序启动以来分配的总对象数。
  • alloc_space: 自程序启动以来分配的总内存大小(字节)。
  • inuse_objects: 当前堆上存活的对象数。
  • inuse_space: 当前堆上存活的内存大小(字节)。
查看方式
(base) macbook-pro-4:by_slice didiyu$ go tool pprof -http=:8080 http://localhost:6060/debug/pprof/heap
Fetching profile over HTTP from http://localhost:6060/debug/pprof/heap
Could not use temp dir /Users/didiyu/pprof: mkdir /Users/didiyu/pprof: not a directory
Saved profile in /var/folders/yd/mp5rd9bx1x3670cth1fp7n180000gn/T/pprof.main.alloc_objects.alloc_space.inuse_objects.inuse_space.007.pb.gz
Serving web UI on http://localhost:8080

然后打开链接http://localhost:8080/ui/, 默认是inuse_space当前存放的内存分配调用图。

image.png

看下图时的若干疑问

image.png

Q: 箭头和框中的值表示什么意思

箭头上的文本: 箭头上的文本表示从父函数到子函数的调用路径上分配的内存量。

例如,main.mainmain.demo 的箭头上标有 1184.27kB (inline),表示通过这个调用关系分配了 1184.27kB 的内存。(inline) 表示调用被内联了。

好的,我将针对你提供的调用图中 main.mainmain.demomain.demo2 相关的部分,包括红框内的文本和箭头上的文本,用表格进行详细说明。由于你使用的是 inuse_space 视图,因此所有数值都表示 采样时刻存活的内存 的加权平均值,而不是累积分配的总量。

框中的文本:

  1. 例如 2086.21kB (55.14%)1184.27kB (31.30%), 表示该函数及其调用的所有其他函数分配的总内存量。括号内的百分比表示该函数及其子函数分配的内存占总分配量的比例。
  2. 0 of ...: 在runtimemain函数中可以看到类似0 of 3783.36kB (100%),这表示该函数本身没有直接分配内存,但是它调用的函数分配了内存。括号内的百分比依然表示该函数及其子函数分配的内存占总分配量的比例。 tips:这里可以修改代码让main自身也分配些内存再看下效果。
Q: 图中的箭头和框中值的含义?
元素文本内容含义
main.main0 of 3270.48kB (86.46%)0 of ... 表示 main.main 函数自身 没有直接分配 任何堆内存。3270.48kB 表示在 采样时刻,通过 main.main 及其调用的子函数main.demomain.demo2)仍然存活的内存的 加权平均值 为 3270.48kB。(86.46%) 表示这 3270.48kB 占 所有采样中记录的存活内存总量的比例 为 86.46%。注意,这里的“总分配量”是指在 所有采样中记录的存活内存总量,而不是程序运行至今分配的所有内存的总和。
main.demo22086.21kB (55.15%)2086.21kB 表示在 采样时刻,通过 main.demo2 及其调用的子函数(虽然这里是内联的,可以忽略) 仍然存活的内存的 加权平均值 为 2086.21kB。由于 main.demo2 内部的 make([]byte, 1<<21) 分配了 2MB 的内存,并且这些内存在采样时刻仍然存活,因此这个值反映了这些存活内存的加权平均值。(55.15%) 表示这 2086.21kB 占 所有采样中记录的存活内存总量的比例 为 55.15%。
main.demo1184.27kB (31.31%)1184.27kB 表示在 采样时刻,通过 main.demo 及其调用的子函数(同样是内联,可以忽略) 仍然存活的内存的 加权平均值 为 1184.27kB。由于 main.demo 内部的 make([]byte, 1<<20) 分配了 1MB 的内存,并且这些内存在采样时刻仍然存活,因此这个值反映了这些存活内存的加权平均值。(31.31%) 表示这 1184.27kB 占 所有采样中记录的存活内存总量的比例 为 31.31%。
main.mainmain.demo2 的箭头2086.21kB (inline)表示在 采样时刻,通过 main.mainmain.demo2调用路径 仍然存活的内存的 加权平均值 为 2086.21kB。(inline) 表示 f2 函数的调用被内联到 demo2 函数中了。
main.mainmain.demo 的箭头1184.27kB (inline)表示在 采样时刻,通过 main.mainmain.demo调用路径 仍然存活的内存的 加权平均值 为 1184.27kB。(inline) 表示 f 函数的调用被内联到 demo 函数中了。
Q: 为什么图中框里显示的内存分配量那么小kb,不是应该分配了很多GB?

A: 我的理解:展示的是采样的加权平均值,基本可以等价为每次分配的平均值,每次分配是2M和1M,所以图中框里

相关知识点

  1. pprof采样 的,并且展示的是 加权平均值,所以图中显示的 1184.27kB2086.21kB 并不一定正好等于 1MB 和 2MB,而是 在采样时刻 存活的、通过 main.demomain.demo2 分配的内存的加权平均值。

  2. 调用图的两种主要类型: 调用图主要有两种类型,分别对应 inuse_*alloc_*

    2.1 inuse 调用图(例如 inuse_space

    • 展示的是 采样时刻 堆上 仍然存活 的对象的分配情况。
    • 节点上的数值表示该函数(及其子函数)在 采样时刻 仍然存活的对象所占用的内存大小。
    • 箭头上的数值表示通过该调用路径分配的、在采样时刻仍然存活 的内存大小。
    • 这种视图适合分析 当前内存占用,例如查找内存泄漏。

    2.2 alloc 调用图(例如 alloc_space

    • 展示的是程序运行至今 总共分配 的对象的分配情况,包括已经被垃圾回收器回收的对象。
    • 节点上的数值表示该函数(及其子函数) 总共 分配的内存大小。
    • 箭头上的数值表示通过该调用路径 总共 分配的内存大小。
    • 这种视图适合分析 内存分配的模式和总量,即使某些内存已经被回收。
Q:如何查看某行的内存分配?

方法1:

网页菜单:VIEW->Source,注意切换下Sample对比看下。 inuse_space有时没采样到一些函数,切换alloc_space才完整。

http://localhost:8080/ui/source?si=inuse_space

方法2:

命令行list 函数名,也可以看到。一般用图看方便些,有时需要切Sample类型,即使是导出的生产环境的pprof文件也可以本地看,就是代码版本要对应,这样才能准确定位。

Q:网页heap输出解读
heap profile: 1: 208 [172833: 181226504400] @ heap/1048576
1: 208 [1: 208] @ 0x1021eb5c1 0x1022685d0 0x1022d2c78 0x1022d29e8 0x102269b60 0x1022d2910 0x1022d28d9 0x102302750 0x102302779 0x1022275e4 0x102217924 0x10221780d 0x102250514
#  0x1022685cf    sync.(*Map).LoadOrStore+0x27f        /Users/didiyu/go/go1.22.2/src/sync/map.go:230
#  0x1022d2c77    internal/godebug.lookup+0x1f7        /Users/didiyu/go/go1.22.2/src/internal/godebug/godebug.go:159
#  0x1022d29e7    internal/godebug.(*Setting).Value.func1+0x57   /Users/didiyu/go/go1.22.2/src/internal/godebug/godebug.go:139
...略

0: 0 [0: 0] @ 0x10240feb4 0x10240fe55 0x10229f3b4 0x102414014 0x10241320c 0x102411938 0x10241f744 0x102420084 0x1023d6a88 0x1023d85f4 0x1023d961c 0x1023d5938 0x102250514
#  0x10240feb3    text/tabwriter.(*Writer).append+0x123  /Users/didiyu/go/go1.22.2/src/text/tabwriter/tabwriter.go:410
#  0x10240fe54    text/tabwriter.(*Writer).Write+0xc4    /Users/didiyu/go/go1.22.2/src/text/tabwriter/tabwriter.go:533
#  0x10229f3b3    fmt.Fprintf+0x83         /Users/didiyu/go/go1.22.2/src/fmt/print.go:225
...略

0: 0 [0: 0] @ 0x102413340 0x10241320c 0x102411938 0x10241f744 0x102420084 0x1023d6a88 0x1023d85f4 0x1023d961c 0x1023d5938 0x102250514
#  0x10241333f    runtime/pprof.writeHeapInternal+0x9f   /Users/didiyu/go/go1.22.2/src/runtime/pprof/pprof.go:602
#  0x10241320b    runtime/pprof.writeHeap+0x2b      /Users/didiyu/go/go1.22.2/src/runtime/pprof/pprof.go:572
#  0x102411937    runtime/pprof.(*Profile).WriteTo+0x147 /Users/didiyu/go/go1.22.2/src/runtime/pprof/pprof.go:369
...略

0: 0 [0: 0] @ 0x1022a9fdc 0x1022a9a8c 0x1022a9bfc 0x10229f3b4 0x1024209c0 0x102420554 0x1023d6a88 0x1023d85f4 0x1023d961c 0x1023d5938 0x102250514
#  0x1022a9fdb    bytes.growSlice+0x8b         /Users/didiyu/go/go1.22.2/src/bytes/buffer.go:249
#  0x1022a9a8b    bytes.(*Buffer).grow+0x12b    /Users/didiyu/go/go1.22.2/src/bytes/buffer.go:151
...略

0: 0 [1: 65536] @ 0x10238ea78 0x102398278 0x102398241 0x102418394 0x10241c804 0x1024134f8 0x10241320c 0x102411938 0x10241f744 0x102420084 0x1023d6a88 0x1023d85f4 0x1023d961c 0x1023d5938 0x102250514
#  0x10238ea77    compress/flate.(*compressor).init+0x2b7       /Users/didiyu/go/go1.22.2/src/compress/flate/deflate.go:582
#  0x102398277    compress/flate.NewWriter+0x287       /Users/didiyu/go/go1.22.2/src/compress/flate/deflate.go:667
#  0x102398240    compress/gzip.(*Writer).Write+0x250       /Users/didiyu/go/go1.22.2/src/compress/gzip/gzip.go:191
...略

0: 0 [86450: 90649395200] @ 0x102420ca8 0x102420c81 0x10221786c 0x102250514
#  0x102420ca7    main.demo+0x97    /Users/didiyu/Downloads/go/src/interview/1xunlianyin/12-26_27_28/go_leak/3/mem/by_slice/main.go:20
#  0x102420c80    main.main+0x70    /Users/didiyu/Downloads/go/src/interview/1xunlianyin/12-26_27_28/go_leak/3/mem/by_slice/main.go:40
#  0x10221786b    runtime.main+0x28b /Users/didiyu/go/go1.22.2/src/runtime/proc.go:271

0: 0 [86381: 90577043456] @ 0x102420c98 0x102420c81 0x10221786c 0x102250514
#  0x102420c97    main.demo+0x87    /Users/didiyu/Downloads/go/src/interview/1xunlianyin/12-26_27_28/go_leak/3/mem/by_slice/main.go:19
#  0x102420c80    main.main+0x70    /Users/didiyu/Downloads/go/src/interview/1xunlianyin/12-26_27_28/go_leak/3/mem/by_slice/main.go:40
#  0x10221786b    runtime.main+0x28b /Users/didiyu/go/go1.22.2/src/runtime/proc.go:271

# runtime.MemStats
....略

其他

一些坑

image.png 我为了验证main函数自身也分配内存情况,就是上文提到0 of 3783.36kB (100%)表示main自身分配为0。修改代码如下。

demo分配1,demo2分配2,main自身分配2M。

for i := 0; i < 100000; i++ {
   demo()
   go demo2() // 注意这里我改成了携程启动
   // main函数自身也分配点内存
   s := make([]byte, 1<<21) // 1MB*2
   f_main(string(s))
}

func f_main(s1 string) {
   sMain = s1[:50] // sMain 和 s1 共享底层内存
}
新pprof图片的几点变化
  1. inuse_space调用链路中,demo2成为独立分支。这是因为demo2在新携程中启动。 pprof的内存采样是按照携程为单位,采样的携程调用栈, 所以函数内部调用的函数如果用go启动,会从调用链中脱离。也就是说函数调用跨携程,无法把他们的调用关系串起来。 另外从火焰图也是可以看出来的。 image.png

  2. 2.04MB (38.95%) of 3.19MB (61.05%): 表示2.04M是自身分配, 3.19M是全部,所以还有1.16是子函数分配的。

灰色方块
  1. 代表程序在堆上 实际分配的内存块。它们的大小以 MB 为单位标注在方块内部。

  2. 与周围元素的关联:

    • 与上方方框(函数/goroutine)的关联: 上方的方框表示 负责分配 这些内存块的函数或 goroutine。例如,main demo2 方框上方的 2.04MB (38.95%) 表示 demo2 负责分配了 2.04MB 的内存。而下方的 2MB 方块则表示这 2.04MB 内存 最终 分配到了一个大小为 2MB 的内存块上。
    • 箭头: 连接方框和内存块的箭头表示内存的分配或传递关系。箭头上的数值通常与内存块的大小相近或相等(可能存在一些小的开销)。
  3. 对于大于 32KB 的对象,Go 内存分配器会直接从 mheap(堆)上分配内存。

  4. 默认情况下,pprof 的堆 profile 采样频率是每分配 512KB 内存进行一次采样。这意味着,如果你的程序只分配了几个 KB 的内存,那么很可能不会触发采样,也就不会被 pprof 记录下来。 我之前分配33KB,基本不会出现在灰色方块上,改成512KB就可以采样到。

  5. pprof 的内存采样是基于 每个 P 的 mcache 进行的

如下图,右下角的512KB image.png

inuse和alloc切换对比的一些发现

  1. 图中输入框可以搜索的,比如搜demo能匹配2个框节点。

http://localhost:8080/ui/?si=alloc_space

http://localhost:8080/ui/?si=inuse_space

参考资料

  1. github.com/google/ppro…
  2. github.com/google/ppro…