使用 perf 测量到达主要功能的时间？

Question

我想通过测量到达主函数的时间来测量我的程序初始化时间，以便我得到 "run-time initializations" 的时间（例如，bss 部分设置为 0 并调用全局构造函数）。

我如何使用 perf 来做到这一点？

Answer 1

首先，您必须考虑 perf 并不是真正测量时间——它记录的是事件。现在您可以做一些分析并查看调用堆栈并得出一些有关初始化的信息，但是为了测量特定时间，我们需要记录开始和结束时间戳。

如果时间达到main函数，我们可以使用

1) main:

上的动态跟踪点

$ sudo perf probe -x ./gctor main Added new event:   probe_gctor:main  (on main in ./gctor)

您现在可以在所有性能工具中使用它，例如：

perf record -e probe_gctor:main -aR sleep

这确实需要相当高的权限，我将在示例中使用 root。

2) 二进制文件 "start" 的合理点。

我建议跟踪点 syscalls:sys_exit_execve。这基本上是在 perf record 开始执行您的二进制文件之后。这适用于我的版本 (5.3.7) - 如果它不适合你，你可能需要修补一下。您当然可以只使用 -e cycles，但稍后您会收到不想要的事件的垃圾邮件。

放在一起：

sudo perf record -e probe_gctor:main -e syscalls:sys_exit_execve ./gctor
                  ^ this is what perf probe told you earlier

然后用perf script --header

来看

# time of first sample : 77582.919313
# time of last sample : 77585.150377
# sample duration :   2231.064 ms
[....]
# ========
#
           gctor 238828 [007] 77582.919313: syscalls:sys_exit_execve: 0x0
           gctor 238828 [001] 77585.150377:         probe_gctor:main: (5600ea33414d)

您可以根据这两个样本计算它，或者如果您的轨迹中确实只有这两个样本，则使用 sample duration。

为了完整起见：这里有一种使用 gdb 的方法：

gdb ./gctor -ex 'b main' -ex 'python import time' -ex 'python ts=time.time()' -ex 'run' -ex 'python print(time.time()-ts)'

这不太准确，在我的系统上有大约 100 毫秒的开销，但它不需要更高的权限。您当然可以通过在 C 中使用 fork/ptrace/exec 构建自己的跑步者来改进这一点。

Answer 2

放置一些可以立即终止进程的东西，几乎不需要清理，比如 exit_group，作为 main 中的第一件事，然后使用 perf stat（查看任务时钟）或简单地 time 测量过程运行时间。

如果您不需要专门使用 perf，一种非破坏性的方法是使用 clock() 调用，它测量自进程启动以来的 CPU 时间，并且对于大多数如果您在 main 开始时发出进程（不在 main 之前启动线程或阻塞），它等于在 main 之前花费的实际时间。

我经常将 clock() 与 perf 的 --delay 选项一起使用，以 从测量中排除 启动成本。这实际上导致了第三种方法——采用运行和不包含排除启动的 --delay 参数之间的统计差异。如果您想获取启动部分时间以外的性能统计信息，这将很有用。

Answer 3

另一种选择是提供您自己的可执行入口点，记录时间戳计数器，然后将控制转移到标准入口点_start。当输入 main 时，您可以从现在减去它以获得 C 或 C++ 运行时间启动的确切周期计数。

工作示例：

[max@supernova:~/src/test] $ cat test.cc
#include <stdint.h>
#include <stdio.h>

extern uint64_t start_tsc;

int main() {
    uint64_t main_tsc = __builtin_ia32_rdtsc();
    printf("C/C++ run-time start took %lu cycles.\n", main_tsc - start_tsc);
}

[max@supernova:~/src/test] $ cat mystart.asm
        global mystart
        global start_tsc
        extern _start

        section .text
mystart:
        push rdx
        rdtsc
        shl rdx, 32
        or rax, rdx
        mov [rel start_tsc], rax
        pop rdx
        jmp _start

        section .data
start_tsc:
        dq 0

[max@supernova:~/src/test] $ make
g++ -o test.o -c -W{all,extra,error} -g -Og test.cc
nasm -felf64 -o mystart.o mystart.asm
g++ -o test -g -Wl,-emystart test.o mystart.o 

[max@supernova:~/src/test] $ ./test
C/C++ run-time start took 5314 cycles.

使用 perf 测量到达主要功能的时间？

Measure the time to reach the main function using perf?

linux

benchmarking

perf