10 性能分析

秦穆之2023/5/21大约 10 分钟

本文为极客时间《Go语言核心36讲》的学习笔记，梳理了相关的知识点。

1. 场景

当我们需要对一个程序进行性能分析的时，通常只有两种情况：
第一种，这个程序是个重要模块，上线后要迎接大流量场景者是支持核心业务线。不能出问题，出了问题就是大问题，今年的绩效就要玩砸了。第二种，程序已经出了性能问题。

第一种情况，需要我们大范围的进行压测，通过循序渐进的方式获取程序的性能瓶颈，为后续的技术优化和应急方案提供详细的指标和场景。比如：把QPS压到1W时，CPU、内存、响应耗时和协程数等指标具体是多少。后续，以此为参考制定优化指标和方案。
第二种情况，需要我们能够快速定位问题原因，尽快修复，减少损失。但，这是理论上。正常线上出现性能问题，应该先执行上文提到的应急方案，减小损失，保留现场。等危机解除，服务稳定后再分析程序的性能问题。

2. 工具

这里先说明下，日志不同于性能分析，也不同于功能测试。很多同学开始写程序的时候习惯性添加很多的日志，以此来观察代码运行情况，这不是一个好习惯。通常情况下，我们会：

在请求入口添加trace，便于追踪整个业务流程，记录每个操作的耗时；
在代码写完以后进行Test自测，找到关键节点和容易出现Error的地方；
在上线后进行小范围压测，摸排服务的性能，制定扩容策略；
在业务的关键节点上添加日志，比如接收到用户提交的数据（网关日志），数据库查询记录（慢日志）等等；
在线上出现难以排查的故障时，使用pprof分析服务状态和并发数，缩小排查范围，确定问题的大致方向。

成为一个独立服务的实际Owner，本质上需要两点：代码熟悉度+业务理解。最快提升代码熟悉度的方法不是看源码和技术方案，而是出现线上问题时的排查和修复。这也是这个行业的一个特色，总是在车速200码的时候换补胎换机油。

2.1. pprof

pprof 是用于可视化和分析性能分析数据的工具，是后续最常用的性能排查工具，也是GO开发人员必备技能。

2.2. 压测工具ab wrk

Apache Benchmark（ab）是Apache安装包中自带的压力测试工具，简单易用。属于上古神器，目前还能用，用的还很多。这个工具的使用非常非常简单，按照说明书执行即可。

wrk是一款C语言开发的开源压测工具，是用的比较多的压测工具。可以直接按照开源文档操作就行。
GitHub - wg/wrk: Modern HTTP benchmarking tool

这里还有一个基于Go语言的压测工具go-wrk，也可以看下：
GitHub - tsliwowicz/go-wrk: go-wrk - a HTTP benchmarking tool based in spirit on the excellent wrk tool (https://github.com/wg/wrk)

2.3. 火焰图与GO-Torch

官方自带的pproft也是支持火焰图或者调用关系图的，需要安装一个graphviz，也可以使用三方包查看性能图。

**一图胜千言。**火焰图（flame graph）是性能分析中最常用到的图例，通过这个图可以快速定位到性能瓶颈。Go语言中常常使用GO-Torch来生成火焰图。

GO-Torch是Uber开源的一个工具包，可以直接读取pprof生成的文件，生成一张可以交互的SVG图片。后续我们会详细展示下如何使用GO-Torch。

2.4. Trace

Trace的主要作用是追踪程序运行过程中信息，通过这些信息可以观察程序在运行过程中都了什么，用了多长时间。从功能和使用的角度来看，有点像编译器的debug模式。另外，Trace的思想是可以推而广之的：我们在某一块代码中使用Trace来追踪代码调用情况，也可以在整个服务中使用Trace来追踪一个请求的处理全部流程，都有谁参与，耗时多久等。

Trace是日常开发中最不常用的功能之一，只有在个别性能出现瓶颈或者有其他疑难杂症的时候才会用到它。在企业服务中，Trace也不常用，但必须要有。这个不起眼的小东西是微服务架构中必备的运维工具。它一方面可以提供链路追踪的功能，另一方面还可以提供服务之间的调用关系，在运维体系中举足轻重。

访问B站的请求头部有一个字段叫做trace_id就是Trace服务下发的。

func testPprof() {

	file1, _ := os.Create("./cpu.pprof") //开启一个文件
	_ = pprof.StartCPUProfile(file1)     //记录CPU的使用情况
	file2, _ := os.Create("./mem.pprof")
	_ = pprof.WriteHeapProfile(file2) //记录内存的使用情况
	defer func() {
		pprof.StopCPUProfile() //这个必须要有
		_ = file1.Close() //随手关闭文件
		_ = file2.Close()
	}()

	tick := time.NewTicker(time.Second / 100) //一秒执行一百次
	closed := make(chan bool)
	go func() {
		time.Sleep(10 * time.Second) //10秒之后结束定时器，使for range 终止
		tick.Stop()
		closed <- true
		fmt.Printf("tick is closed\n")
	}()
	for range tick.C { //一个不常用的用法，tick.C只要不close，就会一直阻塞在这里
		go forSelect(closed) //理论上会执行10*100次
		if <-closed {        //收到关闭消息后，跳出循环
			break
		}
	}
	fmt.Printf("关注香香编程喵喵喵，关注香香编程谢谢喵喵喵！\n")
}

func forSelect(c chan bool) {
	var ch chan int //一个典型的错误用法，此时ch是nil
	for {
		select {
		case _ = <-ch: //读取一个为nil的通道，一定会阻塞
			fmt.Printf("关注香香编程喵喵喵，关注香香编程谢谢喵喵喵！")
		case fl := <-c: //当定时器终止时跳出循环
			if fl {
				fmt.Printf("定时器已终止\n")
				return
			}
		default:
			//每次循环都会默认走这里,可以去掉注释看下
			//fmt.Printf("default")
		}
	}
}

接下来我们执行下这个代码，会在根目录下生成两个文件：cpu.pprof和mem.pprof。这个时候，我们就可以使用：

go tool pprof ./cpu.pprof

进入到一个交互文件界面中，在这里我们可以使用一些命令查看具体的数值。但我们一般不会这么用，毕竟命令行不好用啊。上面命令执行完后，输入TOP大致长这样：

Type: cpu
Time: Apr 5, 2023 at 5:44pm (CST)
Duration: 5.12s, Total samples = 4.47s (87.37%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top //这是我们输入的命令
Showing nodes accounting for 4.45s, 99.55% of 4.47s total
Dropped 6 nodes (cum <= 0.02s)
Showing top 10 nodes out of 18
      flat  flat%   sum%        cum   cum%
     1.34s 29.98% 29.98%      1.34s 29.98%  runtime.unlock2
     1.17s 26.17% 56.15%      1.17s 26.17%  runtime.lock2
     1.09s 24.38% 80.54%      4.25s 95.08%  runtime.selectgo
     0.33s  7.38% 87.92%      1.51s 33.78%  runtime.sellock
     0.21s  4.70% 92.62%      1.55s 34.68%  runtime.selunlock
     0.17s  3.80% 96.42%      4.42s 98.88%  main.forSelect
     0.09s  2.01% 98.43%      0.09s  2.01%  runtime.fastrand (inline)
     0.04s  0.89% 99.33%      0.05s  1.12%  runtime.kevent
     0.01s  0.22% 99.55%      0.10s  2.24%  runtime.fastrandn (inline)
         0     0% 99.55%      0.05s  1.12%  runtime.findRunnable
(pprof)

3.1.2. 字段含义

flat：当前函数占用 profile 样本的数量
flat%：当前函数占用 profile 样本的百分比
sum%：当前行以上所有 flat% 的和
cum：累计的 profile 样本量（cum全写：cumulative）
cum%：累计 profile 样本量占总量的百分比

3.1.3. 常用的命令行

top：默认展示前 10 条样本计数最高的，后面接数字，则显示指定数字的条目，如：top3。
traces：输出所有 profile 的统计信息。
list：输出给定正则表达式匹配的方法源码，list 后面是可以接正则表达式。
tree：输出所有调用关系。
web：生成 profile 的 svg 矢量图片并用 web 打开，如果不指定参数则显示所有，给定指定方法，则显示指定的方法。
pdf：生成 pdf 的 profile 文件，里面展示 profile 图片的内容。
cum：按照累计的 profile 样本量排序。
flat：按照当前函数占用的 profile 排序。

使用这个命令，可以直接在网页上看到相关信息，并且可以进行交互。这是我们最常用到排查方式！

go tool pprof -http=:8080 ./cpu.pprof

3.2. net/http/pprof

这个包的用法相对简单点，主要用来分析WEB服务的状态，直接看下代码：

// _ "net/http/pprof" 需要在文件头部 引入这个包
func testWebPprof() {
	go func() {
		if err := http.ListenAndServe("0.0.0.0:8080", nil); err != nil {
			fmt.Printf("%v", err) //添加一个监听端口
		}
	}()

	tick := time.NewTicker(time.Second / 100) //一秒执行一百次
	closed := make(chan bool)
	go func() {
		time.Sleep(10 * time.Second) //10秒之后结束定时器，使for range 终止
		tick.Stop()
		closed <- true
		fmt.Printf("tick is closed\n")
	}()
	for range tick.C { //一个不常用的用法，tick.C只要不close，就会一直阻塞在这里
		go forSelect(closed) //理论上会执行10*100次
		if <-closed {        //收到关闭消息后，跳出循环
			break
		}
	}
	fmt.Printf("关注香香编程喵喵喵，关注香香编程谢谢喵喵喵！\n")
}