Pyroscope: 优化无止境

·

3 min read

Pyroscope 是什么?

Pyroscope是一个开源的持续分析系统,使用Go语言实现。服务端使用web页面查看,提供丰富的分析的功能,客户端提供Go、Java、Python、Ruby、PHP、.NET等多种语言的支持,并且支持PUSH、PULL两种采集方式

提到 pyroscope 就必须提火焰图了,

火焰图(Flame Graph)是由 Linux 性能优化大师 Brendan Gregg 发明的,和所有其他的 profiling 方法不同的是,火焰图以一个全局的视野来看待时间分布,它从底部往顶部,列出所有可能导致性能瓶颈的调用栈。

提到火焰图必须提 profiling 了

软件工程中,性能分析performance analysis也称为profiling),是以收集程序运行时信息为手段研究程序行为的分析方法,是一种动态程序分析的方法。

好了,名词解释完毕, 不明白也没关系,如果你想对程序调优,那么,火焰图就是一大利(银)器(弹)。

其实想写 Pyroscope 很久,第一次知道这个项目已经是 2020 年了,当年还在幻想着 log、metric、trace 的大一统平台,无意中发现了 pyroscope 这个尚在襁褓中的宝藏项目,没记错,当时还贡献了一个 pr ,在那之后,没过多久 pyroscope 就被 grafana 收了,很遗憾当时没有持续跟进这个颇具潜力的项目。

Pyroscope 解决了什么问题?

为什么在 go 原生支持 profile 的情况下,还会有 pyroscope 这类持续分析平台?笔者的理解:软件工程中的许多问题是渐变的,而不是跳变的。如果是跳变,说明问题的触发条件明显,这类问题相对比较好定位;如果是渐变的,则需要一个时间段内的历史变化数据来辅助分析,从这个角度看,持续分析和可观测平台是一脉相承,同属一套体系。

以笔者的角度,pyroscope 解决了两个问题

  • 持续分析持久化:提供主流编程语言的采样支持及采样数据存储

  • 持续分析平台化:数据可视化以及与 grafana 的集成

当然,pyroscope 在使用体验上也是非常棒的:

pyroscope 的数据采集有 push、pull 两种方式,后面的示例使用的是 push 方式。

使用 docker 方式快速启动 pyroscope

# docker network create pyroscope-demo
# docker run --rm --name pyroscope --network=pyroscope-demo -p 4040:4040 grafana/pyroscope:latest

Pyroscope 实践

言归正传,虽然觉得 pyroscope 这个项目非常好,但受限于工作场景,实际上并没有太多机会用得到 pyroscope 这枚"银弹",过早优化是万恶之源嘛。直到今年,发现下面要讲的这个简单又直观的场景:获取时间戳。

简单的地方在于,它一个非常平常获取 unix 时间戳的场景,最小化代码示例如下所示:

func getTtimestamp() int64 {
    location, err := time.LoadLocation("Asia/Shanghai")
    if err != nil {
        location = time.FixedZone("CST", 8*3600)
    }
    nowTime := time.Now().In(location)
    return nowTime.Unix()
}

不简单的地方在于每次获取时间戳,都需要调用LoadLocation 获取时区,当我看到这块时,立马就觉得可以优化,用最直观的方式,非 pyroscope 莫属了。

优化前的完整代码示例:

package main

import (
    "net/http"
    "time"

    "github.com/gin-gonic/gin"
    "github.com/grafana/pyroscope-go"
)

func getTtimestamp() int64 {
    // time.LoadLocation 函数通过从系统时区数据库(通常是 /usr/share/zoneinfo)
    // 中加载时区信息,解析并返回一个 *time.Location 对象
    location, err := time.LoadLocation("Asia/Shanghai")
    if err != nil {
        location = time.FixedZone("CST", 8*3600)
    }
    nowTime := time.Now().In(location)
    return nowTime.Unix()
}

func pingHandle(c *gin.Context) {
    c.JSON(http.StatusOK, gin.H{
        "message":   "pong",
        "timestamp": getTtimestamp(),
    })
}

func main() {
    // 采用主动 push 方式接入 pyroscope 
    pyroscope.Start(pyroscope.Config{
        ApplicationName: "simple.golang.app",

        // replace this with the address of pyroscope server
        ServerAddress: "http://localhost:4040",

        // by default all profilers are enabled,
        // but you can select the ones you want to use:
        ProfileTypes: []pyroscope.ProfileType{
            pyroscope.ProfileCPU,
            pyroscope.ProfileAllocObjects,
            pyroscope.ProfileAllocSpace,
            pyroscope.ProfileInuseObjects,
            pyroscope.ProfileInuseSpace,
        },
    })

    r := gin.Default()
    r.GET("/ping", pingHandle)
    r.Run()
}
// GOMAXPROCS=1 go run main.go

可以看到 pyroscope 的接入非常方便,使用 wrk 进行 60s 接口压测

❯ wrk -c 10 -t 2 -d 60s http://localhost:8080/ping
Running 1m test @ http://localhost:8080/ping
  2 threads and 10 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   824.35us  539.11us  16.73ms   75.01%
    Req/Sec     6.28k   606.61     7.47k    74.71%
  751371 requests in 1.00m, 117.52MB read
Requests/sec:  12501.80
Transfer/sec:      1.96MB

优化思路也非常容易想到,获取时区仅执行一次即可,代码示例如下所示:

……
var location *time.Location

func init() {
    var err error
    location, err = time.LoadLocation("Asia/Shanghai")
    if err != nil {
        location = time.FixedZone("CST", 8*3600)
    }
}

func getTtimestamp() int64 {
    nowTime := time.Now().In(location)
    return nowTime.Unix()
}
……

同样进行 60s 的接口压测

❯ wrk -c 10 -t 2 -d 60s http://localhost:8080/ping
Running 1m test @ http://localhost:8080/ping
  2 threads and 10 connections


  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   397.85us  282.91us   9.51ms   81.24%
    Req/Sec    13.14k     1.37k   16.52k    76.87%
  1571427 requests in 1.00m, 245.78MB read
Requests/sec:  26146.19
Transfer/sec:      4.09MB

优化前后接口平均时延: 824.35us vs 397.85us

pyroscope 数据分析

浏览器打开:http://localhost:4040/,进入 pyroscope 可视化页面如下所示:

pyroscope 的 Comparision View 功能正好符合我们对比优化前后性能表现的诉求,先上一张大图

优化前:

在这一分钟的压测里,ServeHTTP 占用的 cpu 时间为 40.9s,其中 getTtimestamp 就占了 30.2s

优化后

在这一分钟的压测里,ServeHTTP 耗时 14.8s,由于显示粒度的原因,图中甚至都找不到 getTtimestamp 的耗时……

bench test

作为对比,看看数据

package tests

import (
    "testing"
    "time"
)

func getTtimestampV1() int64 {
    location, err := time.LoadLocation("Asia/Shanghai")
    if err != nil {
        location = time.FixedZone("CST", 8*3600)
    }
    nowTime := time.Now().In(location)
    return nowTime.Unix()
}

var location *time.Location

func init() {
    var err error
    location, err = time.LoadLocation("Asia/Shanghai")
    if err != nil {
        location = time.FixedZone("CST", 8*3600)
    }
}

func getTtimestampV2() int64 {
    nowTime := time.Now().In(location)
    return nowTime.Unix()
}

func Benchmark_getTtimestampV1(b *testing.B) {
    for n := 0; n < b.N; n++ {
        getTtimestampV1()
    }
}

func Benchmark_getTtimestampV2(b *testing.B) {
    for n := 0; n < b.N; n++ {
        getTtimestampV2()
    }
}

跟前面接口压测一样,使用单 cpu 进行测试

❯ go test -bench=. -cpu=1
goos: darwin
goarch: amd64
pkg: m/tests
cpu: Intel(R) Core(TM) i7-9750H CPU @ 2.60GHz
# 优化前
Benchmark_getTtimestampV1        41948         26891 ns/op
# 优化后
Benchmark_getTtimestampV2     16787149            71.22 ns/op
PASS

单纯从数据看:26891 ns vs 71.22 ns,从绝对时间上看,它们耗时都是非常短的,但却有着惊人的 377 倍性能差异!!!

总结

pyroscope 在持续分析领域是一个非常好的解决方案,笔者觉得可以将其用于开发、测试、预发等环境,它对于辅助分析问题还是非常有帮助的。笔者还没有详细测试过采样对性能的影响,性能敏感场景,不建议直接将其用于生产环境。

本文以获取时间戳的优化的示例为引,目的是在实践中了解、学习并使用 pyroscope。这类场景的优化颇有点吹毛求疵的意思(优化效果是明显的,带来的绝对性能延迟提升是有限的),在实际场景中,还是要优先解决主要的性能瓶颈/问题。

解决问题,经验和直觉很重要,但是有理有据,会更好。无论是 pyroscope,还是 bench test,它们提供了依据,有根据地去优化、对比,如此反复,优化可以走的更远。

ps:过早优化是万恶之源,一定要先抓住主要问题


参考: