Go pprof 与线上事故：一次成功的定位与失败的复现

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

阅读此文你将收获：

• 分析问题的一个思路！

• 学会使用 pprof 定位问题。

• 解决问题的一个思路！

大纲：

1. 我是如何思考问题的

2. 如何通过 pprof 精准定位
3. 通过 pprof 来定位代码
4. 我是如何 trouble shooting 的

一. 我是如何思考问题的

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

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

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

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

1. 是某段代码涉及计算量过大？

2. 是小对象太多？导致 GC 压力过大？

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

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

二. 如何用pprof精准定位

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

关于pprof的使用教程，在这里要推荐来自鹅厂大佬陈一枭在深圳 gopher meetup 上的分享：

有详细的 PDF 告诉你 pprof 以及性能优化的各种细节，更有教程 demo 让你参考！

重点如下：

基准--- benchmark 的使用 

分析工具： GODEBUG

分析工具： go tool pprof

分析工具： go tool trace

PS：已经与鸟哥沟通过，获得使用许可

2.1 CPU Profile的使用

先期准备： 几行代码导入 pprof

package main

import (
    "net/http"
    _ "net/http/pprof"
)

func main() {
    // 服务端启动一个协程，支持pprof的handler
    // 导入pprof的包，自动包含一些handler
    // 项目加入如下代码
    go func() {
        // net/http/pprof 注册是的默认的mux
        http.ListenAndServe(":6060", nil) 
    }()
  //other code
}

1.先看Graph图

点击view，选中graph

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

直接将图缩到最小查看爆红点

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

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

json 解码导致的性能消耗。

runtime.scanobject  和  runtime.mallocgc  是  GC  时候的消耗。

在Graph下选择 samples 。

2.再看flameh图

• 火焰图中的X轴表示 CPU 耗时，越宽占用时间越多

• Y轴表示函数栈调用深度，尖刺越高表示函数栈调用越深

flame选中samples

我们可以看到其实采样 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 1s
    do something directly // takes 3s
    d() // 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这一块。下面我们通过针对第一个标记点的分析，来示例如何查找问题代码的。 pprof 问题代码函数调用链

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

func GetGiftCategoryDetails

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

HGetObject

继续进入 decode 方法！

decode

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

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

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

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

四. 我是如何trouble shooting的

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

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

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

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

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

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

1. 近百万用户被分为三个类别。

2. 每个类别用户进入都会取出不同的商品列表。

3. 商品列表存 redis 中。
4. 每次从 redis 中取下来后反序列化返回给用户端。

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

• 技术角度（换 json 包）

• 业务角度（利用本地缓存）

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

如果你觉得这样不合理，那咱们换一个思路：如果我们将这三类商品列表 放在全局变量 中，每次来了直接从全局变量中获取这个方法怎么样？(最简单的一种办法，也可以使用多级缓存，具体根据团队情况取舍，例如考虑一下代码复杂度是否增加)

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

1. redis 走网络开销至少 ms 级，走内存 ns 级，这里省了有没有 一万或者八千倍 ？

2. 从内存中取数据，避免每次方法调用后对临时变量的销毁，还记得 pprof 标记点2、3吗？ 间接解决了 GC 压力的问题

3. 不需要经过 json 序列化···掐指一算，省了···（不好意思，程序就卡死在这里，这里还有算的必要吗？）

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

总结：

1.谈一谈基础

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

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

2.了解分析 工具 的使用

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

3.该如何解决问题

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

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

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

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

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

孙伟的GitHub： https://github.com/xiaowei520

参考资料与推荐阅读文章：

（陈一枭大佬并未上传该PPT至个人GitHub）

https://github.com/first-giver/go-performance-code

滴滴实战分享：通过 profiling 定位 golang 性能问题 - 内存篇

Go语言性能优化工具pprof文本输出的含义

http://blog.sina.com.cn/s/blog_48c95a190102xtse.html

linux下查看cpu负载及分析

https://blog.csdn.net/kepa520/article/details/80874640