Go练习 - PProf分析练习

Introduction

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

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

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

brain fuck ????

我刚拿到这个任务简直无语, 真他妈无聊到批爆 ... 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

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

Summary

总结一下我遇到的问题:

• CPU占用大户: syscall
  • 可能是因为我反复发送请求索取数据, 反复SQL插入导致的时间消耗
  • 即使请求数据我无法优化, 那么SQL插入或许可以执行批量插入缓解?
• 内存占用大户: strings.Split + json.Unmarshall
  • 在整理数据的时候大量的执行strings.Split并分配新内存
  • json.Unmarshall消耗大量内存. 这些问题通过sync.Pool可以解决吗?

流言都是真的吗? 它们适用于我的情况吗? 又有多大程度的效果? 下次继续更新

实践

我的源码是结合我的场景来的, 要让你们先了解我的场景也需要一点成本, 因此我主要使用文字描述, 配合一些伪代码. 而不会直接放源码, 节省你我的耐心. 你懂了原理就可以想想怎么在你的场景下套用了,help me help you.

在这个问题开始前我面临两种选择, 我是根据网上的流言开始优化? 还是从我遇到的问题开始优化, 我选择了后者, 我先说说我遇到的问题

关于strings的叠加

我有一个函数, 这个函数就是执行strings.Join的功能, 以逗号为分隔符将数组拼接成一个字符串所以我一开始做的方法是:

func NewQuery() {
  str = ""
  for index := range array {
    str = str + array[index]
  }
}
复制代码

** 按照上面方式的结果 **

** strings.Join的结果 **

ok这真是有趣, 我按照C++的方式来追加字符串, 结果搞得内存占用很大, 还不如内置的strings.Join, 我的自作聪明让我吃了一些亏, 不过这到底是为什么呢? 我们追到strings.Join的实现上, 它使用了strings.Builder来构建字符串, 关于Builder是什么, 我简单说说我的理解:

Builder通过预分配内存, 随后在已有的内存上追加字符串的形式 最大程度了避免了因内现有内存不足而产生的拷贝. 就是现在的内存不足了, 将老字符串拷贝到一片更大的内存上去

因此我们就懂了, 我一开始str="", 分配的内存非常小, 随后不停追加, 也就不停的出现了内存不足的情况, 也就不停的分配新内存, 拷贝至新内存. 而strings.Builder上来先计算Join这个数组需要多大空间, 先分配好, 然后再追加了, 避免了分配新内存产生的时间消耗, 也避免了一大堆弃用的老内存, 碎片化, 加重GC负担

*但是提醒大家一下, 我的遍历次数是500, 这种时候Builder才会发挥很大作用, 你如果只是平常追加一下字符串, 上Builder没有很大意义

关于Strings的拆分

我们继续往下, 在看看上面的图, 现在的内存占用的大户是strings.genSplit, 这次我是直接使用的strings.Split内置函数来做分隔的, 这次造成内存大量使用的原因很简单, 我就一带而过了:

strings.Split函数返回一个数组, 它的做法是需要自己先预先分配一个数组出来, 然后再将这个数组返还给你,你用自己的变量接住. 在我们的示例中, 我们已经自己通过make([]string,size) 创建过了一个, 那么strings.Split分配的就多余出来了. 我解决这个问题的方法是自己实现strings.Split, 效果如下, 可以发现, 现在Split已经不再消耗内存了

json.Unmarshal - Introduction

最后就来到了大头: json.Unmarshal的优化, 如果前两个String相关的还算好看懂, 那json.Umarhsal确实不容易看懂... 但我又不能假装看不到,然后说一句今天已经优化好了是吧... ok我们来吧, 在上面的图中我们能看到json.Unmarshall占据了3M左右的内存, 我们需要分析一下为什么明明是内置库效率还是如此的低, 以及我们有什么办法能改善一下

先上结论, 首先不说改善多少, 如果你坚持要优化unmarshal过程 ,最简单的方法是通过第三方库来实现unmarshal功能, 这样能减少内存消耗, 代价就是代码复杂程度会增加, 原生库的使用替换成第三方库. 在我的实践中, 通过替换成第三方库json-iterator/go, 以下是我得到的实践结果反馈:

** 使用原生json库 **

** 使用json-iterator/go **

可以发现, 如果从内存角度分析, 那么这个第三方库的确起了很大作用. 如果想要知道为什么这个库"快", 我们需要先知道原生json库为什么"慢"

json.Unmarshal - 过程简述

上图显示我们内存消耗在literalStore这个函数中了, 现在我们从json.Unmarshal往下走, 看看我们是怎么到这儿的, 以及这一步是怎么消耗内存的.

• json.Unmarshal, 开始, 传入[]byte以及v(一个结构体指针)
  • 创建出用于表示解析全过程的decodeState对象
  • checkValid负责检查[]byte是否是合法的, 例如json串格式是否合法
  • 将[]byte内容导入decodeState对象中, 进入下一步
• Unmarshal的核心在于d.object(v). 因为我们要解析的东西是个结构体,就是在这里, 我们将一行一行的数据扫描进结构体的
• 简单来说, 我们的做法是遍历着这个[]byte数组, 一直遍历到最末尾的那个双引号为止, 当然在这之中我们会遇到很多字段
  • 假设遍历[]byte的过程中, 我们拿到的第一个字段是A, 那么接下来, 我们要拿着A去遍历结构体中所有属性
  • 假设json中读到的A字段, 对应上了结构体中的DataA属性, 那么我们接下来就去读A字段对应的值, 将读到的值赋给DataA属性, 一直重复上述过程, 将json中所有的字段赋值上去
  • 那怎么去读A对应的值呢? 这里就是用到了literalStore函数, 终于到了pprof指出的位置了, 简单来说我们先判断这个值是map类型? string类型? 还是bool类型? 在我们的场景下只是一个string型. 对应的做法先将双引号去掉, 然后将这个[]byte变成string型, 然后set上这个值
  • 这个set过程, 就是pprof告诉我们大量消耗内存的地方

至于为什么慢, 你可以看看上面的步骤, 上面所有提到的 "类型判断", "遍历" , "赋值" 基本全是靠反射完成的. 从[]byte对应的是什么类型? 结构体是什么类型 ? 结构体中的某一个字段是什么类型, 全都是靠反射来做的, 就是这些产生了巨大的开销.

json.Unmarshall - 可能的解决方案

目前市面上对此可能的解决方案是通过预编译, 预编译生成代码（提前确定类型）,可以解决运行时的反射带来的性能开销。缺点是增加了预生成的步骤.例如pquerna/ffjson (这个如果有必要以后会说, 但不是今天的重点)

关于Unmarshal到底在做什么

在开始之前我们需要想想, 到底什么是Unmarshal(后文用解析二字代替), 它帮我们做了什么, 直观感受上, 请求里的信息会被放到结构体里. 那请求里的信息是什么, 你会说那就是[]byte呀, 那[]byte是什么, byte又是什么呀? rune又是什么呀? 你打印[]byte能得到什么呀? 是不是一串鬼畜的数字?

我不知道你发现没有, 相比于C++, Golang里是没有char的, 但是Golang里有byte/rune, 他们全都是uint类型的, char类型在C++里是不是也是int类型? 你现在懂了, 这俩货原来是char啊??? 我不胡吹, 你试试这个: go-playground. 那么Unmarshal就是帮我们将string中的字段, 转移到了struct中了而已, 也不是什么黑魔法啊... -.-

原理上, 我们比较关心字符串是怎么扫描到结构体里的, 其实拆到最后还是很naive的, 因为其实json串长得都很像, 它也只能是俩括号{} + "Key":"val"组合的形式. 多个字段之间通过逗号,隔离. 我们首先用逗号分隔开诸多字段, 针对每个字段, 我们通过双引号为界限, 找出key是什么, 再用双引号为界限找出值是什么.针对这个键, 我们查找看一下结构体中有没有这个属性, 然后给设置上.

第三方Unmashal是怎么做的

我们已经知道Unmarshal本质上到底在忙什么了, 回到json-itoerator/go库里, 在设计上, 它要求我们首先给出一个设置, 给出设置以后, 我们得到一个**API**对象, 通过这个API对象我们就能调用我们需要的Unmarshal(后文用解析二字代替)函数. 针对每次解析过程, 我们将[]byte数据及其相关信息存放在一个叫做Iterator中, 可以说, 一个Itorator对应了一次解析. 又来到了这个经典的场景, 反复需要被分配的(短命)对象, 它就使用了Sync.Pool来存储这些Itorator对象来节省内存的分配

那么jsonitor到底是因为什么快, 直接说, Golang内置json包慢就是因为reflect用的过多, 不仅导致效率低, 代码同样混乱看不懂. 我们上述简单的流程中有许多精妙的设计, 用于避免/节省reflect的使用, 包含有:

• 结构体的"阅读"
  • 内置包: 一个结构体, 其中的属性, 对应json的那个字段, 是通过后面的`json:"xxx"`这个标签定义出来的, 那么我们每次Unmarshal一个json串, 都需要重新"读"一遍这个结构体, 消耗时间消耗精力.
  • jsonitor: 设有缓存机制(不是Redis缓存), 就是一个存在内存里的sync.Map, 方便理解, 这个Map的键是hash(Struct), 值就是"阅读"完成了的结构体, 第一次阅读一次, 放进map, 下次直接使用, 避免二次阅读, 浪费时间.
• reflect2的使用:
  • 即使我们已经缓存了结构体的"阅读". 但是往结构体上设置数值还是需要通过反射完成, 在这里就通过reflect2完成, 通过reflect2替代reflect, 节省了运行时的开销

* 值得一提的是即使是json.Unmarshal现在也能支持"缓存"阅读状态, 但是效果不理想, 也只能说相比于不缓存要好一些, 因为内部非常多检查还是在依赖反射来完成

总结

其实洋洋洒洒写了这么多, 又是反射又是strings的操作, 真正对于程序的加速意义很大吗? 可以直接说答案, 很小, 甚至可以说用其实哪个都差不多, 因为你再快, 也架不住一次MySql查询带来的消耗.

只是呢, 我们搞艺术的, 要有所追求 :)

References

• go pprof
• Profiling Go
• 煎鱼

---