go pprof:一次成功的定位与失败的复现

背景： 一次大几万人的线上抢购活动，突然出现了问题，页面半天打不开，打开了半天下不了单，cpu涨了又跌跌了又涨，而内存使用又稳如老狗！不要慌，按照套路去分析问题，一切都不是问题！

阅读此文你将收获：

分析问题的一个思路！
学会使用pprof定位问题。
解决问题的一个思路！

大纲：

我是如何定位问题的
如何通过pprof精准定位
通过pprof来定位代码
我是如何trouble shooting的

一. 我是如何思考问题的

“活动挂了，下不了单！”，随着一声凄凉的惨叫，办公室大门被运营人员打开，于是活动团队开始了紧张的bug定位过程。通过一段时间的代码查看未能定位问题，重启也没法解决。

通过finalshell上的机器使用率显示，我们发现了一个有趣的现象，CPU的使用率从30%涨到60%再涨到99%，然后又从10%开始一路往上涨，如此往复，但是内存的使用率却一动不动，非常稳定。

CPU为什么这么奇怪？CPU是干什么的？
CPU是负责计算的！

那么我们来猜测一下导致cpu暴涨的原因：

是某段代码涉及计算量过大？
是小对象太多？导致GC压力过大？

然后导致cpu资源占用过高，在高并发环境下请求积压越来越多？处理不了？

有了初步推测，下一步就该用出golang性能分析大杀器—pprof！

二. 如何用proof精准定位

很多小伙伴担心线上使用pprof会影响性能，担心安全问题。这个在我看来利大于弊，当服务出现问题的时候，资源占用多一点点与能够解决问题相比微不足道，当服务没有问题的时候使用pprof那更没有问题了~

在这里要推荐来自鹅厂大佬陈一枭在深圳gopher meetup上的分享：

《Go性能优化之路》点击进入GitHub下载PDF文档与示例demo
重点如下：
基准—benchmark的使用
分析工具：GODEBUG
分析工具：go tool pprof
分析工具：go tool trace
PS：已经与鸟哥沟通过，获得使用许可

2.1 CPU Profile的使用

1.先看Graph图

该图展示了函数逻辑调用树，框越红，越大表示消耗越多！

在该步骤中，我们直接将graph图缩到整个屏幕可见，哪里红线明显，哪里框框最大，一目了然

通过缩略图我们标记了四个消耗量大的点位。我们再继续看放大图。

2.再看flame图

火焰图中的X轴表示CPU耗时，越宽占用时间越多
Y轴表示函数栈调用深度，尖刺越高表示函数栈调用越深

我们可以看到其实采样SAMPLE中选择cpu或者samples都差不多，消耗越大的地方cpu占用越高，采样点也是越集中在这里！

3.再看TOP

Flat：函数自身运行耗时
Flat%：函数自身耗时比例
Sum%：指的就是每一行的flat%与上面所有行的flat%总和
Cum：当前函数加上它之上的调用运行总耗时
Cum%：当前函数加上它之上的调用运行总耗时比例

**举例说明：**函数b由三部分组成：调用函数c、自己直接处理一些事情、调用函数d，其中调用函数c耗时1秒，自己直接处理事情耗时3秒，调用函数d耗时2秒，那么函数b的flat耗时就是3秒，cum耗时就是6秒。

// 该示例在文末参考列表的博客中
func b() {c() // takes 1sdo something directly // takes 3sd() // takes 2s
}

4.看看内存Profile

alloc_objects：收集自程序启动以来，累计的分配对象数
alloc_space：收集自程序启动以来，累计的分配空间
inuse_objects：收集实时的正在使用的分配对象数
inuse_space：收集实时的正在使用的分配空间

如图显示这两个地方使用对象最多，分别占比53.10%与26.63%，二者相加等于79.73%。
GC收集的就是内存中的小对象，而这里我们所见的UnmarshalJSON与json compact所产生的对象占了80%，这里可以列入优化点！

三.通过pprof的定位来追代码

通过pprof中CPU与内存的Graph、Flame Graph和Top，我们基本清楚了程序性能消耗大户就在json.Unmarshal这一块。下面我们通过针对第一个标记点的分析，来示例如何查找问题代码的。

从上图可以分析出来是api.GetGiftCategoryDetails这个方法消耗了太多性能，因为往下走就是redis的HGetObject和json的Unmarshal方法，这些方法属于不可控方法，不能直接对其进行修改，所以定位就定位在api.GetGiftCategoryDetails这个方法上！

上图为pprof中标记1的主要方法，pprof cpu显示，该方法消耗了大量的CPU时间。
该方法被调用的时候会判断in.Giftcategoryid 是否有值，有值则从redis中取出数据。
进入HGetObject方法，如下图：

继续进入decode方法！

在该方法中我们看到了p.Option.Unmarshal，这个跟我们在pprof中看到的json Unmarshal是什么关系呢？
进入p.Option.Unmarshal中查看。

到这里就明白了默认使用的是json.Unmarshal反序列化方法

那么我们从pprof中所观察到的一切都能够串联起来了，整个逻辑流程如下：

文章看到这里，在回头看看pprof的CPU还有其他的各种截图，结合代码，整个流程清晰明了，就是从redis中取出数据的时候进行的json.Unmarshal损耗CPU性能太多！

四. 我是如何trouble shooting的

既然我们知道了是json反序列化的问题导致这次线上事故的产生，那么这个问题我们该如何解决呢？

这个很容易想到，既然标准库中的json序列化效率不高，咱们换个高效率的不就行了吗？例如：https://github.com/json-iterator/go

但是，换了高效的json序列化包，那么效率到底能够提升多少呢？30%？50%，100%，三倍？五倍？十倍？···

我的看法是：脱离业务谈技术的都是耍流氓！

在不清楚业务的情况下，任何解决方案都只是猜测而已，因为最高效的手段永远都是从业务上去解决，然后再是技术手段。

通过与活动团队沟通，了解到业务逻辑如下：

近百万用户分为三个类别。
每个类别用户进入都会取出不同的商品列表。
商品列表存redis中。
每次从redis中取下来后反序列化返回给用户端。

那么看完了整个业务流程，应该怎么去做呢？
咱们不妨从下面两个角度想一想：

技术手段
业务手段

几万个用户几乎同时取redis中取三种相同的臃肿的数据，然后还需要经过json反序列化去消耗大量的CPU，这样做是否合理？

如果你觉得这样不合理，那咱们换一个思路：
如果我们将这三类商品列表放在全局变量中，每次来了直接从全局变量中获取这个方法怎么样？

来，咱们算一算两种方式的开销如何：

redis走网络开销至少ms级，走内存ns级，这里省了有没有十万或者八万倍？
不需要经过json序列化···掐指一算，省了···（不好意思，程序就卡死在这里，这里还有算的必要吗？）

我们反思复盘一下，要是我们不考虑业务直接换json库换上目前性能最高的json库，那么下次活动结果会如何？（心里知道就行了）

总结：

1.谈一谈基础

起码得知道CPU是计算资源，查看CPU使用率和负载，当CPU使用率低，负载高是个什么情况。

又例如服务OOM了得考虑是不是内存泄漏了，当内存泄漏的时候，操作系统杀的一般是占用内存最大的而不是泄露的···

2.了解分析工具的使用

常用的性能分析工具要掌握，pprof肯定不用说，还有一些Linux命令例如top，uptime，还有查看TCP连接数的等等命令。

3.该如何解决问题

首先得分析问题，是CPU问题还是内存问题，又或者是网络问题。当三者都没问题的时候，请你压一压是不是自己程序性能有问题···

当能够充分定位问题的时候，首先得梳理清楚业务流程，因为一般我们用的包或者标准库，亦或是框架，他们的性能相差其实也没有大到很离谱，除非你故意挑个玩具代码来应用到生产环境。

先确认业务流程和程序处理上已经没有优化的空间，请再考虑寻找一个高效的库，或者自己去实现一些代码优化措施！

PS：该业务不是我负责的，纯属同事之间友情互助，帮忙查找问题。至于后来我也模拟过同样的数据，利用time.sleep(5ms)，然后反序列化，但是并未出现CPU使用率波浪式呈现。太遗憾了，要是有知道的大佬还望不吝赐教！

感谢阿郎，孙伟，陈一枭等大佬提供的帮助

参考资料与推荐阅读文章：
滴滴实战分享：通过 profiling 定位 golang 性能问题 - 内存篇
Go语言性能优化工具pprof文本输出的含义
linux下查看cpu负载及分析