关于linux：使用perf测量到达main函数的时间？

Measure the time to reach the main function using perf?

我想通过测量到达主函数的时间来测量我的程序初始化时间，这样我就得到了”运行时初始化”的时间(例如，bss 部分设置为 0 并调用了全局构造函数) .

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

将一些可以立即终止进程而很少或根本没有清理的东西，例如 exit_group，作为 main 中的第一件事，然后使用 perf stat(查看任务时钟)或简单地使用 time 来测量进程运行时间。

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

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

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

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

1) main:

上的动态跟踪点

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

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

1	perf record -e probe_gctor:main -aR sleep

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

2) 二进制文件的”开始”是一个明智的点。

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

把它放在一起：

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

然后用perf script –header

查看

1
2
3
4
5
6
7
8

# 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:

的方法

1	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 构建自己的跑步者来改进这一点。

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

工作示例：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38

[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./
", 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.

即使在 PIE 可执行文件中，您也应该能够使用 jmp _start ； CRT _start 静态链接到可执行文件，因此它将在 my_start 的 -2GiB 范围内，并且可以达到 rel32 跳转；您不需要 64 位绝对地址。
同样对于数据，像普通人一样使用 [rel start_tsc](或使用 default rel)。另外，不要调用 NASM 源文件 .S；那是用于 GAS 语法源的。称它们为 .asm。您也不需要保存/恢复 rdx ；正常的 CRT 代码不依赖于它在进程进入时被归零。单独存储 TSC 的两半也可能更小，尽管 shr/或在寄存器中创建一个 qword 是相当惯用的。
@PeterCordes 我接受你的观点，谢谢。关于 rdx，我查看了 glibc start.S 并且似乎使用了 rdx，所以这就是我保留它的原因。
@PeterCordes 关于使用两家商店来保存 TSC 的有趣点。一个 store 可能会更好，因为 CPU 每个周期只能发出 1-2 个 store，所以尽量减少 store 的数量是有意义的(因为我们不厌其烦地编写汇编，所以不妨分头)。
啊，对了，我忘记了 ABI 为此指定了哪个寄存器。而且我认为这是真正的进程入口点(因此 RDX 将为零)，但这仅在动态链接器不首先运行的静态可执行文件中才是正确的。谢谢你的链接。
回复：效率。确实，其余的启动代码可能会进行大量存储，因此我们几乎不可能在每个时钟上遇到 1 个存储的瓶颈。但这极不可能。我们应该优化的事情是问题/重命名瓶颈的总 uop 计数，以及代码大小和解码器注意事项。这不是一个循环； out-of-order exec 将与这两个背靠背存储重叠，并带有大量后续指令。存储缓冲区和 ROB 足够大，可以吸收两个背靠背存储，尤其是因为它们位于同一个高速缓存行。 2 mov 存储 = 2 微指令，而你的 3
哦，如果您想要速度而不是代码大小，请将 RDX 保存在 RCX 或任何其他寄存器而不是堆栈中。但是 push/pop 很小。我认为为了获得最大的清晰度/人类读者的利益，您可能应该保持原样。这是为数不多的节省字节或周期的次数之一，因为人类读者的考虑，IMO，因为此代码仅在每个进程中运行一次，并且仅对手动实验有用。
@PeterCordes您击败了我一秒钟，我正要说，而不是推/弹出它可以刮擦另一个寄存器。
@PeterCordes 是的，push/pop 清楚地表明寄存器正在被保留。我喜欢每一行汇编代码都有自己的小代码审查。

原创文章，作者：ItWorker，如若转载，请注明出处：https://blog.ytso.com/269880.html

关于linux：使用perf测量到达main函数的时间？

Measure the time to reach the main function using perf?

相关推荐

发表回复