这是我参与「第三届青训营 -后端场」笔记创作活动的的第3篇笔记
前言
本次课程讲解大体分为两个部分：讲述高质量编码的规范和性能调优实战，这篇文章侧重于复现使用pprof工具性能调优的实践过程，而第一部分则希望大家各自总结归纳。
pprof性能调优实战
项目地址：https://github.com/wolfogre/go-pprof-practice
这个项目中作者埋藏了很多5个性能炸弹，故意降低了项目的性能，提高资源占用量，我们将使用pprof工具定位这些问题，并完成性能调优。
克隆项目之后，使用：go mod init go mod init github.com/wolfogre/go-pprof-practice，初始化go mod，之后就可以运行程序。
pprof预览
程序运行之后，浏览器输入http://localhost:6060/debug/pprof/，可以查看pprof监控页面。
allocs表示分配了19次内存，block表示有3次阻塞，goroutine表示有55个协程正在运行，heap为堆上内存使用，mutex表示有1个锁竞争，threadcreate表示有7个线程创建。
通过这个面板可以先大致了解程序运行情况，并定位可能出现性能问题的位置，下面将具体排查各个问题。
优化CPU占用
我们先来看一下在活动监视器中该程序CPU占用情况：45.3%恐怖！
在Terminal窗口输入：go tool pprof "http://localhost:6060/debug/pprof/profile?seconds=10"，先pprof工具先采集10秒的数据到文件中，然后再开始接受命令去展示性能分析的结果。
输入top命令，查看占用CPU资源较多的调用。
- flat：当前函数本身的执行耗时（flat == 0 则函数中只有其他函数的调用）
- flat%：flat占CPU总时间的比例
- sum%：上面每一行的flat%的总和
- cum：指当前函数本身加上其调用函数的总耗时（flat == cum 则函数中没有调用其他函数）
- cum%：cum占CPU总时间的比例
很明显github.com/wolfogre/go-pprof-practice/animal/felidae/tiger.(*Tiger).Eat的调用占用了绝大部分CPU。
定位到Eat方法占用资源最多之后，使用list Eat命令排查看出问题的代码具体是什么内容：
这里看到for循环执行了3.8s的时间，是问题所在。
接着输入web命令，可以实现调用关系可视化，这个命令前提是需要下载graphviz，一个图形化显示调用链的工具（在后续的性能调优过程中graphviz被多次使用，这里建议先完成安装～）。
定位到问题之后，注释掉Tiger的Eat方法的耗时操作。
然后查看mac活动监视器，发现CPU的占用明显降低了到了0.2%。
在终端输入exit退出pprof的工作模式。
优化内存占用
CPU占用问题解决了，但是程序内存占用依旧过高。
再次在终端输入go tool pprof http://localhost:6060/debug/pprof/heap命令，这次结尾是heap，表示查看堆内存的占用情况，然后依旧配合输入top、list。
可以看到，这个for循环不断给m.buffer追加1MB的内容，并设定上限1GB，暂未看到内存的释放，所以推测这就是程序占用高内存的原因。
接着输入web，依旧会弹出一个可视化页面展示内存占用情况。
和上面解决CPU占用问题一样，这里注释掉无效分配内存的代码。
重启项目再看一下活动监视器，看到内存占用过大的问题也解决了。
排查协程问题
在最上面那张pprof状态监听图上，你可能还记得协程数量有55，而此刻再刷新一下，竟然有105，所以怀疑出现了问题，下面排查一下。
终端输入exit退出内存的监测，重新输入go tool pprof http://localhost:6060/debug/pprof/goroutine，开始监测协程的分配情况，输入top、找到占用最高的方法调用github.com/wolfogre/go-pprof-practice/animal/canidae/wolf.(*Wolf).Drink.func1。
执行list Drink，定位到了Drink方法中每调用一次Drink()都会创建10个协程，然后睡眠30秒结束。
再照常使用一下web命令，可以看到可视化的协程的创建情况。
依旧是将这部分循环创建协程的无意义代码注释掉，重启程序，再次查看pprof监测面板，协程的数量降低到了6，优化完成。
排查锁争用
这是排查的第四个性能炸弹，终端输入go tool pprof http://localhost:6060/debug/pprof/mutex，接着输入top、list XXX、web定位到出现锁争用的代码，web图我就不放了。
这里主协程调用了Lock获得锁，然后开启子协程在一秒后释放锁，主协程第二次调用Lock方法的功能是如果子协程没有调用unLock方法，则主协程依旧会阻塞在这里，等待m锁的释放，贴一段Lock方法的源码，这里注释给出了详细解释。
关于互斥锁其实很常用，之前写作业一二都用到了，我们无法完全断定用到了锁就会被捕获为锁竞争情况，需要额外分析，这里就当作是确实发生了锁竞争，注释掉这段代码，重启项目，然后查看pprof监测面板。
排查阻塞问题
第五个性能优化的点，因为上图中block的数量是2，表示存在阻塞，那么让我们来排查一下，在终端输入命令go tool pprof http://localhost:6060/debug/pprof/block，然后输入top、list Pee、web命令，这里web的监测图依旧没有给出。
这里阻塞的原因是第39行代码，<-time.After实现了延时一秒的功能，那么就会因为这个人为的设定，每次多阻塞一秒，这里注释掉这部分代码，重启项目，观察pprof监测面板。
这里看到block还有1，而且刚才top和list也只是定位到了一个block，那这个1是阻塞在哪里了？我们直接在pprof面板上点击block，可以看到这部分block是被隐藏起来的，通过观察发现是和http/server相关，推测是程序正常工作需要的阻塞。
火焰图展示
此刻这个项目的5个性能炸弹都被我们修复了，但是课程中提到的Flame-Graph让人十分好奇，这里体验一下。依旧是在终端输入go tool pprof http://localhost:6060/debug/pprof/profile命令。
前面说了，pprof监测工具是将数据存入一个文件再进行性能分析，这里定位到这个文件后，exit退出终端，然后重新执行go tool pprof -http localhost:3030 /Users/yucong/pprof/pprof.samples.cpu.004.pb.gz命令，这里的localhost:3030是你自己指定的网页监测工具访问端口。
然后就能访问在线的监测工具了，也可以切换各种展示方式。关于火焰图，方块的大小代表了占用 CPU 使用的长短，纵向表示调用链，颜色好像没特别的意义，只是配色很像火焰🔥。
经过测试，下面的命令可以一步直接打开在线监测平台：（将block替换成mutex、goroutine等等都可以）
`go tool pprof -http=:8080 "http://localhost:6060/debug/pprof/block"
`
结束语
pprof的实战通过监测一个包含5个性能炸弹的项目，逐步修复5个性能漏洞，学习这部分的知识将为后续编写可靠的项目代码打下坚实基础～
关注微信公众号【程序员白泽】，将同步青训营期间每一课的笔记和作业。
