GDB Frame Unwinding for Pure Assembly Code

Mon Jun 22 21:29:01 GMT 2020

Hi,
I ran a simple ffmpeg benchmark in perf to record dram access samples
with backtraces. Perf copies stack contents during execution and uses
libunwind to unwind the backtraces in a post-process phase. The
problem is that ffmpeg has many pure assembly implementations which do
not have entries in ".eh_frame". Therefore, libunwind can not unwind
backtraces containing these access points. For example, GDB reports
the following backtrace which has a pure assembly code address in the
innermost frame (i.e., #0):
#0  0x00007fffeab68840 in x264_pixel_avg_w16_avx2 () at
/usr/lib/x86_64-linux-gnu/libx264.so.152
#1  0x00007fffeaabdad9 in x264_mb_mc_01xywh (h=0x5555561dea00, x=0,
y=0, width=4, height=<optimized out>) at common/macroblock.c:128
#2  0x00007fffeab0dd37 in x264_macroblock_analyse
(h=h@entry=0x5555561dea00) at encoder/analyse.c:3456
#3  0x00007fffeab48c6e in x264_slice_write (h=0x5555561dea00) at
encoder/encoder.c:2739
#4  0x00007fffeab85286 in x264_stack_align () at
/usr/lib/x86_64-linux-gnu/libx264.so.152
#5  0x00007fffeab45bdc in x264_slices_write (h=h@entry=0x5555561dea00)
at encoder/encoder.c:3079
#6  0x00007fffeab52062 in x264_encoder_encode (h=<optimized out>,
pp_nal=pp_nal@entry=0x7fffffffca28,
pi_nal=pi_nal@entry=0x7fffffffca20,
pic_in=pic_in@entry=0x555555828098,
pic_out=pic_out@entry=0x7fffffffca30) at encoder/encoder.c:3738
#7  0x00007ffff5ff8cd1 in X264_frame (ctx=0x555555827800,
pkt=0x55555610acc0, frame=0x55555633a500, got_packet=0x7fffffffcc64)
at src/libavcodec/libx264.c:337
#8  0x00007ffff5dbc6c7 in avcodec_encode_video2
(avctx=avctx@entry=0x555555827800, avpkt=0x55555610acc0,
frame=frame@entry=0x55555633a500,
got_packet_ptr=got_packet_ptr@entry=0x7fffffffcc64) at
src/libavcodec/encode.c:307
#9  0x00007ffff5dbcaad in do_encode (avctx=0x555555827800,
frame=0x55555633a500, got_packet=0x7fffffffcc64) at
src/libavcodec/encode.c:378
#10 0x00007ffff5dbcc5a in avcodec_send_frame (avctx=0x555555827800,
frame=0x55555633a500) at src/libavcodec/encode.c:427
#11 0x000055555557e253 in do_video_out (of=0x555555825020,
ost=0x5555558208a0, next_picture=0x55555633a500, sync_ipts=<optimized
out>) at src/fftools/ffmpeg.c:1288
#12 0x000055555558220f in reap_filters (flush=0) at src/fftools/ffmpeg.c:1506
#13 0x00005555555611b2 in transcode_step () at src/fftools/ffmpeg.c:4588
#14 0x00005555555611b2 in transcode () at src/fftools/ffmpeg.c:4632
#15 0x00005555555611b2 in main (argc=<optimized out>, argv=<optimized
out>) at src/fftools/ffmpeg.c:4838

Unlike GDB, Perf (precisely, libunwind) can not unwind this backtrace
and only reports the innermost frame (i.e.,
"x264_pixel_avg_w16_avx2()"). I traced GDB execution at backtrace
report time and this seems to be the point where the RIP value (i.e.,
"0x00007fffeaabdad9") for the next to the innermost frame (frame 1?!)
is retrieved:
#0  _Z27frame_unwind_register_valueP10frame_infoi
(frame=0x55555673c2e0, regnum=16) at frame.c:1234
#1  0x00005555558b231e in
_Z21frame_register_unwindP10frame_infoiPiS1_P9lval_typePmS1_Ph
(frame=0x55555673c2e0, regnum=16, optimizedp=0x7fffffffd6d0,
    unavailablep=0x7fffffffd6d4, lvalp=0x7fffffffd6dc,
addrp=0x7fffffffd6e0, realnump=0x7fffffffd6d8, bufferp=0x7fffffffd710
" \327\377\377\377\177") at frame.c:1096
#2  0x00005555558b2643 in _Z21frame_unwind_registerP10frame_infoiPh
(frame=0x55555673c2e0, regnum=16, buf=0x7fffffffd710 "
\327\377\377\377\177") at frame.c:1153
#3  0x0000555555602706 in i386_unwind_pc (gdbarch=0x555556692200,
next_frame=0x55555673c2e0) at i386-tdep.c:1965
#4  0x00005555558c6056 in _Z17gdbarch_unwind_pcP7gdbarchP10frame_info
(gdbarch=0x555556692200, next_frame=0x55555673c2e0) at gdbarch.c:3075
#5  0x00005555558b1b0b in frame_unwind_pc (this_frame=0x55555673c2e0)
at frame.c:885
#6  0x00005555558b4f72 in _Z12get_frame_pcP10frame_info
(frame=0x55555673c490) at frame.c:2379
#7  0x00005555558b50ea in _Z26get_frame_address_in_blockP10frame_info
(this_frame=0x55555673c490) at frame.c:2410
#8  0x0000555555905d53 in inline_frame_sniffer (self=0x555556193520
<inline_frame_unwind>, this_frame=0x55555673c490,
this_cache=0x55555673c4a8) at inline-frame.c:215
#9  0x00005555558b719a in frame_unwind_try_unwinder
(this_frame=0x55555673c490, this_cache=0x55555673c4a8,
unwinder=0x555556193520 <inline_frame_unwind>)
    at frame-unwind.c:106
#10 0x00005555558b737d in
_Z26frame_unwind_find_by_frameP10frame_infoPPv
(this_frame=0x55555673c490, this_cache=0x55555673c4a8) at
frame-unwind.c:164
#11 0x00005555558b0d8f in compute_frame_id (fi=0x55555673c490) at frame.c:501
#12 0x00005555558b407d in get_prev_frame_if_no_cycle
(this_frame=0x55555673c2e0) at frame.c:1913
#13 0x00005555558b478e in get_prev_frame_always_1
(this_frame=0x55555673c2e0) at frame.c:2087
#14 0x00005555558b47e6 in _Z21get_prev_frame_alwaysP10frame_info
(this_frame=0x55555673c2e0) at frame.c:2103
#15 0x00005555558b4e39 in _Z14get_prev_frameP10frame_info
(this_frame=0x55555673c2e0) at frame.c:2356
#16 0x00005555556b7fab in _Z26frame_info_to_frame_objectP10frame_info
(frame=0x55555673c2e0) at python/py-frame.c:372
#17 0x00005555556bd003 in bootstrap_python_frame_filters
(frame=0x55555673c2e0, frame_low=0, frame_high=-1) at
python/py-framefilter.c:1283
#18 0x00005555556bd3a2 in
_Z24gdbpy_apply_frame_filterPK23extension_language_defnP10frame_infoi19ext_lang_frame_argsP6ui_outii
(
    extlang=0x5555560c3c40 <extension_language_python>,
frame=0x55555673c2e0, flags=7, args_type=CLI_SCALAR_VALUES,
out=0x55555636bef0, frame_low=0, frame_high=-1)
    at python/py-framefilter.c:1359
#19 0x00005555558a8664 in
_Z27apply_ext_lang_frame_filterP10frame_infoi19ext_lang_frame_argsP6ui_outii
(frame=0x55555673c2e0, flags=7, args_type=CLI_SCALAR_VALUES,
    out=0x55555636bef0, frame_low=0, frame_high=-1) at extension.c:570
#20 0x00005555559e33b4 in backtrace_command_1 (count_exp=0x0,
show_locals=0, no_filters=0, from_tty=1) at stack.c:1789
#21 0x00005555559e3816 in backtrace_command (arg=0x0, from_tty=1) at
stack.c:1902
#22 0x000055555566c8a4 in do_const_cfunc (c=0x555556344a70, args=0x0,
from_tty=1) at cli/cli-decode.c:106
#23 0x000055555566fba8 in _Z8cmd_funcP16cmd_list_elementPKci
(cmd=0x555556344a70, args=0x0, from_tty=1) at cli/cli-decode.c:1886
#24 0x0000555555a4066e in _Z15execute_commandPKci (p=0x55555660a1d2
"", from_tty=1) at top.c:630
#25 0x00005555558a1b58 in _Z15command_handlerPKc
(command=0x55555660a1d0 "bt") at event-top.c:583
#26 0x00005555558a1f6c in _Z20command_line_handlerPc
(rl=0x55555ac9fe70 "") at event-top.c:774
#27 0x00005555558a12c6 in gdb_rl_callback_handler (rl=0x55555ac9fe70
"") at event-top.c:213
#28 0x0000555555aca378 in rl_callback_read_char () at callback.c:220
#29 0x00005555558a11b2 in gdb_rl_callback_read_char_wrapper_noexcept
() at event-top.c:175
#30 0x00005555558a1231 in gdb_rl_callback_read_char_wrapper
(client_data=0x5555561f9030) at event-top.c:192
#31 0x00005555558a19ea in _Z19stdin_event_handleriPv (error=0,
client_data=0x5555561f9030) at event-top.c:511
#32 0x000055555589f930 in handle_file_event (file_ptr=0x555560306720,
ready_mask=1) at event-loop.c:733
#33 0x000055555589fef9 in gdb_wait_for_event (block=1) at event-loop.c:859
#34 0x000055555589ec76 in _Z16gdb_do_one_eventv () at event-loop.c:347
#35 0x000055555589ecbd in _Z16start_event_loopv () at event-loop.c:371
#36 0x000055555592869b in captured_command_loop () at main.c:330
#37 0x0000555555929c7c in captured_main (data=0x7fffffffe3f0) at main.c:1157
#38 0x0000555555929d51 in _Z8gdb_mainP18captured_main_args
(args=0x7fffffffe3f0) at main.c:1173
#39 0x00005555555ff4a3 in main (argc=2, argv=0x7fffffffe4f8) at gdb.c:32

I'm not sure if this is the moment when that RIP value (i.e.,
"0x00007fffeaabdad9") is actually calculated (perhaps it was
calculated as soon as the inferior process stopped and retrieved in
the above backtrace). 1) Am I right?
My other question is:
2) How can GDB get around the problem with pure assembly files (those
assembled using NASM,... and not GCC)?
Based on the second backtrace, it seems that, GDB differentiates
between frames and has detected that the innermost frame should use
"inline_frame_sniffer" as the unwinder to find its return point (i.e.,
"0x00007fffeaabdad9").
I also checked for two such pure assembly cases and saw that the
return address is exactly where $RSP points. Is it possible that GDB,
luckily, found the return address? Perhaps, because the assembly code
is only a single level of function call (e.g., there is no pure
assembly call to another pure assembly code) and no stack manipulation
(i.e., push/pop) happened after the assembly function is called and
before the breakpoint is triggered (Note that the above backtrace
triggers immediately when the assembly function is called and is not a
good example. But in reality my samples are in the middle of the
assembly functions)?

Any guesses/ideas is appreciated. The code is really advanced and hard
to grasp. In other words, I'm stuck.

Regards.