如何在golang中测量函数的执行时间，不包括等待时间

Posted 2023-03-06

【中文标题】如何在golang中测量函数的执行时间，不包括等待时间

【英文标题】：How to measure execution time of function in golang, excluding waiting time

【发布时间】：2019-05-05 08:16:19

【问题描述】：

我有个需求测量go中插件的执行时间(cpu cost)，我们可以把插件当成函数，可能有很多goroutine同时运行。更准确地说，执行时间应该不包括空闲时间（goroutine等待时间），只有cpu获取时间（当前goroutine）。 就像：

go func()
    // this func is a plugin
    ** start to record cpu acquire time of current func/plugin/goroutine **
    ** run code **
    ** stop to record cpu acquire time of current func/plugin/goroutine **
    log.Debugf("This function is buzy for %d millisecs.", cpuAcquireTime)
    ** report cpuAcquirTime to monitor **
()

在我的情况下，很难进行单元测试来衡量功能，代码很难解耦。

我在google和***上搜索都没有找到任何线索，有没有什么解决方案可以满足我的需求，是不是占用了太多资源？

【问题讨论】：

我假设，简单地从time.Now() 中减去两个值还不够好？

@rustyx CentOS Linux 版本 7.4.1708（核心）

@Sergio Tulentsev 对，它会包括 goroutine 退出时的空闲时间。

【参考方案1】：

对于后来像我一样偶然发现此问题的人，您实际上可以使用内置的 syscall.Getrusage 而不是使用 Cgo。这样的一个例子看起来像

func GetCPU() int64 
    usage := new(syscall.Rusage)
    syscall.Getrusage(syscall.RUSAGE_SELF, usage)
    return usage.Utime.Nano() + usage.Stime.Nano()

在将调用进程 (RUSAGE_SELF) 的 Utime（用户 CPU 时间）和 Stime（系统 CPU 时间）都转换为纳秒后，我将它们加起来。 man 2 getrusage 有更多关于这个系统调用的信息。

syscall.Timeval 的文档表明 Nano() 返回自 Unix 纪元以来的纳秒时间，但在我的测试和查看实现时，它似乎实际上只返回以纳秒为单位的 CPU 时间，而不是自Unix 纪元。

【讨论】：

如果只为了调用 goroutine 加上它的分叉子项而这样做呢？ （例如，与此并行运行的任何内容都不会影响算法的用户和系统时间）

【参考方案2】：

Go 中没有内置方法来测量 CPU 时间，但您可以通过特定于平台的方式来测量。

例如，在 POSIX 系统（例如 Linux）上，使用 clock_gettime 和 CLOCK_THREAD_CPUTIME_ID 作为参数。

同样，您可以使用 CLOCK_PROCESS_CPUTIME_ID 测量进程 CPU 时间，使用 CLOCK_MONOTONIC 测量经过的时间。

例子：

package main

/*
#include <pthread.h>
#include <time.h>
#include <stdio.h>

static long long getThreadCpuTimeNs() 
    struct timespec t;
    if (clock_gettime(CLOCK_THREAD_CPUTIME_ID, &t)) 
        perror("clock_gettime");
        return 0;
    
    return t.tv_sec * 1000000000LL + t.tv_nsec;

*/
import "C"
import "fmt"
import "time"

func main() 
    cputime1 := C.getThreadCpuTimeNs()
    doWork()
    cputime2 := C.getThreadCpuTimeNs()
    fmt.Printf("CPU time = %d ns\n", (cputime2 - cputime1))


func doWork() 
    x := 1
    for i := 0; i < 100000000; i++ 
        x *= 11111
    
    time.Sleep(time.Second)

输出：

CPU time = 31250000 ns

注意输出以纳秒为单位。所以这里的 CPU 时间是 0.03 秒。

【讨论】：

这看起来是一个不错的解决方案，但是我想知道一个goroutine是否有uniq CLOCK_THREAD_CPUTIME_ID ，我会花一些时间学习“clock_gettime”，做一些实验和反馈，非常感谢。跨度>

为此，导入 C 必须紧跟在 C 代码头之后