是什么导致无法在 DWARF 性能调用堆栈中展开?

问题描述

在由 perf record --call-graph dwarf 生成并由 perf script 打印的回溯中,我始终收到大约 5% 的调用堆栈的错误地址,即展开失败。一个例子是

my_bin 770395 705462.825887:    3560360 cycles: 
        7f0398b9b7e2 __vsnprintf_internal+0x12 (/usr/lib/x86_64-linux-gnu/libc-2.32.so)
        7ffcdb6fbfdf [unkNown] ([stack])

my_bin 770395 705462.827040:    3447195 cycles: 
        7f0398ba1624 __GI__IO_default_xsputn+0x104 (inlined)
        7ffcdb6fb7af [unkNown] ([stack])

它是从这段代码中产生的(用 g++ -O3 -g -fno-omit-frame-pointer my_bin.cpp -o my_bin 编译):

#include <cstdio>
#include <iostream>

int __attribute__ ((noinline)) libc_string(int x) {
    char buf[64] = {0};
    // Some nonsense workload using libc
    int res = 0;
    for (int i = 0; i < x; ++i) {
        res += snprintf(buf,64,"%d %d %d Can I bring my friends to tea?",(i%10),(i%3)*10,i+2);
        res = res % 128;
    }
    return res;
}

int main() {
    int result = libc_string(20000000);
    std::cout << result << "\n";
}

我很确定我的程序在堆栈中不应该有可执行代码,所以这些地址似乎是错误的。它不仅是一个程序,而且我分析过的大多数程序都有大约 5% 的错误调用堆栈。这些调用堆栈大多只有两个堆栈帧,最里面的一个有时在像 Eigen 这样的库中(即使它们通常具有正确的调用堆栈),有时在 C++ STL 或 libc 中。我已经看到在 unkNown[stack][heap]anon//anonlibstdc++.so.6.0.28 或 {{1} }.

我在 Ubuntu 18.04、20.04 和 20.10 上看到过这个。

这只发生在 DWARF 展开时。如何解决这个问题?

解决方法

您还测试了哪些其他类型的展开?

在示例中,我 disabled kernel ASLR feature 使用 setarch x86_64 -R 以获得更稳定的地址和更小的 perf.data 文件。

使用 perf record option -e cycles:u 命令可能会有所帮助,因为它不包括内核样本。

对于使用 __GI__IO_default_xsputn (inlined) 函数的默认 perf 记录事件('-e 循环:u';使用了 libc6-prof package 的 libc-2.31)生成的文件,我重现了类似的 dwarf 展开问题:>

env LD_LIBRARY_PATH=/lib/libc6-prof/x86_64-linux-gnu setarch `uname -m` -R perf record --call-graph dwarf -o perf.data.dwarf.u -e cycles:u ./my_bin
perf script -i perf.data.dwarf.u |less

不正确的样本:

my_bin 28100 760107.271010:     461418 cycles:u: 
            7ffff7c74f06 __GI__IO_default_xsputn+0x106 (inlined)
            7ffff7c59c6c __vfprintf_internal+0xf4c (/usr/lib/libc6-prof/x86_64-linux-gnu/libc-2.31.so)

正确示例:

my_bin 28100 760107.257283:     267268 cycles:u: 
            7ffff7c74eff __GI__IO_default_xsputn+0xff (inlined)
            7ffff7c59c6c __vfprintf_internal+0xf4c (/usr/lib/libc6-prof/x86_64-linux-gnu/libc-2.31.so)
            7ffff7c6e9f6 __vsnprintf_internal+0xb6 (/usr/lib/libc6-prof/x86_64-linux-gnu/libc-2.31.so)
            7ffff7d14a2c ___snprintf_chk+0x9c (inlined)
            555555555314 libc_string+0xb4 (/home/user/so/my_bin)
            555555555314 libc_string+0xb4 (/home/user/so/my_bin)
            555555555111 main+0x11 (/home/user/so/my_bin)
            7ffff7c040fa __libc_start_main+0x10a (/usr/lib/libc6-prof/x86_64-linux-gnu/libc-2.31.so)
            55555555519d _start+0x2d (/home/user/so/my_bin)

为了正确展开,我在 __GI__IO_default_xsputn+(+ 后面的数字)中有许多不同的偏移量:

perf script -i perf.data.dwarf.u ||grep vsnprintf_internal -B3 |grep _GI__IO_default_xsputn|cut -d + -f 2|sort | uniq -c
...
    208 0x0 (inlined)
     45 0x101 (inlined)
      2 0x105 (inlined)
     91 0x10 (inlined)
    294 0x110 (inlined)
      2 0x117 (inlined)
      2 0x11d (inlined)
    326 0x121 (inlined)

但是我没有正确展开的 +0x106 地址。并且所有不正确的展开都有 +0x106 地址。让我们用gdb检查一下(禁用ASLR后更容易;+262是+0x106):

env LD_LIBRARY_PATH=/lib/libc6-prof/x86_64-linux-gnu setarch `uname -m` -R  gdb -q ./my_bin
(gdb) start
(gdb) x/i 0x7ffff7c74f06
   0x7ffff7c74f06 <__GI__IO_default_xsputn+262>:    retq  
(gdb) disassemble __GI__IO_default_xsputn
Dump of assembler code for function __GI__IO_default_xsputn:
...
   0x00007ffff7c74f05 <+261>:   pop    %rbp
   0x00007ffff7c74f06 <+262>:   retq   

展开问题似乎与在 retq 指令或 pop %rbp 之后采样的内联 (?) 函数有关?