[WIP] Go练习 – PProf分析练习

先说一下这次要做什么, 我们每天都需要同步一次本部门人员详细信息. 但是只有两个接口可用:

  • 获取所有人员姓名
  • 根据指定姓名, 查询详细信息的接口

在获得详细信息以后需要筛选出本部门的人员信息, 也就是 org 字段中包含 云部门 的数据, 筛选出的数据算是最新人员名单, 对比数据库中已有的数据, 做增量更新(也就是不存在的补上就够了).

brain fuck :middle_finger:

我刚拿到这个任务简直无语, 真他妈无聊到批爆 … fuck! 但是又隐约想起这似乎是我以前遇到过的一个面试题, 简单想想好像没什么嘛, 但是在30万的数量级, daily basis的情况下. 任何微小的浪费都会被放大, 这样一下就有意思了, 能做肯定是能做, 但是怎么做会比较”快”, 比较”经济”(不浪费内存), 针对这种情况, 现在市面上有这些流言, 他们说:

  • 通过make做数组做预分配,能减轻Slice再分配内存所消耗的时间, 同时减少内存碎片化更好的利用内存
  • 通过sync.Pool能很大程度的提升短命内存的使用效率(这个我也说过)
  • 通过 for _,item := range array 中间会有一次值拷贝, 而 range array[index]没有
  • 合理设计协程,channel能加速你的烂程序, fuck !
  • 逐个执行SQL单条插入 vs SQL批量插入 那个比较好?

背景知识

我们会从时间+内存+CPU占用的情况分析某个策略的好坏, 时间的话好办, 那么内存+CPU数据应该怎么捕捉呢? 我知道有很多种方式, 目前比较常见的(网上教程比较多的)方法是通过pprof的方法来做. 我现在是通过最简单最naive的方式实现了我的需求, 在我定位出了我面临的问题以后, 我就可以一个一个去验证网上的这些”流言”

(其实我想知道他们在说这些之前, 自己有没有真的实践过)

在开始用pprof之前, 先介绍一下这个工具, 这个概念:

PProf是什么

大部分市面上的教程呢, 都是教教你怎么画火焰图, 调用图然后就结束了. 我觉得pprof这个单词有点鬼畜, 我就从定义开始说, 单独搜了一下这个词是什么含义, 将它拆成两段: pprof = p + prof = Package Profiling. Packge就是你的程序, Prof就是Profile的简写, Profile是指一组栈追踪信息. 指, 当你希望完成一个事件的时候, 所有的栈调用信息 .

那么我们就理解了, pprof是指我们程序运行的时候, 来做栈分析, 进一步往下, 分析的内容可以是CPU, 也可以是内存分配分析等 , 对应下来, 这个工具就提供了相应的指标供你观察, 我们从最小, 但却最常用最简单的指标开始学习: ( 想学习最全面的指标, 可以点击这里 → 完整的指标 )

  • profile指标:
    • CPU占用时长分析, 采样时长默认30秒, 分析一下这30秒内那些函数, 分别消耗了多长时间
    • 上面提到了一个词:”采样”, 我们不能做到全实时监控这个程序, 因此我们每10ms查看程序一次, 主要看看有哪些函数正在运行 , 现在假设我执行了100次采样(共1秒), 其中有50次函数f都在运行, 那么我们就估算出, 这个函数运行了50 * 10ms = 0.5秒
  • heap指标:
    • 内存分配分析, 函数分配的内存都是在Heap(堆)上, 因此分析函数内存占用本质上就是对于堆内存的分析

布置pprof采集点

为了布置pprof, 你一共有两种方式, 两句话概括这两种方式, 它们分别是:

  • runtime/pprof :
    • 使用这种方式, 你需要在程序里通过调用API获得采集数据, 在程序运行结束的时候生成prof文件, 然后单独分析这个文件.
    • 采集什么指标是你决定的, 灵活性高
  • net/http/pprof : ( 我们使用这种方式 )
    • 这种方式更加简单, 你只需要在程序里单独开一个接口, 然后程序运行的时候通过访问这个接口就能访问pprof数据了, 本质上也是通过第一种方式来实现的
    • 虽然没有那么灵活但是足够简单, 在你的程序里添加下面的语句
import _ "net/http/pprof"

func main() {
  go func() {
    http.ListenAndServe("localhost:6060", nil)
  }
}
复制代码

第一次采集

CPU数据采集

在pprof观察点设置好了以后, 我们让程序运行起来, 然后在** 命令行中 输入命令: go tool pprof http://localhost:6060/debug/pprof/profile 来获得CPU分析结果, 输入命令以后需要等待30秒钟等待采样完成. 随后就进入命令行模式, 我们通过 top5命令**查询CPU占用前五高的函数

这样我们就能获得, 在这30秒里, 在CPU上都发生了什么, 接下来, 我们来详细分析一下这里面的一些指标都是什么含义:

  • Duration: 30.15s, Total samples = 2.22s
    • 程序运行了30秒, 在这期间, 我们总共花在采样上的时间是2.22秒
  • Showing nodes accounting for 1040ms, 46.85% of 2220ms total
    • 我们索取了前五高, 这前五高的时间加一起一共占据了1.04秒, 花在采样上的时间总共是2.22秒, 因此, 就CPU占用时间上来说, 这前五个函数, 占掉了总时间的46%
    • 我们看flat列中的时间, 这么些时间加在一起正好是1.04秒, 然后看看flat列中的百分比, 百分比加在一起是46%. 也就是说:系统认为, 五个函数消耗的时间是基于flat时间算出来的
  • flat/cum指标:
    • 区别是什么? 为什么两个值不一样?
    • flat指标 = 采样时正在运行这个函数
    • cum指标 = 采样时,这个函数(A)出现在堆栈上, 可能是正在运行, 也可能是这个函数正在调用子函数(B), 这个函数A正在等待子函数B返回, 我们要画出来基本是这样的

内存占用采集

同样的, 我们使用这个命令来查看内存的使用情况: go tool pprof http://localhost:6060/debug/pprof/heap

跟上面的分析类似, 我们能发现在我们的程序中, 内存消耗大户是strings调用的函数, 以及json调用的函数. 如果你想知道更多, 我们还能从网页版里面验证这些说法:

太好拉, 通过堆栈调用信息, 一下就他妈破案了, 我们内存占用大户主要来自这两个函数的反复调用:

  • strings.Spilit
  • json.Unmarshall

我不是说这两个函数有问题, 大家以后不要用了, 不是这样的, 只是说在我的程序中, 我反复调用了这两个函数, 不停的分配新内存. 现在真是太好了, 在”优化程序”这个巨大的话题中, 我们至少已经定位出了我们的问题, 围绕我们的问题, 我们不用像无头苍蝇一样了, 我们可以针对问题想办法了 🙂