Profiling 这个词比较难翻译，一般译成画像。比如在案件侦破的时候会对嫌疑人做画像，从犯罪现场的种种证据，找到嫌疑人的各种特征，方便对嫌疑人进行排查；还有就是互联网公司会对用户信息做画像，通过了解用户各个属性（年龄、性别、消费能力等），方便为用户推荐内容或者广告。
在计算机性能调试领域里，profiling 就是对应用的画像，这里画像就是应用使用 CPU 和内存的情况。也就是说应用使用了多少 CPU 资源？都是哪些部分在使用？每个函数使用的比例是多少？有哪些函数在等待 CPU 资源？知道了这些，我们就能对应用进行规划，也能快速定位性能瓶颈。
Golang 提供了四种 pprof 类型：
| 类型 | 描述 |
|---|---|
| CPU profile | 报告程序的 CPU 使用情况，按照一定频率去采集应用程序在 CPU 和寄存器上面的数据。 |
| Memory Profile | 报告程序的内存使用情况。 |
| Block Profiling | 报告 goroutines 不在运行状态的情况，可以用来分析和查找死锁等性能瓶颈。 |
| Goroutine Profiling | 报告 goroutines 的使用情况，有哪些 goroutine，它们的调用关系是怎样的。 |
做 Profiling 第一步就是怎么获取应用程序的运行情况数据。go 语言提供了 runtime/pprof 和 net/http/pprof 两个库。同时，按照我们的服务类型，我们可以分为种收集方式：
如果你的应用是一次性的，运行一段时间就结束。那么最好的办法，就是在应用退出的时候把 profiling 的报告保存到文件中，进行分析。对于这种情况，可以使用 runtime/pprof 库。
pprof 封装了很好的接口供我们使用，比如要想进行 CPU Profiling，可以调用 pprof.StartCPUProfile() 方法，它会对当前应用程序进行 CPU profiling，并写入到提供的参数中 （w io.Writer），要停止调用StopCPUProfile() 即可。
去除错误处理只需要三行内容，一般把部分内容写在 main.go 文件中，应用程序启动之后就开始执行：
f, err := os.Create(*cpuprofile)
...
pprof.StartCPUProfile(f)
defer pprof.StopCPUProfile()
应用执行结束后，就会生成一个文件，保存了我们的 CPU profiling 数据。如果，我们想要获得内存的数据，直接使用 WriteHeapProfile 就行，不用 start 和 stop 这两个步骤了：
f, err := os.Create(*memprofile) pprof.WriteHeapProfile(f) f.Close()
如果你的应用是一直运行的，比如 web 应用，那么可以使用 net/http/pprof 库，它能够在提供 HTTP 服务进行分析。
如果使用了默认的 http.DefaultServeMux（通常是代码直接使用 http.ListenAndServe(“0.0.0.0:8000”, nil)），只需要添加一行：
import _ "net/http/pprof"
如果你使用自定义的 Mux，则需要手动注册一些路由规则：
r.HandleFunc("/debug/pprof/", pprof.Index)
r.HandleFunc("/debug/pprof/cmdline", pprof.Cmdline)
r.HandleFunc("/debug/pprof/profile", pprof.Profile)
r.HandleFunc("/debug/pprof/symbol", pprof.Symbol)
r.HandleFunc("/debug/pprof/trace", pprof.Trace)
不管哪种方式，你的 HTTP 服务都会多出 /debug/pprof endpoint，访问它会得到类似下面的内容：
/debug/pprof/
profiles:
0 block
62 goroutine
444 heap
30 threadcreate
full goroutine stack dump
这个路径下还有几个子页面：
| 页面 | 描述 |
|---|---|
| /debug/pprof/profile | 访问这个链接会自动进行 CPU profiling，持续 30s，并生成一个文件供下载。 |
| /debug/pprof/heap | Memory Profiling 的路径，访问这个链接会得到一个内存 Profiling 结果的文件。 |
| /debug/pprof/block | block Profiling 的路径。 |
| /debug/pprof/goroutines | 运行的 goroutines 列表，以及调用关系。 |
go tool pprof 命令用于获取和分析 Profiling 数据。
能通过对应的库获取想要的 Profiling 数据之后（不管是文件还是 http），下一步就是要对这些数据进行保存和分析，我们可以使用 go tool pprof 命令行工具。
注意：获取的 Profiling 数据是动态的，要想获得有效的数据，请保证应用处于较大的负载（比如正在生成中运行的服务，或者通过其他工具模拟访问压力）。否则如果应用处于空闲状态，得到的结果可能没有任何意义。
go tool pprof 最简单的使用方式为 go tool pprof [binary] [source]，binary 是应用的二进制文件，用来解析各种符号；source 表示 profile 数据的来源，可以是本地的文件，也可以是 http 地址。比如：
go tool pprof -seconds 60 10.20.55.101:9089/debug/pprof/profile
Fetching profile over HTTP from http://10.20.55.101:9089/debug/pprof/profile?seconds=60
Please wait... (1m0s)
Local symbolization failed for dbmanager: open /home/haicoder/hai/bin/dbmanager: no such file or directory
Some binary filenames not available. Symbolization may be incomplete.
Try setting PPROF_BINARY_PATH to the search path for local binaries.
Saved profile in /root/pprof/pprof.dbmanager.samples.cpu.008.pb.gz
File: dbmanager
Type: cpu
Time: Apr 3, 2019 at 11:20am (CST)
Duration: 1mins, Total samples = 12.36s (20.56%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
这个命令会进行 CPU profiling 分析，等待一段时间（默认是 30s，如果在 url 最后加上 ?seconds=60 参数可以调整采集数据的时间为60s）之后，我们就进入了一个交互式命令行，可以对解析的结果进行查看和导出。可以通过help 查看支持的自命令有哪些。
它列出最耗时间的地方：
(pprof) top20
Showing nodes accounting for 6810ms, 55.10% of 12360ms total
Dropped 484 nodes (cum <= 61.80ms)
Showing top 20 nodes out of 206
flat flat% sum% cum cum%
1160ms 9.39% 9.39% 1350ms 10.92% syscall.Syscall
830ms 6.72% 16.10% 830ms 6.72% runtime.futex
700ms 5.66% 21.76% 1510ms 12.22% runtime.scanobject
480ms 3.88% 25.65% 1660ms 13.43% runtime.mallocgc
430ms 3.48% 29.13% 430ms 3.48% runtime.memclrNoHeapPointers
320ms 2.59% 31.72% 320ms 2.59% runtime.epollwait
300ms 2.43% 34.14% 300ms 2.43% runtime.usleep
280ms 2.27% 36.41% 280ms 2.27% runtime.nextFreeFast
270ms 2.18% 38.59% 270ms 2.18% runtime.heapBitsForObject
260ms 2.10% 40.70% 260ms 2.10% runtime.memmove
260ms 2.10% 42.80% 290ms 2.35% runtime.runqgrab
240ms 1.94% 44.74% 2990ms 24.19% base/redis.(*RedisCon).readReply
200ms 1.62% 46.36% 460ms 3.72% runtime.deferreturn
200ms 1.62% 47.98% 250ms 2.02% runtime.freedefer
180ms 1.46% 49.43% 840ms 6.80% bufio.(*Reader).ReadSlice
160ms 1.29% 50.73% 160ms 1.29% runtime.markBits.isMarked (inline)
140ms 1.13% 51.86% 140ms 1.13% runtime.spanClass.noscan (inline)
140ms 1.13% 52.99% 140ms 1.13% runtime.step
130ms 1.05% 54.05% 160ms 1.29% runtime.heapBitsSetType
130ms 1.05% 55.10% 160ms 1.29% runtime.lock
(pprof)
每一行表示一个函数的信息。前两列表示函数在 CPU 上运行的时间以及百分比；第三列是当前所有函数累加使用 CPU 的比例；第四列和第五列代表这个函数以及子函数运行所占用的时间和比例（也被称为累加值 cumulative），应该大于等于前两列的值；最后一列就是函数的名字。
如果应用程序有性能问题，上面这些信息应该能告诉我们时间都花费在哪些函数的执行上了。
pprof 不仅能打印出最耗时的地方(top)，还能列出函数代码以及对应的取样数据(list)、汇编代码以及对应的取样数据(disasm)，而且能以各种样式进行输出，比如 svg、gv、callgrind、png、gif 等等。
其中一个非常便利的是 web 命令，在交互模式下输入 web，就能自动生成一个 svg 文件，并跳转到浏览器打开，生成了一个函数调用图。
这个调用图包含了更多的信息，而且可视化的图像能让我们更清楚地理解整个应用程序的全貌。图中每个方框对应一个函数，方框越大代表执行的时间越久（包括它调用的子函数执行时间，但并不是正比的关系）；方框之间的箭头代表着调用关系，箭头上的数字代表被调用函数的执行时间。
要想更细致分析，就要精确到代码级别了，看看每行代码的耗时，直接定位到出现性能问题的那行代码。pprof 也能做到，list 命令后面跟着一个正则表达式，就能查看匹配函数的代码以及每行代码的耗时
(pprof) list main
Total: 12.36s
ROUTINE ======================== main.(*DbServer).AcInfoFetchByUser in E:/go_server/haicoder-server/src/dbmanager/db.acc.go
0 20ms (flat, cum) 0.16% of Total
Error: Could not find file E:/go_server/haicoder-server/src/dbmanager/db.acc.go on path /root/pprof
ROUTINE ======================== main.(*DbServer).AppGWLogin in E:/go_server/haicoder-server/src/dbmanager/db.online.go
0 10ms (flat, cum) 0.081% of Total
Error: Could not find file E:/go_server/haicoder-server/src/dbmanager/db.online.go on path /root/pprof
ROUTINE ======================== main.(*DbServer).ACDot in E:/go_server/haicoder-server/src/dbmanager/db.active.go
0 10ms (flat, cum) 0.081% of Total
Error: Could not find file E:/go_server/haicoder-server/src/dbmanager/db.active.go on path /root/pprof
ROUTINE ======================== main.(*DbServer).ClearUnReadMsg in E:/go_server/haicoder-server/src/dbmanager/db.stat.go
0 10ms (flat, cum) 0.081% of Total
Error: Could not find file E:/go_server/haicoder-server/src/dbmanager/db.stat.go on path /root/pprof
ROUTINE ======================== main.(*DbServer).FetchMyAAInfo in E:/go_server/haicoder-server/src/dbmanager/db.answer.go
0 50ms (flat, cum) 0.4% of Total
Error: Could not find file E:/go_server/haicoder-server/src/dbmanager/db.answer.go on path /root/pprof
ROUTINE ======================== main.(*DbServer).FetchUserAALis in E:/go_server/haicoder-server/src/dbmanager/db.answer.go
0 10ms (flat, cum) 0.081% of Total
Error: Could not find file E:/go_server/haicoder-server/src/dbmanager/db.answer.go on path /root/pprof
ROUTINE ======================== main.(*DbServer).GetAccount in E:/go_server/haicoder-server/src/dbmanager/dbmanager.login.go
0 20ms (flat, cum) 0.16% of Total
Error: Could not find file E:/go_server/haicoder-server/src/dbmanager/dbmanager.login.go on path /root/pprof
ROUTINE ======================== main.(*DbServer).GetAtList in E:/go_server/haicoder-server/src/dbmanager/db.relation3.go
0 240ms (flat, cum) 1.94% of Total
Error: Could not find file E:/go_server/haicoder-server/src/dbmanager/db.relation3.go on path /root/pprof
ROUTINE ======================== main.(*DbServer).GetBlackList in E:/go_server/haicoder-server/src/dbmanager/db.relation3.go
0 20ms (flat, cum) 0.16% of Total
Error: Could not find file E:/go_server/haicoder-server/src/dbmanager/db.relation3.go on path /root/pprof
ROUTINE ======================== main.(*DbServer).GetCommentsList in E:/go_server/haicoder-server/src/dbmanager/db.comments.go
0 20ms (flat, cum) 0.16% of Total
Error: Could not find file E:/go_server/haicoder-server/src/dbmanager/db.comments.go on path /root/pprof
ROUTINE ======================== main.(*DbServer).GetFansList in E:/go_server/haicoder-server/src/dbmanager/db.relation3.go
0 400ms (flat, cum) 3.24% of Total
Error: Could not find file E:/go_server/haicoder-server/src/dbmanager/db.relation3.go on path /root/pprof
ROUTINE ======================== main.(*DbServer).GetGoldUser in E:/go_server/haicoder-server/src/dbmanager/db.gold.go
0 10ms (flat, cum) 0.081% of Total
如果想要了解对应的汇编代码，可以使用 disadm <regex> 命令。这两个命令虽然强大，但是在命令行中查看代码并不是很方面，所以你可以使用 weblist 命令，用法和两者一样，但它会在浏览器打开一个页面，能够同时显示源代码和汇编代码。
注意：更详细的 pprof 使用方法可以参考 pprof --help 或者 pprof 文档。
peek 是用来查询具体哪个函数的调用关系以及耗时：
(pprof) peek GetUserById
Showing nodes accounting for 13.53s, 100% of 13.53s total
----------------------------------------------------------+-------------
flat flat% sum% cum cum% calls calls% + context
----------------------------------------------------------+-------------
0.18s 58.06% | main.(*DbServer).GetAtList
0.11s 35.48% | main.(*DbServer).OMGetAAtList
0.01s 3.23% | main.(*DbServer).LikeMe
0.01s 3.23% | main.UserInExitRoom
0 0% 0% 0.31s 2.29% | dbmanager/mongodb.GetUserById
0.31s 100% | dbmanager/mongodb.GetUserInfo
----------------------------------------------------------+-------------
0.50s 100% | main.(*DbServer).GetUserById
0 0% 0% 0.50s 3.70% | dbmanager/mongodb.GetUserByIdAlias
0.50s 100% | dbmanager/mongodb.GetUserInfo
----------------------------------------------------------+-------------
0.50s 100% | protocol/db._DBServerInside_GetUserById_Handler
0 0% 0% 0.50s 3.70% | main.(*DbServer).GetUserById
0.50s 100% | dbmanager/mongodb.GetUserByIdAlias
----------------------------------------------------------+-------------
0.52s 100% | google.golang.org/grpc.(*Server).processUnaryRPC
0 0% 0% 0.52s 3.84% | protocol/db._DBServerInside_GetUserById_Handler
0.50s 96.15% | main.(*DbServer).GetUserById
0.01s 1.92% | google.golang.org/grpc.(*Server).processUnaryRPC.func3
0.01s 1.92% | runtime.assertE2I
----------------------------------------------------------+-------------
要想获得内存使用 Profiling 信息，只需要把数据源修改一下就行（对于 http 方式来说就是修改 url 的地址，从 /debug/pprof/profile 改成 /debug/pprof/heap）
go tool pprof -seconds 60 10.20.55.101:9089/debug/pprof/heap
Fetching profile over HTTP from http://10.20.55.101:9089/debug/pprof/heap?seconds=60
Please wait... (1m0s)
Local symbolization failed for dbmanager: open /home/haicoder/hai/release/bin/dbmanager: no such file or directory
Some binary filenames not available. Symbolization may be incomplete.
Try setting PPROF_BINARY_PATH to the search path for local binaries.
Saved profile in /root/pprof/pprof.dbmanager.alloc_objects.alloc_space.inuse_objects.inuse_space.002.pb.gz
File: dbmanager
Type: inuse_space
Time: Apr 3, 2019 at 11:29am (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
和 CPU Profiling 使用一样，使用 top N 可以打印出使用内存最多的函数列表：
(pprof) top20
Showing nodes accounting for 876.41MB, 95.20% of 920.65MB total
Dropped 356 nodes (cum <= 4.60MB)
Showing top 20 nodes out of 87
flat flat% sum% cum cum%
438.77MB 47.66% 47.66% 438.77MB 47.66% base/redis.NewCmdPool
171.01MB 18.58% 66.23% 267.02MB 29.00% base/redis.(*RedisCon).Do
96MB 10.43% 76.66% 96MB 10.43% base/redis.(*RedisCon).SendToConn
31.50MB 3.42% 80.08% 167.01MB 18.14% common.(*ImplRedisCluster).Exists
29.50MB 3.20% 83.29% 29.50MB 3.20% fmt.Sprintf
24MB 2.61% 85.90% 24MB 2.61% base/redis.(*RedisCon).DoArg1
16MB 1.74% 87.63% 40MB 4.34% base/redis.(*RedisOp).Get
14MB 1.52% 89.15% 84.50MB 9.18% common.(*ImplRedisCluster).GetObject1
10MB 1.09% 90.24% 10MB 1.09% dbmanager/redisdb.checklovekey
9.50MB 1.03% 91.27% 31.50MB 3.42% common.(*ImplRedisCluster).Hget
6.41MB 0.7% 91.97% 6.41MB 0.7% bufio.NewWriterSize (inline)
6MB 0.65% 92.62% 6MB 0.65% dbmanager/redisdb.CRKey
4.61MB 0.5% 93.12% 4.61MB 0.5% bufio.NewReaderSize
4.59MB 0.5% 93.62% 443.36MB 48.16% base/redis.(*RedisCon).init
4.50MB 0.49% 94.11% 10MB 1.09% common.(*ImplRedisCluster).Expire
3.50MB 0.38% 94.49% 69MB 7.50% dbmanager/mongodb.GetUserById
2MB 0.22% 94.71% 5.27MB 0.57% common.(*ImplRedisCluster).Geodist
2MB 0.22% 94.92% 6.50MB 0.71% common.(*ImplRedisCluster).Hincrby
1.50MB 0.16% 95.09% 6.50MB 0.71% common.(*ImplRedisCluster).Hset
1MB 0.11% 95.20% 5.50MB 0.6% base/redis.Args.AddFlat
(pprof)
每一列的含义也是类似的，只不过从 CPU 使用时间变成了内存使用大小，就不多解释了。类似的，web 命令也能生成 svg 图片在浏览器中打开，从中可以看到函数调用关系，以及每个函数的内存使用多少。
需要注意的是，默认情况下，统计的是内存使用大小，如果执行命令的时候加上 --inuse_objects 可以查看每个函数分配的对象数；–alloc-space 查看分配的内存空间大小。
这里还要提两个比较有用的方法，如果应用比较复杂，生成的调用图特别大，看起来很乱，有两个办法可以优化：
在我们使用 go test 进行测试时，我们还有使用相关的参数，来诊断程序的性能：
| 参数 | 描述 |
|---|---|
| -cpuprofile | cpu profiling 数据要保存的文件地址。 |
| -memprofile | memory profiling 数据要报文的文件地址。 |
比如下面执行测试的同时，也会执行 CPU profiling，并把结果保存在 cpu.prof 文件中：
$ go test -bench . -cpuprofile=cpu.prof
执行结束之后，就会生成 main.test 和 cpu.prof 文件。要想使用 go tool pprof，需要指定的二进制文件就是 main.test。
需要注意的是，Profiling 一般和性能测试一起使用，这个原因在前文也提到过，只有应用在负载高的情况下Profiling 才有意义。
我们输入以下命令，开始收集收集：
go tool pprof -seconds 60 10.20.55.101:9089/debug/pprof/profile
Fetching profile over HTTP from http://10.20.55.101:9089/debug/pprof/profile?seconds=60
Please wait... (1m0s)
Local symbolization failed for dbmanager: open /home/haicoder/hai/release/bin/dbmanager: no such file or directory
Some binary filenames not available. Symbolization may be incomplete.
Try setting PPROF_BINARY_PATH to the search path for local binaries.
Saved profile in /root/pprof/pprof.dbmanager.samples.cpu.010.pb.gz
File: dbmanager
Type: cpu
Time: Apr 3, 2019 at 4:36pm (CST)
Duration: 1mins, Total samples = 16.64s (27.72%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof)
使用 web 命令生成 svg 调用图，命令如下：
(pprof) web xdg-open: no method available for opening '/tmp/pprof001.svg' (pprof)
使用 list 命令，查看调用时间，命令如下：
(pprof) list main
Total: 16.64s
ROUTINE ======================== main.(*DbServer).AddUserSocre in /home/haihai/haicoder-server/src/dbmanager/db.level.go
0 30ms (flat, cum) 0.18% of Total
Error: open /home/haihai/haicoder-server/src/dbmanager/db.level.go: no such file or directory
ROUTINE ======================== main.(*DbServer).AppGWLogin in /home/haihai/haicoder-server/src/dbmanager/db.online.go
0 10ms (flat, cum) 0.06% of Total
Error: open /home/haihai/haicoder-server/src/dbmanager/db.online.go: no such file or directory
ROUTINE ======================== main.(*DbServer).AppGWLogout in /home/haihai/haicoder-server/src/dbmanager/db.online.go
0 10ms (flat, cum) 0.06% of Total
Error: open /home/haihai/haicoder-server/src/dbmanager/db.online.go: no such file or directory
ROUTINE ======================== main.(*DbServer).ACDot in /home/haihai/haicoder-server/src/dbmanager/db.active.go
0 10ms (flat, cum) 0.06% of Total
Error: open /home/haihai/haicoder-server/src/dbmanager/db.active.go: no such file or directory
ROUTINE ======================== main.(*DbServer).FetchDolist in /home/haihai/haicoder-server/src/dbmanager/db.love.go
0 10ms (flat, cum) 0.06% of Total
Error: open /home/haihai/haicoder-server/src/dbmanager/db.love.go: no such file or directory
ROUTINE ======================== main.(*DbServer).FetchMyInfo in /home/haihai/haicoder-server/src/dbmanager/db.answer.go
0 60ms (flat, cum) 0.36% of Total
Error: open /home/haihai/haicoder-server/src/dbmanager/db.answer.go: no such file or directory
ROUTINE ======================== main.(*DbServer).FetchAALis in /home/haihai/haicoder-server/src/dbmanager/db.answer.go
0 10ms (flat, cum) 0.06% of Total
Error: open /home/haihai/haicoder-server/src/dbmanager/db.answer.go: no such file or directory
ROUTINE ======================== main.(*DbServer).GetAtList in /home/haihai/haicoder-server/src/dbmanager/db.relation3.go
0 260ms (flat, cum) 1.56% of Total
使用 peek 命令，查看函数的具体耗时，命令如下：
(pprof) peek GetUserById
Showing nodes accounting for 16.64s, 100% of 16.64s total
----------------------------------------------------------+-------------
flat flat% sum% cum cum% calls calls% + context
----------------------------------------------------------+-------------
0.18s 56.25% | main.(*DbServer).GetAtList
0.04s 12.50% | main.(*DbServer).OMGetAAtList
0.03s 9.38% | main.(*DbServer).LikeMe
0.02s 6.25% | main.(*DbServer).GetBlackList
0.02s 6.25% | main.(*DbServer).GetAttEachother
0.01s 3.12% | dbmanager/mongodb.GetAnswerQuestionRankByUID
0.01s 3.12% | main.(*DbServer).GetDoList
0.01s 3.12% | main.(*DbServer).GetUserBill
0 0% 0% 0.32s 1.92% | dbmanager/mongodb.GetUserById
0.32s 100% | dbmanager/mongodb.GetUserInfo
----------------------------------------------------------+-------------
0.61s 89.71% | main.(*DbServer).GetUserById
0.06s 8.82% | main.(*DbServer).RPckShow
0.01s 1.47% | main.PackageList
0 0% 0% 0.68s 4.09% | dbmanager/mongodb.GetUserByIdAlias
0.67s 98.53% | dbmanager/mongodb.GetUserInfo
0.01s 1.47% | runtime.newobject
----------------------------------------------------------+-------------
0.63s 100% | protocol/db._DBServerInside_GetUserById_Handler
0 0% 0% 0.63s 3.79% | main.(*DbServer).GetUserById
0.61s 96.83% | dbmanager/mongodb.GetUserByIdAlias
0.01s 1.59% | protocol.MakeRespBaseInfo
0.01s 1.59% | runtime.newobject
----------------------------------------------------------+-------------
0.66s 100% | google.golang.org/grpc.(*Server).processUnaryRPC
0 0% 0% 0.66s 3.97% | protocol/db._DBServerInside_GetUserById_Handler
0.63s 95.45% | main.(*DbServer).GetUserById
0.03s 4.55% | google.golang.org/grpc.(*Server).processUnaryRPC.func3
----------------------------------------------------------+-------------
