Code.1 pprof 分析测试用例

测试 pprof
查看 cpu
占用

首先,我们声明一个耗时函数。传递一个 time.Duration
的数据类型,表示函数执行的时间。注意,这里不能使用 time.Sleep
,它得不到 cpu
的执行。函数如下:

// 耗时函数
func consumer(ctx context.Context, s time.Duration) {
    subCtx, _ := context.WithTimeout(ctx, s)
    i := 0

    for {
        select {
        case <-subCtx.Done():
            fmt.Println(i)
            return
        default:
            i = i + 2
        }
    }
}

我们再声明一个冗余的函数,这个函数调用 consumer
,同时 Copy
一份 consumer
的逻辑

// 间接耗时4s
func indirectConsumer(ctx context.Context, s time.Duration) {
    consumer(ctx, s)
    
    // copy同一份代码
    subCtx, _ := context.WithTimeout(ctx, s)
    i := 0

    for {
        select {
        case <-subCtx.Done():
            fmt.Println(i)
            return
        default:
            i = i + 2
        }
    }
}

最后,我们写一个 Test
,来生成 cpu_profile
文件。

// 生成CPU Profile文件
func TestConsumer(t *testing.T) {
    pf, err := os.OpenFile("cpu_profile", os.O_RDWR|os.O_CREATE, 0644)
    if err != nil {
        t.Fatal(err)
    }
    defer pf.Close()

    pprof.StartCPUProfile(pf)
    defer pprof.StopCPUProfile()

    ctx := context.Background()

    // 耗时2s
    consumer(ctx, time.Second*2)

    // 耗时4s
    indirectConsumer(ctx, time.Second*2)
}

查看我们生成的 pprof
文件,这里我们使用 web
的方式来查看。在命令行执行:

go tool pprof -http=:1888 cpu_profile

页面直接跳转到浏览器,并提供了很多菜单选项。我们看一下我机器上 Top
的情况:

关注一下 local/one-case.indirectConsumer
local/one-case.consumer
,他们的占比基本是相同的,这也跟我们的预期是相同的。

通过查看 Graph
我们可以清楚的看到调用的流程。 Test
内部直接调用了 consumer
函数,而 indirectConsumer
也调用了 consumer
函数。


通过 Source
我们可以看到具体的代码的耗时占比。它明确的表示了 flat
cum
占用的时长。从某种意义上来说,这才是所谓的 cpu
的直接调用和间接调用关系。我们使用 indirectConsumer
为例:


如果觉得 Graph
图拉的很长,我们可以选择 Flame Graph
来查看。我们也展示一下: