这里写目录标题

1. Golang Profiling
- 1.1. runtime/pprof 包的使用
- 1.2. net/http/pprof 包的使用
2. 创建火焰图
- 2.1. 安装 go-torch
- 2.2. 安装
- 2.3. 安装 graphviz
- 2.4. 使用 pprof
- 2.5. ab 压测
- 2.6. pprof 使用
- - 2.6.1. 监听
  - 2.6.2. 操作
  - 2.6.3. pprof 命令
- 2.7. 火焰图工具使用
- - 2.7.1. 监听
  - 2.7.2. 操作
3. 更加易用的 pprof
- 3.1. 修改 main 函数
- 3.2. 可视化
- 3.3. 轻松获取内存 pprof
- 3.4. 处理线上问题: 通过 profiling 定位 golang 性能问题(内存篇)
- - 3.4.1. profiling 是什么
  - 3.4.2. 两次 profiling 线上实战
  - - 3.4.2.1. cpu 占用 99
    - 3.4.2.2. 内存占用 90
  - 3.4.3. 经验总结
- 3.5. 搭建 profiling 监控: 快速定位线上性能问题: Profiling 在微服务应用下的落地实践
- - 3.5.1. Golang pprof 解析
  - 3.5.2. pprof 启用方式
  - - 3.5.2.1. 进程 Profiling
    - - 3.5.2.1.1. 非常驻进程
      - 3.5.2.1.2. 常驻进程
    - 3.5.2.2. 函数 Profiling
  - 3.5.3. 可视化
  - 3.5.4. Profiling 在微服务应用下的实践
  - 3.5.5. 痛点分析
  - 3.5.6. 架构设计
  - 3.5.7. 功能设计
  - 3.5.8. 服务注册与管理
  - 3.5.9. 任务编排
  - 3.5.10. 报表管理
  - 3.5.11. 任务管理
  - 3.5.12. 与微服务的集成
  - 3.5.13. 落地效果
  - 3.5.14. 结语

1. Golang Profiling

1.1. runtime/pprof 包的使用

适用于运行一次的数据采集。生成的文件需要命令行进行调试, 非常不方便, 不推荐。

针对于应用程序, 通过命令行的启动参数来生成 prof 文件, 再使用 go tool pprof 工具进行分析。

package mainimport ("flag""log""os""runtime/pprof"
)var cpuprofile = flag.String("cpuprofile", "","write cpu profile to file")func main() {flag.Parse()if *cpuprofile != "" {f, err := os.Create(*cpuprofile)if err != nil {log.Fatal(err)}err = pprof.StartCPUProfile(f)if err != nil {log.Fatal(err)}defer pprof.StopCPUProfile()}Add("test")
}func Add(str string) string {data := []byte(str)sData := string(data)var sum = 0for i := 0; i < 10000; i++ {sum += i}return sData
}

1.2. net/http/pprof 包的使用

net/http/pprof 对 runtime/pprof 进行了封装, 并在 http 端口上暴露出来, 入口为 IP:PORT/debug/pprof/

若应用为 web 服务器, 只需引入包即可 _ "net/http/pprof", 会自动注册路由到 /debug/pprof/
若为服务时程, 可开启一个 goroutine 开启端口并监听, 如

go func(){log.Println(http.ListenAndServe(":8080",nil))}()

2. 创建火焰图

2.1. 安装 go-torch

go get github.com/uber/go-torch

2.2. 安装

cd $WORK_PATH && git clone https://github.com/brendangregg/FlameGraph.git
export PATH=$PATH:$WORK_PATH/FlameGraph

2.3. 安装 graphviz

https://graphviz.org/

yum install graphviz

2.4. 使用 pprof

package mainimport ("net/http"_ "net/http/pprof"
)func main() {// 服务端启动一个协程, 支持 pprof 的 handler// 导入 pprof 的包, 自动包含一些 handler// 项目加入如下代码go func() {http.ListenAndServe("0.0.0.0:8888", nil)}()//other code
}

2.5. ab 压测

ab -n 19999 -c 20 http://xxxxxxxxxxxx
-n 总数
-c 同时并发请求数

2.6. pprof 使用

2.6.1. 监听

go tool pprof http://localhost:port/debug/pprof/profile

2.6.2. 操作

进入 30 秒的 profile 收集时间, 在这段时间内请求服务, 尽量让 cpu 占用性能产生数据。

2.6.3. pprof 命令

top
在默认情况下, top 命令会输出以本地取样计数为顺序的列表。我们可以把这个列表叫做本地取样计数排名列表。
web
与 gv 命令类似, web 命令也会用图形化的方式来显示概要文件。但不同的是, web 命令是在一个 Web 浏览器中显示它。

2.7. 火焰图工具使用

2.7.1. 监听

//cpu 火焰图
go-torch -u http://ip:port/debug/pprof/ -p > profile-cpu.svg
// 内存火焰图
go-torch -u http://ip:port/debug/pprof/heap -p > profile-heap.svg

2.7.2. 操作

针对测试服务端, 进行操作, 上述步骤默认监听 30s, 即 30s 后可以生成相关图像

3. 更加易用的 pprof

golang 自带的 prof 包是 runtime/pprof, 这个是低级别的, 需要你手动做一些设置等等周边工作, 不利于我们快速上手, 利用 pprof 帮助我们解决实际的问题。这里推荐 davecheney 封装的 pprof, 它可以 1 行代码, 让你用上 pprof, 专心解决自己的代码问题, 下载:

go get github.com/pkg/profile

3.1. 修改 main 函数

只需要为 hi.go 增加这一行, defer profile.Start().Stop(), 程序运行时, 默认就会记录 cpu 数据:

上面的命令生成的 pprof 文件是在临时目录下的, 可以指定目录:

defer profile.Start(profile.ProfilePath(utils.GetCurrentDirectory())).Stop() // cpu
defer profile.Start(profile.ProfilePath(utils.GetCurrentDirectory()), profile.MemProfile).Stop() // inuse_space, mem

package mainimport ("fmt""github.com/pkg/profile"
)func main() {defer profile.Start(profile.ProfilePath(utils.GetCurrentDirectory()), profile.MemProfile).Stop()// 为了看协程抢占, 这里设置了一个 cpu 跑runtime.GOMAXPROCS(1)f, _ := os.Create("trace.dat")defer f.Close()_ = trace.Start(f)defer trace.Stop()ctx, task := trace.NewTask(context.Background(), "sumTask")defer task.End()var wg sync.WaitGroupwg.Add(10)for i := 0; i < 10; i++ {// 启动 10 个协程, 只是做一个累加运算go func(region string) {defer wg.Done()// 标记 regiontrace.WithRegion(ctx, region, func() {sl := makeSlice()sum := sumSlice(sl)fmt.Println(region, sum)})}(fmt.Sprintf("region_%02d", i))}wg.Wait()
}func makeSlice() []int {sl := make([]int, 10000000)for idx := range sl {sl[idx] = idx}return sl
}func sumSlice(sl []int) int {sum := 0for _, x := range sl {sum += x}return sum
}

go build hi.go
./hi

3.2. 可视化

可视化有多种方式, 可以转换为 text、pdf、svg 等等。text 命令是

go tool pprof --text ./yourbinary ./cpu.pprof

还有 pdf 这种效果更好:

go tool pprof --pdf ./yourbinary ./cpu.pprof > cpu.pdf

至此, 已经搞定 cpu pprof 了。

3.3. 轻松获取内存 pprof

如果你掌握了 cpu pprof, mem pprof 轻而易举就能拿下, 只需要改 1 行代码:

defer profile.Start(profile.MemProfile).Stop()

go tool pprof -pdf ./hi /var/folders/5g/rz16gqtx3nsdfs7k8sb80jth0000gn/T/profile986580758/mem.pprof > mem.pdf

3.4. 处理线上问题: 通过 profiling 定位 golang 性能问题(内存篇)

From: Infoq

线上性能问题的定位和优化是程序员进阶的必经之路, 定位问题的方式有多种多样, 常见的有观察线程栈、排查日志和做性能分析。性能分析(profile)作为定位性能问题的大杀器, 它可以收集程序执行过程中的具体事件, 并且对程序进行抽样统计, 从而能更精准的定位问题。本文会以 go 语言的 pprof 工具为例, 分享两个线上性能故障排查过程, 希望能通过本文使大家对性能分析有更深入的理解。

在遇到线上的性能问题时, 面对几百个接口、成吨的日志, 如何定位具体是哪里的代码导致的问题呢? 这篇文章会分享一下 profiling 这个定位性能问题的利器, 内容主要有:

如何通过做 profiling 来精准定位故障源头
两个工作中通过 profiling 解决性能问题的实际例子
总结在做 profiling 时如何通过一些简单的现象来快速定位问题的排查方向
日常 golang 编码时要避开的一些坑
部分 golang 源码解析

文章篇幅略长, 也可直接翻到下面看经验总结。

3.4.1. profiling 是什么

profile 一般被称为性能分析, 词典上的翻译是概况(名词)或者描述…的概况(动词)。对于计算机程序来说, 它的 profile, 就是一个程序在运行时的各种概况信息, 包括 cpu 占用情况, 内存情况, 线程情况, 线程阻塞情况等等。知道了程序的这些信息, 也就能容易的定位程序中的问题和故障原因。

golang 对于 profiling 支持的比较好, 标准库就提供了 profile 库 “runtime/pprof” 和 “net/http/pprof”, 而且也提供了很多好用的可视化工具来辅助开发者做 profiling。

3.4.2. 两次 profiling 线上实战

纸上得来终觉浅, 下面分享两个在工作中实际遇到的线上问题, 以及我是如何通过 profiling 一步一步定位到问题的。

3.4.2.1. cpu 占用 99

某天早上一到公司就收到了线上 cpu 占用率过高的报警。立即去看监控, 发现这个故障主要有下面四个特征:

cpu idle 基本掉到了 0% , 内存使用量有小幅度增长但不严重;
故障是偶发的, 不是持续存在的;
故障发生时 3 台机器的 cpu 几乎是同时掉底;
故障发生后, 两个小时左右能恢复正常。

现象如图, 上为内存, 下为 cpu idle:

检查完监控之后, 立即又去检查了一下有没有影响线上业务。看了一下线上接口返回值和延迟, 基本上还都能保持正常使用, 就算 cpu 占用 99% 时接口延时也只比平常多了几十 ms。由于不影响线上业务, 所以没有选择立即回滚, 而是决定在线上定位问题(而且前一天后端也确实没有上线新东西)。

所以给线上环境加上了 pprof, 等着这个故障自己复现。代码如下:

import _ "net/http/pprof"func main() {go func() {log.Println(http.ListenAndServe("0.0.0.0:8005", nil))}()// ..... 下面业务代码不用动
}

golang 对于 profiling 的支持比较完善, 如代码所示, 只需要简单的引入 “net/http/pprof” 这个包, 然后在 main 函数里启动一个 http server 就相当于给线上服务加上 profiling 了, 通过访问 8005 这个 http 端口就可以对程序做采样分析。

服务上开启 pprof 之后, 在本地电脑上使用 go tool pprof 命令, 可以对线上程序发起采样请求, golang pprof 工具会把采样结果绘制成一个漂亮的前端页面供人们排查问题。

等到故障再次复现时, 我们首先对 cpu 性能进行采样分析:

brew install graphviz # 安装graphviz, 只需要安装一次就行了go tool pprof -http=:1234 http://your-prd-addr:8005/debug/pprof/profile?seconds=30

打开 terminal, 输入上面命令, 把命令中的 your-prd-addr 改成线上某台机器的地址, 然后回车等待 30 秒后, 会自动在浏览器中打开一个页面, 这个页面包含了刚刚 30 秒内对线上 cpu 占用情况的一个概要分析。点击左上角的 View 选择 Flame graph, 会用火焰图(Flame graph)来显示 cpu 的占用情况:

分析此图可以发现, cpu 资源的半壁江山都被 GetLeadCallRecordByLeadId 这个函数占用了, 这个函数里占用 cpu 最多的又大多是数据库访问相关的函数调用。由于 GetLeadCallRecordByLeadId 此函数业务逻辑较为复杂, 数据库访问较多, 不太好具体排查是哪里出的问题, 所以我把这个方向的排查先暂时搁置, 把注意力放到了右边那另外半壁江山。

在火焰图的右边, 有个让我比较在意的点是 runtime.gcBgMarkWorker 函数, 这个函数是 golang 垃圾回收相关的函数, 用于标记(mark)出所有是垃圾的对象。一般情况下此函数不会占用这么多的 cpu, 出现这种情况一般都是内存 gc 问题, 但是刚刚的监控上看内存占用只比平常多了几百 M, 并没有特别高又是为什么呢? 原因是影响 GC 性能的一般都不是内存的占用量, 而是对象的数量。举例说明, 10 个 100m 的对象和一亿个 10 字节的对象占用内存几乎一样大, 但是回收起来一亿个小对象肯定会被 10 个大对象要慢很多。

插一段 golang 垃圾回收的知识, golang 使用"三色标记法"作为垃圾回收算法, 是"标记-清除法"的一个改进, 相比"标记-清除法"优点在于它的标记(mark)的过程是并发的, 不会 Stop The World。但缺点是对于巨量的小对象处理起来比较不擅长, 有可能出现垃圾的产生速度比收集的速度还快的情况。gcMark 线程占用高很大几率就是对象产生速度大于垃圾回收速度了。

三色标记法

所以转换方向, 又对内存做了一下 profiling:

go tool pprof http://your-prd-addr:8005/debug/pprof/heap

然后在浏览器里点击左上角 VIEW-》flame graph, 然后点击 SAMPLE-》inuse_objects。

这样显示的是当前的对象数量:

可以看到, 还是 GetLeadCallRecordByLeadId 这个函数的问题, 它自己就产生了 1 亿个对象, 远超其他函数。所以下一步排查问题的方向确定了是: 定位为何此函数产生了如此多的对象。

之后我开始在日志中 grep ‘/getLeadCallRecord’ lead-platform. 来一点一点翻, 重点看 cpu 掉底那个时刻附近的日志有没有什么异常。果然发现了一条比较异常的日志:

[net/http.HandlerFunc.ServeHTTP/server.go:1947] _com_request_in||traceid=091d682895eda2fsdffsd0cbe3f9a95||spanid=297b2a9sdfsdfsdfb8bf739||hintCode=||hintContent=||method=GET||host=10.88.128.40:8000||uri=/lp-api/v2/leadCallRecord/getLeadCallRecord||params=leadId={"id":123123}||from=10.0.0.0||proto=HTTP/1.0

注意看 params 那里, leadId 本应该是一个 int, 但是前端给传来一个 JSON, 推测应该是前一天上线带上去的 bug。但是还有问题解释不清楚, 类型传错应该报错, 但是为何会产生这么多对象呢? 于是我进代码(已简化)里看了看:

func GetLeadCallRecord(leadId string, bizType int) ([]model.LeadCallRecords, error) {sql := "SELECT record.* FROM lead_call_record AS record " +
"where record.lead_id  = {{leadId}} and record.biz_type = {{bizType}}"
conditions := make(map[string]interface{}, 2)
conditions["leadId"] = leadId
conditions["bizType"] = bizType
cond, val, err := builder.NamedQuery(sql, conditions)

发现很尴尬的是, 这段远古代码里对于 leadId 根本没有判断类型, 直接用 string 了, 前端传什么过来都直接当作 sql 参数了。也不知道为什么 mysql 很抽风的是, 虽然 lead_id 字段类型是 bigint, 在 sql 里条件用 string 类型传参数 WHERE leadId = ‘someString’ 也能查到数据, 而且返回的数据量很大。本身 lead_call_record 就是千万级别的大表, 这个查询一下子返回了几十万条数据。又因为此接口后续的查询都是根据这个这个查询返回的数据进行查询的, 所以整个请求一下子就产生了上亿个对象。

由于之前传参都是正确的, 所以一直没有触发这个问题, 正好前一天前端小姐姐上线需求带上了这个 bug, 一波前后端混合双打造成了这次故障。

到此为止就终于定位到了问题所在, 而且最一开始的四个现象也能解释的通了:

cpu idle 基本掉到了 0% , 内存使用量有小幅度增长但不严重;
故障是偶发的, 不是持续存在的;
故障发生时 3 台机器的 cpu 几乎是同时掉底;
故障发生后, 两个小时左右能恢复正常。

逐条解释一下:

GetLeadCallRecordByLeadId 函数每次在执行时从数据库取回的数据量过大, 大量 cpu 时间浪费在反序列化构造对象和 gc 回收对象上。
和前端确认 /lp-api/v2/leadCallRecord/getLeadCallRecord 接口并不是所有请求都会传入 json, 只在某个页面里才会有这种情况, 所以故障是偶发的。
因为接口并没有直接挂掉报错, 而是执行的很慢, 所以应用前面的负载均衡会超时, 负载均衡器会把请求打到另一台机器上, 结果每次都会导致三台机器同时爆表。
虽然申请了上亿个对象, 但 golang 的垃圾回收器是真滴靠谱, 兢兢业业的回收了两个多小时之后, 就把几亿个对象全回收回去了, 而且奇迹般的没有影响线上业务。几亿个对象都扛得住, 只能说厉害了我的 go。

最后捋一下整个过程:

cpu 占用 99% -> 发现 GC 线程占用率持续异常 -> 怀疑是内存问题 -> 排查对象数量 -> 定位产生对象异常多的接口 -> 定位到某接口 -> 在日志中找到此接口的异常请求 -> 根据异常参数排查代码中的问题 -> 定位到问题

可以发现, 有 pprof 工具在手的话, 整个排查问题的过程都不会懵逼, 基本上一直都照着正确的方向一步一步定位到问题根源。这就是用 profiling 的优点所在。

3.4.2.2. 内存占用 90

第二个例子是某天周会上有同学反馈说项目内存占用达到了 15 个 G 之多, 看了一下监控现象如下:

cpu 占用并不高, 最低 idle 也有 85%
内存占用呈锯齿形持续上升, 且速度很快, 半个月就从 2G 达到了 15G

如果所示:

锯齿是因为昼夜高峰平峰导致的暂时不用管, 但持续上涨很明显的是内存泄漏的问题, 有对象在持续产生, 并且被持续引用着导致释放不掉。于是上了 pprof 然后准备等一晚上再排查, 让它先泄露一下再看现象会比较明显。

这次重点看内存的 inuse_space 图, 和 inuse_objects 图不同的是, 这个图表示的是具体的内存占用而不是对象数, 然后 VIEW 类型也选 graph, 比火焰图更清晰。

这个图可以明显的看出来程序中 92%的对象都是由于 event.GetInstance 产生的。然后令人在意的点是这个函数产生的对象都是一个只有 16 个字节的对象(看图上那个 16B)这个是什么原因导致的后面会解释。

先来看这个函数的代码吧:

var (firstActivationEventHandler FirstActivationEventHandlerfirstOnlineEventHandler FirstOnlineEventHandler
)
func GetInstance(eventType string) Handler {if eventType == FirstActivation {firstActivationEventHandler.ChildHandler = firstActivationEventHandler
return firstActivationEventHandler} else if eventType == FirstOnline {firstOnlineEventHandler.ChildHandler = firstOnlineEventHandler
return firstOnlineEventHandler
}
// ... 各种类似的判断, 略过return nil
}

这个是做一个类似单例模式的功能, 根据事件类型返回不同的 Handler。但是这个函数有问题的点有两个:

firstActivationEventHandler.ChildHandler 是一个 interface, 在给一个 interface 赋值的时候, 如果等号右边是一个 struct, 会进行值传递, 也就意味着每次赋值都会在堆上复制一个此 struct 的副本。(golang 默认都是值传递)
firstActivationEventHandler.ChildHandler = firstActivationEventHandler 是一个自己引用自己循环引用。

两个问题导致了每次 GetInstance 函数在被调用的时候, 都会复制一份之前的 firstActivationEventHandler 在堆上, 并且让 firstActivationEventHandler.ChildHandler 引用指向到这个副本上。

这就导致人为在内存里创造了一个巨型的链表:

并且这个链表中所有节点都被之后的副本引用着, 永远无法被 GC 当作垃圾释放掉。

所以解决这个问题方案也很简单, 单例模式只需要在 init 函数里初始化一次就够了, 没必要在每次 GetInstance 的时候做初始化操作:

func init() {firstActivationEventHandler.ChildHandler = &firstActivationEventHandlerfirstOnlineEventHandler.ChildHandler = &firstOnlineEventHandler
// ... 略过
}

另外, 可以深究一下为什么都是一个 16B 的对象呢? 为什么 interface 会复制呢? 这里贴一下 golang runtime 关于 interface 部分的源码:

下面分析 golang 源码, 不感兴趣可直接略过。

// interface 底层定义
type iface struct {tab  *itabdata unsafe.Pointer
}
// 空 interface 底层定义
type eface struct {_type *_typedata  unsafe.Pointer
}
// 将某变量转换为interface
func convT2I(tab *itab, elem unsafe.Pointer) (i iface) {t := tab._typeif raceenabled {raceReadObjectPC(t, elem, getcallerpc(), funcPC(convT2I))}if msanenabled {msanread(elem, t.size)}x := mallocgc(t.size, t, true)typedmemmove(t, x, elem)i.tab = tabi.data = xreturn
}

iface 这个 struct 是 interface 在内存中实际的布局。可以看到, 在 golang 中定义一个 interface, 实际上在内存中是一个 tab 指针和一个 data 指针, 目前的机器都是 64 位的, 一个指针占用 8 个字节, 两个就是 16B。

我们的 firstActivationEventHandler 里面只有一个 ChildHandler interface, 所以整个 firstActivationEventHandler 占用 16 个字节也就不奇怪了。

另外看代码第 20 行那里, 可以看到每次把变量转为 interface 时是会做一次 mallocgc(t.size, t, true) 操作的, 这个操作就会在堆上分配一个副本, 第 21 行 typedmemmove(t, x, elem) 会进行复制, 会复制变量到堆上的副本上。这就解释了开头的问题。

3.4.3. 经验总结

在做内存问题相关的 profiling 时:

若 gc 相关函数占用异常, 可重点排查对象数量
解决速度问题(CPU 占用)时, 关注对象数量( --inuse/alloc_objects )指标
解决内存占用问题时, 关注分配空间( --inuse/alloc_space )指标

inuse 代表当前时刻的内存情况, alloc 代表从从程序启动到当前时刻累计的内存情况, 一般情况下看 inuse 指标更重要一些, 但某些时候两张图对比着看也能有些意外发现。

在日常 golang 编码时:

参数类型要检查, 尤其是 sql 参数要检查(低级错误)
传递 struct 尽量使用指针, 减少复制和内存占用消耗(尤其对于赋值给 interface, 会分配到堆上, 额外增加 gc 消耗)
尽量不使用循环引用, 除非逻辑真的需要
能在初始化中做的事就不要放到每次调用的时候做

3.5. 搭建 profiling 监控: 快速定位线上性能问题: Profiling 在微服务应用下的落地实践

目前， Freewheel 核心任务系统采用微服务架构，在降低服务间耦合的同时，也对每个服务的鲁棒性提出了更高的要求。每个模块作为独立服务部署，都可能面临诸如性能瓶颈、内存泄露、Goroutine 泄漏等问题。在微服务化的环境中，快速准确定位具体服务的性能等问题是我们急需解决的痛点，Profiling 往往是解决这类问题的利器。本文主要介绍 Freewheel 的 Profiling 实践，供读者参考。

3.5.1. Golang pprof 解析

在软件工程中，Profiling 是指在程序的执行过程中，收集能反映程序执行状态的数据，例如程序执行所占用内存、特定指令的使用情况或函数调用的频率和持续时间，等等。Profiling 最常见的应用就是帮助应用程序定位和优化性能问题。

pprof 是 Golang 内置的 Profiling 工具，它主要支持以下几个维度的 Profiling：

cpu：CPU 分析，按照一定的频率采集所监听的应用程序的 CPU 使用情况。
heap：内存分析，记录内存分配情况。用于监控当前和历史内存使用情况，辅助检查内存泄漏。
threadcreate：反映系统线程的创建情况。
goroutine：当前所有 goroutine 的堆栈跟踪。
block：阻塞分析，记录 goroutine 阻塞等待同步的位置，可以用来分析和查找死锁等性能瓶颈。
mutex：互斥锁分析，记录互斥锁的竞争情况。

3.5.2. pprof 启用方式

针对不同的服务类型和场景，pprof 有多种启用方式。

3.5.2.1. 进程 Profiling

3.5.2.1.1. 非常驻进程

可以通过如下方式引入 runtime/pprof 库，在进程退出后，就可以获得 Profiling 数据：

3.5.2.1.2. 常驻进程

可以引入 net/http/pprof 来通过特定的 http 接口获得 Profiling 数据，这个库会注册如下的路由：

只需要在代码里启动一个 http server，就可以对外暴露出 pprof 信息，然后使用 go tool pprof 命令就可以通过这些路由获得数据：

3.5.2.2. 函数 Profiling

Golang 的 go test -bench 命令已经集成了 pprof 功能，只要针对特定函数编写 Benchmark 测试函数：

使用如下指令可以在不侵入原有代码的情况下获得 foo 函数 Profiling 数据：

3.5.3. 可视化

有了 Profiling 数据，就可以借助各种工具进行分析了。Profiling 数据的可视化支持火焰图、函数调用图、使用 top N 打印出占用 CPU/ 内存最多的函数列表，等等。其中最直观的展示方式就是火焰图了。火焰图 (Flame Graph) 是性能优化大师 Bredan Gregg 创建的一种性能分析图标，因为它的样子近似火焰而得名。

X 轴表示抽样数，如果一个函数在 X 轴占据的宽度越宽，就表示它被抽到的次数多，即执行的时间长。

Y 轴表示调用栈，每一层都是一个函数。调用栈越深，火焰就越高，顶部就是正在执行的函数，下方都是它的父函数。

火焰图支持搜索，支持在每个函数上点击缩放，从而方便对 Profiling 结果进行精细分析。

3.5.4. Profiling 在微服务应用下的实践

Profiling 是大型应用程序无法避免的重要任务。Profiling 有助于我们理解 CPU 和内存密集型代码，帮助我们快速准确地定位性能 / 内存等问题，以便更好地优化代码。为此我们构建了完善的 Profiling 组件，并且集成到了现有的运维管理平台。

3.5.5. 痛点分析

对线上服务做 Profiling 困难重重：由于安全需要，本地环境和线上服务之间会设置网络隔离，导致我们并不能在本地环境连通线上服务进行 Profiling，而直接在线上服务器做 Profiling 也比较困难，首先需要申请各种操作权限登录线上服务器，然后安装 pprof、graphviz 工具生成可视化的 Profiling Report，流程比较繁琐复杂。而线上环境由于采用 docker 部署，也无法直接使用浏览器查看可视化的 Profiling Report。

触发 Profiling 的方式单一：一般而言，我们是在性能测试时或者生产环境出现问题的当下，手动发送 Profiling 请求。但是这种方式并不能有效应对线上的突发状况，自动生成 Profiling Report。

不方便追踪和对比 Profiling 的结果：对于某个微服务而言，当我们检测到线上服务的性能下降时，会希望跟性能下降之前的 Profiling Report 做对比，以便快速定位性能下降的原因。现在为微服务生成的 Profiling Report 一般存储在开发人员本地环境，缺乏统一的管理，不方便日后追踪和对比。

3.5.6. 架构设计

Profiling 组件由前后端两个部分构成。

前端：提供一个完善的 UI 用于微服务的注册、Profiling 任务的编排和触发，以及 Profiling Report 的展示；

后端：主要由三个组件构成：

a. Service Management 即服务管理，用于注册与管理微服务的基础信息 (地址，端口等)；
b. Scheduler 即调度程序，通过定时器执行数据库里的计划任务；
c. Profiling Executor 即 Profiling 执行器，采集微服务的 Profiling 数据，并且生成 Profiling Report 并将文件进行归档存储。

具体的架构图如下所示：

3.5.7. 功能设计

基于以上的痛点分析， Profling 组件设计了如下功能模块：

3.5.8. 服务注册与管理

为微服务做 Profiling，首先我们需要知晓服务的地址，端口号和 Profiling 服务的端口号。Profiling 组件 Service Management 模块提供微服务信息的注册功能。

3.5.9. 任务编排

在任务编排模块，用户可以从 Profiling 类型以及触发 Profiling 的方式两个维度来进行任务的设置与编排。目前系统提供的 Profiling 功能已经覆盖了关键的四项数据指标以及三种常用的触发机制。

支持生成多个维度的 Profiling Report。Profiling 组件现在支持四种类型的 Profiling：CPU Profiling、Heap Profiling、Goroutine Profiling、Block Profiling，并且能够很容易地扩展支持其他类型的 Profiling。

支持多种方式触发 Profiling：即时开启、计划任务、自适应 Profiling

a. 即时开启 (On Demand Profiling)

这种情况适用于用户观测到了服务的异常情况或者正在进行性能测试，需要立即触发 Profiling，并且生成 Profiling Report 进行分析。

b. 计划任务 (Scheduled Profiling)

如果我们想对流量高峰时的服务性能进行分析，可以首先基于日志信息对历史流量情况进行分析，预测流量高峰出现的时间点，然后可以 schedule 到这个时间点自动触发 Profiling，生成 Profiling Report。

c. 自适应 Profiling (Adaptive Profiling)

我们知道，在线上环境开启某些类型的 Profiling 会对性能造成一些损失。所以，我们一般只会在服务出现相应问题的时候才会触发 Profiling。当线上服务出现突发状况，譬如性能骤降、goroutine 或者内存暴涨时，我们首先要做的就是快速修复，譬如服务重启、服务降级、回滚等，而不是保存现场，手动触发 Profiling，然后根据 Profiling Report 详细分析故障原因。上面介绍的两种 Profiling 方案并不能及时 catch 到线上的突发状况，自动触发 Profiling。所以，为了既减少性能损耗，避免不必要的 Profiling，同时又能捕捉到线上的突发状况，我们提出了一种基于监控的自适应的弹性 Profiling 方案。

这里所说的自适应性体现在两个方面，一方面是指当特定的监控指标出现异常时，自动触发 Profiling；另一方面是指，根据监控指标的不同，触发不同类型的 Profiling。例如，当监控系统监控到性能下降到特定阈值时，自动触发 CPU Profiling；当监控到内存涨到特定阈值时，自动触发 Heap Profiling；当监控到 Goroutines 数目涨到特定阈值时，自动触发 Goroutine Profiling 等。当然触发 Profiling 的条件可以自定义，也可以支持多种条件的组合。

具体如下图所示：

具体的实现方式是 Profiling 组件与监控系统集成，由 Profiling 组件提供一套能够触发 Profiling 的 API，在监控系统检测到具体指标异常时直接调用 API，触发 Profiling，生成 Profiling Report。

Freewheel 目前有两套主流监控系统。一套基于 ElastAlert，一套是自主开发的 pqm 监控组件。下面是与 ElastAlert 监控系统的集成。ElastAlert 支持在报警发生之后触发相关回调，使得我们能够借此能力通过 HTTP Post 接口调用 Profiling 组件 API 执行 Profiling 操作。

与 Freewheel 自主研发的监控系统 pqm 集成也是采用类似的方式：

3.5.10. 报表管理

在报表管理模块，我们可以查看为某个微服务生成的所有 Profiling Report（目前支持火焰图和函数调用图）。但如果要处理某些问题，譬如性能回退，就要在代码修改前后或者不同时期不同场景下的火焰图之间，不断切换对比，定位问题所在。红蓝差分火焰图可以对比两张普通的火焰图，并对差异部分进行标色：红色表示上升，蓝色表示衰减，非常直观。鉴于此，我们同时提供了生成红蓝差分火焰图的功能。

3.5.11. 任务管理

在任务管理模块，可以查看某个微服务所有的 Profiling 任务及其状态，同时也支持 Profiling 任务的删除。

3.5.12. 与微服务的集成

微服务使用 Profiling 组件功能的前提是启用 pprof ，支持 Profiling 数据的采集。Freewheel 的微服务属于上文提到的常驻进程型服务，与 pprof 集成的方式这里不再赘述。

为了防止长期暴露 pprof 服务及端口，规避被攻击的风险，同时为了降低引入 pprof 对服务的性能影响，我们为微服务挂载了两个 API，以便动态启动和停止 pprof server。

Profiling 组件在执行某个 Profiling 任务时，会先通过以上的接口启动 pprof server，然后通过调用 /debug/pprof/profile 等接口获得 runtime/pprof 库里相关函数采集的程序运行数据，在使用数据生成性能报告之后，再次调用接口停止 pprof server，具体的工作流程如下图所示：

3.5.13. 落地效果

某一天，一个开发很久的新服务终于上线了。我们想了解在流量高峰阶段，服务的性能表现如何，于是根据历史日志预估了流量高峰到来的时间，并注册了一个此时间点执行的 Profiling 任务，生成的火焰图如下：

可以看到 domain.inValidRequest 执行时间竟然占到了总执行时间的 80% 以上，并且性能瓶颈主要在 regexp.(*machine).match。我们分析了要匹配的正则表达式，最后采用 strings.Index 和 strings.Replace 来实现同样的效果。优化之后的 domain.inValidRequest 仅占总执行时长的 2.2%，性能简直实现了质的飞越。

但我们仍然从上面的火焰图看到 json.Unmarshal 占到了总执行时长的 22% 左右。通过一番调研，我们引入了 github.com/json-iterator/go 库来替代 golang 原生的 encoing/json 库来执行 Unmarshal 操作，通过下面的火焰图可以看到 Unmarshal 的耗时降到了 14.2%。

对此我们其实也有一些思考，我们在本地做了压测，性能达到了预期，通过火焰图也没有看到明显的性能瓶颈，那为什么问题到了线上就体现出来了呢?

后来我们定位到了原因，是因为线上需要解析的字符串竟然能达到几兆，这也是本地测试没有考虑到的情况。所以，即使我们认为在本地已经进行了充分测试，但是百密也可能会有一疏，在真实的生产环境，在流量高峰期收集一段时间的 Profiling 数据并进行分析和优化，不失为一个好的习惯。

3.5.14. 结语

本文介绍了如何基于 Golang pprof 构建完善的 Profiling 组件，提供多种触发 Profiling 的方式，并为微服务提供自动生成的、可追踪的 Profiling Report，希望能为微服务的稳定性保驾护航。

golang profiling相关推荐

Golang内存分析工具gctrace和pprof实战
目录 gctrace 参数说明举例分析补充说明 pprof go tool pprof分析工具参考 gctrace gctrace用途主要是用于跟踪GC的不同阶段的耗时与GC前后的内存量对比. ...
golang cpuprofile分析
http://www.philo.top/2015/05/29/golangProfilingAndGC/ Philo 关注Golang与Docker技术 HomeArchivesAboutDonat ...
攀登规模化的高峰 - 蚂蚁集团大规模 Sigma 集群 ApiServer 优化实践
文|唐博(花名:博易蚂蚁集团技术专家) 谭崇康(花名:见云蚂蚁集团高级技术家) 本文 10316 字阅读 18 分钟 ▼ 蚂蚁集团运行着全球最大的 Kubernetes*(内部称为 Sigm ...
Go pprof和火焰图
Profiling 在计算机性能调试领域里,profiling 就是对应用的画像,这里画像就是应用使用 CPU 和内存的情况.也就是说应用使用了多少 CPU 资源?都是哪些部分在使用?每个函数使用的比 ...
golang垃圾回收概述
golang垃圾回收 golang的垃圾回收机制已经迭代过好几次了,主要的几个演进过程如下: v1.0版本中使用标记和清除算法,需要再整个gc过程中暂定程序. V1.5版本中实现了三色标记清除的并发垃 ...
Go 语言编程 — Profiling 性能分析
目录文章目录目录 Profiling runtime MemStat GC pprof trace Profiling Golang 提供了友好的工程化支持,其中之一就是 Profiling(分析 ...
才云开源 Nirvana：Golang REST API框架
自 2009 年开源以来,Go 作为一种强大.高效.简洁.易上手的编程语言,在帮助阅读.调试和维护大型软件系统上发挥着越来越重要的作用.而依托其健康生态,Golang 社区也相继涌现出诸如 beego ...
golang调用java的函数_大话golang性能分析（一）：profile基本原理
引言:好久没分享了,不多废话了,准备一个专题分三期来分享下golang的性能分析. O 专题目标理解profile基本原理熟悉go常用性能分析工具pprof 快速对线上服务的cpu.内存.goro ...
Golang程序性能分析（二）在Echo和Gin框架中使用pprof
前言今天继续分享使用Go官方库pprof做性能分析相关的内容,上一篇文章:Golang程序性能分析(一)pprof和go-torch中我花了很大的篇幅介绍了如何使用pprof采集Go应用程序的性能指 ...

golang profiling