错误的性能回溯
Wrong Perf Backtraces
我使用 Perf
在 evince
基准测试中提取 调用图 。使用的命令如下:
sudo perf record -d --call-graph dwarf -c 10000 -e mem_load_uops_retired.l3_miss:uppp /opt/evince-3.28.4/bin/evince
我使用 Perf script
提取了回溯,发现有许多损坏的回溯实例。一些包含重复的冗余函数调用,例如:
EvJobScheduler 10021 8653.926478: 100 mem_load_uops_retired.l3_miss:uppp: 7fffd1062a00 5080022 N/A|SNP N/A|TLB N/A|LCK N/A
7ffff4b07207 tcache_get+0x197 (inlined)
7ffff4b07207 __GI___libc_malloc+0x197 (inlined)
7fffd9872fb9 gmalloc+0x59 (inlined)
7fffd9872fb9 gmallocn+0x59 (/usr/lib/x86_64-linux-gnu/libpoppler.so.73.0.0)
7fffd9872fb9 gmallocn+0x59 (/usr/lib/x86_64-linux-gnu/libpoppler.so.73.0.0)
7fffd9951e6f _ZN8TextLine8coalesceEP10UnicodeMap+0xff (/usr/lib/x86_64-linux-gnu/libpoppler.so.73.0.0)
7fffd9952f82 _ZN9TextBlock8coalesceEP10UnicodeMapd+0x752 (/usr/lib/x86_64-linux-gnu/libpoppler.so.73.0.0)
7fffd995bc37 _ZN8TextPage8coalesceEbdb+0x1507 (/usr/lib/x86_64-linux-gnu/libpoppler.so.73.0.0)
7fffd995cb71 _ZN13TextOutputDev7endPageEv+0x31 (/usr/lib/x86_64-linux-gnu/libpoppler.so.73.0.0)
7fffe803c6d2 _ZL26poppler_page_get_text_pageP12_PopplerPage+0x92 (/usr/lib/x86_64-linux-gnu/libpoppler-glib.so.8.9.0)
7fffe803deb3 poppler_page_get_selection_region+0x63 (/usr/lib/x86_64-linux-gnu/libpoppler-glib.so.8.9.0)
7fffe82ab650 [unknown] (/opt/evince-3.28.4/lib/evince/4/backends/libpdfdocument.so)
7ffff795f165 ev_job_page_data_run+0x2f5 (/opt/evince-3.28.4/lib/libevview3.so.3.0.0)
7ffff7961309 ev_job_thread+0xe9 (inlined)
7ffff7961309 ev_job_thread_proxy+0xe9 (/opt/evince-3.28.4/lib/libevview3.so.3.0.0)
7ffff5492194 g_thread_proxy+0x54 (/usr/lib/x86_64-linux-gnu/libglib-2.0.so.0.5600.4)
7ffff4e686da start_thread+0xda (/lib/x86_64-linux-gnu/libpthread-2.27.so)
7ffff4b9188e __GI___clone+0x3e (inlined)
有两个连续的gmallocs()
是不正确的。有些函数调用是调用者和被调用者不匹配,例如:
evince 10015 8640.962182: 100 mem_load_uops_retired.l3_miss:uppp: 7fffdc005030 5080022 N/A|SNP N/A|TLB N/A|LCK N/A
7ffff5a3275f g_action_get_enabled+0x3f (/usr/lib/x86_64-linux-gnu/libgio-2.0.so.0.5600.4)
7ffff5a2ffcc g_simple_action_group_query_action+0x3c (/usr/lib/x86_64-linux-gnu/libgio-2.0.so.0.5600.4)
7ffff7130d8c gtk_action_muxer_query_action+0xac (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff7130d4c gtk_action_muxer_query_action+0x6c (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff7130d4c gtk_action_muxer_query_action+0x6c (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff7130d4c gtk_action_muxer_query_action+0x6c (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff7130d4c gtk_action_muxer_query_action+0x6c (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff7130994 gtk_action_muxer_action_added+0x64 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff574510c g_closure_invoke+0x19c (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff575805d signal_emit_unlocked_R+0xf4d (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff5760714 g_signal_emit_valist+0xa74 (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff576112e g_signal_emit+0x8e (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff71309e2 gtk_action_muxer_action_added+0xb2 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff574510c g_closure_invoke+0x19c (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff575805d signal_emit_unlocked_R+0xf4d (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff5760714 g_signal_emit_valist+0xa74 (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff576112e g_signal_emit+0x8e (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff71309e2 gtk_action_muxer_action_added+0xb2 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff574510c g_closure_invoke+0x19c (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff575805d signal_emit_unlocked_R+0xf4d (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff5760714 g_signal_emit_valist+0xa74 (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff576112e g_signal_emit+0x8e (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff71309e2 gtk_action_muxer_action_added+0xb2 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff574510c g_closure_invoke+0x19c (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff575805d signal_emit_unlocked_R+0xf4d (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff5760714 g_signal_emit_valist+0xa74 (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff576112e g_signal_emit+0x8e (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff71309e2 gtk_action_muxer_action_added+0xb2 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff7131482 gtk_action_muxer_set_parent+0x1d2 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff73c46f8 gtk_widget_set_parent+0x198 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff73d0228 gtk_window_set_titlebar+0xb8 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
55555558d391 ev_window_init+0x2e1 (/opt/evince-3.28.4/bin/evince)
7ffff57699c4 g_type_create_instance+0x1e4 (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff574a747 g_object_new_internal+0x2e7 (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff574c5bf g_object_new_valist+0x3cf (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff574c938 g_object_new+0x98 (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
55555558f192 ev_window_new+0x42 (/opt/evince-3.28.4/bin/evince)
5555555778f4 ev_application_open_recent_view+0x14 (/opt/evince-3.28.4/bin/evince)
555555573733 load_files+0x473 (inlined)
555555573733 main+0x473 (/opt/evince-3.28.4/bin/evince)
7ffff4a91b96 __libc_start_main+0xe6 (/lib/x86_64-linux-gnu/libc-2.27.so)
555555573899 _start+0x29 (/opt/evince-3.28.4/bin/evince)
这是错误的,因为:
1) gtk_action_muxer_action_added()
在偏移量 0x64
处调用 g_action_group_query_action()
(即十进制的 100
):
0x00000000000f898f <+95>: push %rax
0x00000000000f8990 <+96>: callq 0x84e20 <g_action_group_query_action@plt>
0x00000000000f8995 <+101>: test %eax,%eax
2) gtk_action_muxer_query_action()
在偏移量 0x6c
处调用 g_action_group_query_action()
(即十进制的 108
):
0x00000000000f8d45 <+101>: mov %rbp,%rsi
0x00000000000f8d48 <+104>: callq 0x84e20 <g_action_group_query_action@plt>
0x00000000000f8d4d <+109>: pop %rdx
3) gtk_action_muxer_query_action()
在偏移量 0xac
处调用 g_action_group_query_action()
(即十进制的 172
):
0x00000000000f8d85 <+165>: mov %r12,%rdx
0x00000000000f8d88 <+168>: callq 0x84e20 <g_action_group_query_action@plt>
0x00000000000f8d8d <+173>: pop %rsi
可以看出,其中 none 与报告的回溯相匹配。 Perf
尝试将函数名称与地址匹配时是否会出现问题,或者地址本身是错误的?我该如何修改问题?
内联和优化的尾调用是使 C 源代码中的调用不出现在运行时堆栈回溯中的两种不同方式。
一个内联函数将导致直接从它内联到的父函数调用它的子函数,而这个函数根本不会出现。
多级内联当然是可能的,并且在小函数中很常见。
以优化的 jmp
尾调用结尾的函数使其看起来像是直接从其父级调用被调用方。它没有在自己的堆栈框架下创建新的堆栈框架,而是拆除自己的堆栈框架并跳转到目标函数,return 地址仍然存在。这样新函数的堆栈帧将使用与执行尾调用的函数之前使用的内存相同的内存。
换句话说,任何call func; ret
序列都可以被jmp func
代替。即使 jmp 目标是一个(plt 存根)库函数,或者是 gcc -fno-plt
样式代码生成的间接 call/jmp *printf@GOTPCREL(%rip)
目标,这仍然有效。
另见 https://en.wikipedia.org/wiki/Tail_call
例如
void leaf(); // some other function
void foo() { stuff; ...; leaf(); } // ends with a tailcall
void bar() { stuff; foo(); stuff; }
在 foo
执行 "stuff" 时触发的事件将具有 bar->foo 的回溯。
如果不进行优化,在 "leaf" 中触发的事件将具有类似 bar->foo->leaf 的回溯。
使用优化的尾调用,它将是 bar->leaf,没有 foo,因为 foo 刚刚跳转到 leaf,将其 return 地址转发给 leaf
所以当 leaf
最终 returns 它将直接到 bar
.
这适用于 args 和 return 值,尤其是寄存器 args。并非总是使用堆栈参数,例如,如果 leaf
的堆栈参数多于 foo
.
是不可能的
我使用 Perf
在 evince
基准测试中提取 调用图 。使用的命令如下:
sudo perf record -d --call-graph dwarf -c 10000 -e mem_load_uops_retired.l3_miss:uppp /opt/evince-3.28.4/bin/evince
我使用 Perf script
提取了回溯,发现有许多损坏的回溯实例。一些包含重复的冗余函数调用,例如:
EvJobScheduler 10021 8653.926478: 100 mem_load_uops_retired.l3_miss:uppp: 7fffd1062a00 5080022 N/A|SNP N/A|TLB N/A|LCK N/A
7ffff4b07207 tcache_get+0x197 (inlined)
7ffff4b07207 __GI___libc_malloc+0x197 (inlined)
7fffd9872fb9 gmalloc+0x59 (inlined)
7fffd9872fb9 gmallocn+0x59 (/usr/lib/x86_64-linux-gnu/libpoppler.so.73.0.0)
7fffd9872fb9 gmallocn+0x59 (/usr/lib/x86_64-linux-gnu/libpoppler.so.73.0.0)
7fffd9951e6f _ZN8TextLine8coalesceEP10UnicodeMap+0xff (/usr/lib/x86_64-linux-gnu/libpoppler.so.73.0.0)
7fffd9952f82 _ZN9TextBlock8coalesceEP10UnicodeMapd+0x752 (/usr/lib/x86_64-linux-gnu/libpoppler.so.73.0.0)
7fffd995bc37 _ZN8TextPage8coalesceEbdb+0x1507 (/usr/lib/x86_64-linux-gnu/libpoppler.so.73.0.0)
7fffd995cb71 _ZN13TextOutputDev7endPageEv+0x31 (/usr/lib/x86_64-linux-gnu/libpoppler.so.73.0.0)
7fffe803c6d2 _ZL26poppler_page_get_text_pageP12_PopplerPage+0x92 (/usr/lib/x86_64-linux-gnu/libpoppler-glib.so.8.9.0)
7fffe803deb3 poppler_page_get_selection_region+0x63 (/usr/lib/x86_64-linux-gnu/libpoppler-glib.so.8.9.0)
7fffe82ab650 [unknown] (/opt/evince-3.28.4/lib/evince/4/backends/libpdfdocument.so)
7ffff795f165 ev_job_page_data_run+0x2f5 (/opt/evince-3.28.4/lib/libevview3.so.3.0.0)
7ffff7961309 ev_job_thread+0xe9 (inlined)
7ffff7961309 ev_job_thread_proxy+0xe9 (/opt/evince-3.28.4/lib/libevview3.so.3.0.0)
7ffff5492194 g_thread_proxy+0x54 (/usr/lib/x86_64-linux-gnu/libglib-2.0.so.0.5600.4)
7ffff4e686da start_thread+0xda (/lib/x86_64-linux-gnu/libpthread-2.27.so)
7ffff4b9188e __GI___clone+0x3e (inlined)
有两个连续的gmallocs()
是不正确的。有些函数调用是调用者和被调用者不匹配,例如:
evince 10015 8640.962182: 100 mem_load_uops_retired.l3_miss:uppp: 7fffdc005030 5080022 N/A|SNP N/A|TLB N/A|LCK N/A
7ffff5a3275f g_action_get_enabled+0x3f (/usr/lib/x86_64-linux-gnu/libgio-2.0.so.0.5600.4)
7ffff5a2ffcc g_simple_action_group_query_action+0x3c (/usr/lib/x86_64-linux-gnu/libgio-2.0.so.0.5600.4)
7ffff7130d8c gtk_action_muxer_query_action+0xac (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff7130d4c gtk_action_muxer_query_action+0x6c (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff7130d4c gtk_action_muxer_query_action+0x6c (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff7130d4c gtk_action_muxer_query_action+0x6c (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff7130d4c gtk_action_muxer_query_action+0x6c (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff7130994 gtk_action_muxer_action_added+0x64 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff574510c g_closure_invoke+0x19c (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff575805d signal_emit_unlocked_R+0xf4d (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff5760714 g_signal_emit_valist+0xa74 (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff576112e g_signal_emit+0x8e (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff71309e2 gtk_action_muxer_action_added+0xb2 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff574510c g_closure_invoke+0x19c (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff575805d signal_emit_unlocked_R+0xf4d (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff5760714 g_signal_emit_valist+0xa74 (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff576112e g_signal_emit+0x8e (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff71309e2 gtk_action_muxer_action_added+0xb2 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff574510c g_closure_invoke+0x19c (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff575805d signal_emit_unlocked_R+0xf4d (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff5760714 g_signal_emit_valist+0xa74 (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff576112e g_signal_emit+0x8e (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff71309e2 gtk_action_muxer_action_added+0xb2 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff574510c g_closure_invoke+0x19c (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff575805d signal_emit_unlocked_R+0xf4d (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff5760714 g_signal_emit_valist+0xa74 (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff576112e g_signal_emit+0x8e (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff71309e2 gtk_action_muxer_action_added+0xb2 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff7131482 gtk_action_muxer_set_parent+0x1d2 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff73c46f8 gtk_widget_set_parent+0x198 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
7ffff73d0228 gtk_window_set_titlebar+0xb8 (/usr/lib/x86_64-linux-gnu/libgtk-3.so.0.2200.30)
55555558d391 ev_window_init+0x2e1 (/opt/evince-3.28.4/bin/evince)
7ffff57699c4 g_type_create_instance+0x1e4 (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff574a747 g_object_new_internal+0x2e7 (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff574c5bf g_object_new_valist+0x3cf (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
7ffff574c938 g_object_new+0x98 (/usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.5600.4)
55555558f192 ev_window_new+0x42 (/opt/evince-3.28.4/bin/evince)
5555555778f4 ev_application_open_recent_view+0x14 (/opt/evince-3.28.4/bin/evince)
555555573733 load_files+0x473 (inlined)
555555573733 main+0x473 (/opt/evince-3.28.4/bin/evince)
7ffff4a91b96 __libc_start_main+0xe6 (/lib/x86_64-linux-gnu/libc-2.27.so)
555555573899 _start+0x29 (/opt/evince-3.28.4/bin/evince)
这是错误的,因为:
1) gtk_action_muxer_action_added()
在偏移量 0x64
处调用 g_action_group_query_action()
(即十进制的 100
):
0x00000000000f898f <+95>: push %rax
0x00000000000f8990 <+96>: callq 0x84e20 <g_action_group_query_action@plt>
0x00000000000f8995 <+101>: test %eax,%eax
2) gtk_action_muxer_query_action()
在偏移量 0x6c
处调用 g_action_group_query_action()
(即十进制的 108
):
0x00000000000f8d45 <+101>: mov %rbp,%rsi
0x00000000000f8d48 <+104>: callq 0x84e20 <g_action_group_query_action@plt>
0x00000000000f8d4d <+109>: pop %rdx
3) gtk_action_muxer_query_action()
在偏移量 0xac
处调用 g_action_group_query_action()
(即十进制的 172
):
0x00000000000f8d85 <+165>: mov %r12,%rdx
0x00000000000f8d88 <+168>: callq 0x84e20 <g_action_group_query_action@plt>
0x00000000000f8d8d <+173>: pop %rsi
可以看出,其中 none 与报告的回溯相匹配。 Perf
尝试将函数名称与地址匹配时是否会出现问题,或者地址本身是错误的?我该如何修改问题?
内联和优化的尾调用是使 C 源代码中的调用不出现在运行时堆栈回溯中的两种不同方式。
一个内联函数将导致直接从它内联到的父函数调用它的子函数,而这个函数根本不会出现。
多级内联当然是可能的,并且在小函数中很常见。
以优化的 jmp
尾调用结尾的函数使其看起来像是直接从其父级调用被调用方。它没有在自己的堆栈框架下创建新的堆栈框架,而是拆除自己的堆栈框架并跳转到目标函数,return 地址仍然存在。这样新函数的堆栈帧将使用与执行尾调用的函数之前使用的内存相同的内存。
换句话说,任何call func; ret
序列都可以被jmp func
代替。即使 jmp 目标是一个(plt 存根)库函数,或者是 gcc -fno-plt
样式代码生成的间接 call/jmp *printf@GOTPCREL(%rip)
目标,这仍然有效。
另见 https://en.wikipedia.org/wiki/Tail_call
例如
void leaf(); // some other function
void foo() { stuff; ...; leaf(); } // ends with a tailcall
void bar() { stuff; foo(); stuff; }
在 foo
执行 "stuff" 时触发的事件将具有 bar->foo 的回溯。
如果不进行优化,在 "leaf" 中触发的事件将具有类似 bar->foo->leaf 的回溯。
使用优化的尾调用,它将是 bar->leaf,没有 foo,因为 foo 刚刚跳转到 leaf,将其 return 地址转发给 leaf
所以当 leaf
最终 returns 它将直接到 bar
.
这适用于 args 和 return 值,尤其是寄存器 args。并非总是使用堆栈参数,例如,如果 leaf
的堆栈参数多于 foo
.