From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mail-wm1-x331.google.com (mail-wm1-x331.google.com [IPv6:2a00:1450:4864:20::331]) by sourceware.org (Postfix) with ESMTPS id 0DFBD3858D34 for ; Fri, 26 Jun 2020 11:33:06 +0000 (GMT) DMARC-Filter: OpenDMARC Filter v1.3.2 sourceware.org 0DFBD3858D34 Received: by mail-wm1-x331.google.com with SMTP id q15so8516073wmj.2 for ; Fri, 26 Jun 2020 04:33:06 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:in-reply-to:references:from:date :message-id:subject:to:cc; bh=Qg++N6Y+MsMszThav5NXiZjd+RzLVK1GPGykGgj1Po0=; b=Ergs2VdRnGyQ7cHBBpi6AUyuYujLwo3Aq5vplqV6X1pqHCEwn0xC2+6riOPP1vwtHj EzP+rE+YKwklbnv5Er7nmb8MelUo2ha8eThBipQ81rOSSxiq5DOtoZ55J066ciP9wnHw lO5WMW+LsQHW2L+ib4wufCso60RZjVOT42KB7GGRy1gJugF07TAaBG+H1wvV7k37Fgr9 CdaeeBANU+RPMhjyJRiSGH/R2powYdv++KyV7C8P/Yj6qJxZdn/m/JoaH90u0Foxv4qL EO0OAnl79IMbD+Qo9GXOGb4bVj+3GPCOdnJkGUyxGABZvq46Fn5mBsYyl4Dy1l9Pgey7 oQ7g== X-Gm-Message-State: AOAM530ng9w3bgv57iZEDfH7A1m0fzQeoqcLKxTmxNPGfxB+G+y8opwN MYjvS5OIbh0sQmS52wmH73qIFfzzRS8STtwVMhs= X-Google-Smtp-Source: ABdhPJysU68Rt/z7Tv3kLLfeB7zUsm63jjZWzbYv6NDYVQf7sH0QdpTaErp7T2nn0aP9ZK2c30WP2fNAi/wNeKlI2Y0= X-Received: by 2002:a1c:61d7:: with SMTP id v206mr2830420wmb.173.1593171185001; Fri, 26 Jun 2020 04:33:05 -0700 (PDT) MIME-Version: 1.0 Received: by 2002:a1c:5654:0:0:0:0:0 with HTTP; Fri, 26 Jun 2020 04:33:04 -0700 (PDT) In-Reply-To: <20200625165137.GD3463@embecosm.com> References: <20200622213956.GA3486027@host1.jankratochvil.net> <20200623072654.GA3548953@host1.jankratochvil.net> <20200624150602.GN623665@embecosm.com> <20200625165137.GD3463@embecosm.com> From: Ahmad Nouralizadeh Date: Fri, 26 Jun 2020 16:03:04 +0430 Message-ID: Subject: Re: GDB Frame Unwinding for Pure Assembly Code To: Andrew Burgess Cc: Jan Kratochvil , "gdb@sourceware.org" X-Spam-Status: No, score=-2.0 required=5.0 tests=BAYES_00, DKIM_SIGNED, DKIM_VALID, DKIM_VALID_AU, DKIM_VALID_EF, FREEMAIL_FROM, HTML_MESSAGE, RCVD_IN_DNSWL_NONE, SPF_HELO_NONE, SPF_PASS, TXREP autolearn=ham autolearn_force=no version=3.4.2 X-Spam-Checker-Version: SpamAssassin 3.4.2 (2018-09-13) on server2.sourceware.org Content-Type: text/plain; charset="UTF-8" X-Content-Filtered-By: Mailman/MimeDel 2.1.29 X-BeenThere: gdb@sourceware.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: Gdb mailing list List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 26 Jun 2020 11:33:09 -0000 Thanks, Andrew, I will try harder. Regards. On Thursday, 25 June 2020, Andrew Burgess wrote: > * Ahmad Nouralizadeh [2020-06-25 13:40:21 +0430]: > > > Hi Andrew, > > > > Thanks! This makes many things clear to me. > > > > I enabled frame debugging (by setting the global variable, "frame_debug", > > to 1). The frame debugging information shows that, the frame that Perf > > could not unwind (i.e., the next to the innermost frame of ffmpeg > > benchmark), is extracted using the inline unwinder. It knows that > > "0x7fffeaabdad9" is stored at $RSP. The value is accessed using the > > following backtrace: > > #0 _Z23frame_unwind_got_memoryP10frame_infoim (frame=0x555556314750, > > regnum=16, addr=140737488309304) at frame-unwind.c:236 > > #1 0x000055555561dc64 in amd64_frame_prev_register > > (this_frame=0x555556314750, this_cache=0x555556314768, regnum=16) at > > amd64-tdep.c:2642 > > #2 0x00005555558b27d4 in _Z27frame_unwind_register_valueP10frame_infoi > > (frame=0x555556314750, regnum=16) at frame.c:1194 > > #3 0x00005555558b231e in > > _Z21frame_register_unwindP10frame_infoiPiS1_P9lval_typePmS1_Ph > > (frame=0x555556314750, regnum=16, optimizedp=0x7fffffffd6e0, > > unavailablep=0x7fffffffd6e4, lvalp=0x7fffffffd6ec, > > addrp=0x7fffffffd6f0, realnump=0x7fffffffd6e8, bufferp=0x7fffffffd720 > > "0\327\377\377\377\177") at frame.c:1096 > > #4 0x00005555558b2643 in _Z21frame_unwind_registerP10frame_infoiPh > > (frame=0x555556314750, regnum=16, buf=0x7fffffffd720 > > "0\327\377\377\377\177") at frame.c:1153 > > #5 0x0000555555602706 in i386_unwind_pc (gdbarch=0x5555566924c0, > > next_frame=0x555556314750) at i386-tdep.c:1965 > > #6 0x00005555558c6056 in _Z17gdbarch_unwind_pcP7gdbarchP10frame_info > > (gdbarch=0x5555566924c0, next_frame=0x555556314750) at gdbarch.c:3075 > > #7 0x00005555558b1b0b in frame_unwind_pc (this_frame=0x555556314750) at > > frame.c:885 > > #8 0x00005555558b4f72 in _Z12get_frame_pcP10frame_info > > (frame=0x555556314900) at frame.c:2379 > > #9 0x00005555558b50ea in _Z26get_frame_address_in_blockP10frame_info > > (this_frame=0x555556314900) at frame.c:2410 > > #10 0x0000555555905d53 in inline_frame_sniffer (self=0x555556193520 > > , this_frame=0x555556314900, > > this_cache=0x555556314918) at inline-frame.c:215 > > #11 0x00005555558b719a in frame_unwind_try_unwinder > > (this_frame=0x555556314900, this_cache=0x555556314918, > > unwinder=0x555556193520 ) > > at frame-unwind.c:106 > > #12 0x00005555558b737d in _Z26frame_unwind_find_by_frameP10frame_infoPPv > > (this_frame=0x555556314900, this_cache=0x555556314918) at > frame-unwind.c:164 > > #13 0x00005555558b0d8f in compute_frame_id (fi=0x555556314900) at > > frame.c:501 > > #14 0x00005555558b407d in get_prev_frame_if_no_cycle > > (this_frame=0x555556314750) at frame.c:1913 > > #15 0x00005555558b478e in get_prev_frame_always_1 > > (this_frame=0x555556314750) at frame.c:2087 > > #16 0x00005555558b47e6 in _Z21get_prev_frame_alwaysP10frame_info > > (this_frame=0x555556314750) at frame.c:2103 > > #17 0x00005555558b4e39 in _Z14get_prev_frameP10frame_info > > (this_frame=0x555556314750) at frame.c:2356 > > #18 0x00005555556b7fab in _Z26frame_info_to_frame_objectP10frame_info > > (frame=0x555556314750) at python/py-frame.c:372 > > #19 0x00005555556bd003 in bootstrap_python_frame_filters > > (frame=0x555556314750, frame_low=0, frame_high=-1) at > > python/py-framefilter.c:1283 > > #20 0x00005555556bd3a2 in > > _Z24gdbpy_apply_frame_filterPK23extension_language_ > defnP10frame_infoi19ext_lang_frame_argsP6ui_outii > > ( > > extlang=0x5555560c3c40 , > > frame=0x555556314750, flags=7, args_type=CLI_SCALAR_VALUES, > > out=0x55555636bed0, frame_low=0, frame_high=-1) > > at python/py-framefilter.c:1359 > > #21 0x00005555558a8664 in > > _Z27apply_ext_lang_frame_filterP10frame_infoi19ext_ > lang_frame_argsP6ui_outii > > (frame=0x555556314750, flags=7, args_type=CLI_SCALAR_VALUES, > > out=0x55555636bed0, frame_low=0, frame_high=-1) at extension.c:570 > > #22 0x00005555559e33b4 in backtrace_command_1 (count_exp=0x0, > > show_locals=0, no_filters=0, from_tty=1) at stack.c:1789 > > #23 0x00005555559e3816 in backtrace_command (arg=0x0, from_tty=1) at > > stack.c:1902 > > #24 0x000055555566c8a4 in do_const_cfunc (c=0x555556344a60, args=0x0, > > from_tty=1) at cli/cli-decode.c:106 > > #25 0x000055555566fba8 in _Z8cmd_funcP16cmd_list_elementPKci > > (cmd=0x555556344a60, args=0x0, from_tty=1) at cli/cli-decode.c:1886 > > #26 0x0000555555a4066e in _Z15execute_commandPKci (p=0x555556609e52 "", > > from_tty=1) at top.c:630 > > #27 0x00005555558a1b58 in _Z15command_handlerPKc (command=0x555556609e50 > > "bt") at event-top.c:583 > > #28 0x00005555558a1f6c in _Z20command_line_handlerPc (rl=0x55555ab70790 > "") > > at event-top.c:774 > > #29 0x00005555558a12c6 in gdb_rl_callback_handler (rl=0x55555ab70790 "") > at > > event-top.c:213 > > #30 0x0000555555aca378 in rl_callback_read_char () at callback.c:220 > > #31 0x00005555558a11b2 in gdb_rl_callback_read_char_wrapper_noexcept () > at > > event-top.c:175 > > #32 0x00005555558a1231 in gdb_rl_callback_read_char_wrapper > > (client_data=0x5555561f9030) at event-top.c:192 > > #33 0x00005555558a19ea in _Z19stdin_event_handleriPv (error=0, > > client_data=0x5555561f9030) at event-top.c:511 > > #34 0x000055555589f930 in handle_file_event (file_ptr=0x55555af2fd60, > > ready_mask=1) at event-loop.c:733 > > #35 0x000055555589fef9 in gdb_wait_for_event (block=1) at > event-loop.c:859 > > #36 0x000055555589ec76 in _Z16gdb_do_one_eventv () at event-loop.c:347 > > #37 0x000055555589ecbd in _Z16start_event_loopv () at event-loop.c:371 > > #38 0x000055555592869b in captured_command_loop () at main.c:330 > > #39 0x0000555555929c7c in captured_main (data=0x7fffffffe400) at > main.c:1157 > > #40 0x0000555555929d51 in _Z8gdb_mainP18captured_main_args > > (args=0x7fffffffe400) at main.c:1173 > > #41 0x00005555555ff4a3 in main (argc=2, argv=0x7fffffffe508) at gdb.c:32 > > > > "#1 0x000055555561dc64 in amd64_frame_prev_register > > (this_frame=0x555556314750, this_cache=0x555556314768, regnum=16) at > > amd64-tdep.c:2642", is this code snippet: > > return frame_unwind_got_memory (this_frame, regnum, > > cache->saved_regs[regnum]); > > > > There seems to be a cache of registers. > > The last parameter of "#0 _Z23frame_unwind_got_memoryP10frame_infoim > > (frame=0x555556314750, regnum=16, addr=140737488309304) at > > frame-unwind.c:236" shows that addr is 140737488309304 which is > > "0x7fffffff4c38" in hex (RSP for the innermost ffmpeg backtrace function > > (frame -1) that I mentioned in the first thread, is in fact equal > > to "0x7fffffff4c38"). GDB, somehow, knows that the $RIP value for frame 0 > > (i.e. "#1 0x00007fffeaabdad9 in x264_mb_mc_01xywh (h=0x5555561dea00, > x=0, > > y=0, width=4, height=) at common/macroblock.c:128") is > > stored at "0x7fffffff4c38" (i.e., the RSP value for frame -1). But I do > not > > know how! Perhaps, luckily, because there is no push/pop in the innermost > > function of the ffmpeg workload?! > > If you're on x86-64 then the place to start in answering this question > would be amd64-tdep.c:amd64_analyze_prologue. I'm no expert on this > code, but the basic idea is we actually inspect the instructions, and > so long as the prologue of the function follows some basic conventions > then we can figure out the size of the stack frame, and where the > important bits of state have been written too. > > Obviously it is trivially easy to write a prologue that _can't_ be > scanned, as Jan said earlier in the thread, the prologue scanner is a > last ditched fall back for when no other scanner wants to claim the > frame. > > I think the most common usage for the prologue scanning unwinder is to > unwind compiler generated code when the debug info has been stripped. > As such the "conventions" that I mention are actually just "what does > the compiler spit out", and from time to time the prologue scanner > will get an update as GCC/LLVM starts spitting out some new > instruction into the prologue. > > Hope that helps a little. > > Thanks, > Andrew > > > > > > > > > Here is the initial portion of the GDB output, when frame_debug is > enabled: > > Thread 1 "ffmpeg" hit Breakpoint 1, 0x00007fffeab68840 in > > x264_pixel_avg_w16_avx2 () from /usr/lib/x86_64-linux-gnu/libx264.so.152 > > (gdb) bt > > { get_prev_frame_always (this_frame=-1) -> > > {level=0,type=NORMAL_FRAME,unwind=0x555556191780,pc= > 0x7fffeab68840,id=,func=} > > // cached > > { get_prev_frame_always (this_frame=-1) -> > > {level=0,type=NORMAL_FRAME,unwind=0x555556191780,pc= > 0x7fffeab68840,id=,func=} > > // cached > > { compute_frame_id (fi=0) { get_frame_func (this_frame=0) -> > 0x7fffeab68840 > > } > > { frame_unwind_register_value (frame=-1,regnum=7(rsp),...) -> register=7 > > bytes=[f845ffffff7f0000] } > > { frame_id_p (l={stack=0x7fffffff4600,code=0x7fffeab68840,!special}) -> > 1 } > > -> {stack=0x7fffffff4600,code=0x7fffeab68840,!special} } > > { get_prev_frame_always (this_frame=0) -> > > {level=1,type=,unwind=,pc=, > id=,func=} > > } > > { compute_frame_id (fi=1) { frame_unwind_arch (next_frame=0) -> > i386:x86-64 > > } > > { frame_unwind_register_value (frame=0,regnum=16(rip),...) -> > > address=0x7fffffff45f8 bytes=[d9daabeaff7f0000] } > > { frame_unwind_pc (this_frame=0) -> 0x7fffeaabdad9 } > > { get_frame_func (this_frame=1) -> 0x7fffeaabd860 } > > { frame_id_p (l={!stack,!code,!special}) -> 0 } > > { frame_unwind_register_value (frame=0,regnum=7(rsp),...) -> computed > > bytes=[0046ffffff7f0000] } > > { frame_id_p (l={stack=0x7fffffff4940,code=0x7fffeaabd860,!special}) -> > 1 } > > -> {stack=0x7fffffff4940,code=0x7fffeaabd860,!special} } > > #0 0x00007fffeab68840 in x264_pixel_avg_w16_avx2 () from > > /usr/lib/x86_64-linux-gnu/libx264.so.152 > > { get_prev_frame_always (this_frame=0) -> > > {level=1,type=NORMAL_FRAME,unwind=0x5555560c8820,pc= > 0x7fffeaabdad9,id={stack=0x7fffffff4940,code= > 0x7fffeaabd860,!special},func=0x7fffeaabd860} > > // cached > > #1 0x00007fffeaabdad9 in x264_mb_mc_01xywh ({ frame_id_p > > (l={stack=0x7fffffff4940,code=0x7fffeaabd860,!special}) -> 1 } > > { frame_id_eq > > (l={stack=0x7fffffff4940,code=0x7fffeaabd860,!special},r={ > stack=,!code,special=0x0}) > > -> 0 } > > > > The $RIP value for frame 0 is reported as "{ frame_unwind_register_value > > (frame=0,regnum=16(rip),...) -> address=0x7fffffff45f8 > > bytes=[d9daabeaff7f0000] }". > > > > Regards. > > > > On Wednesday, 24 June 2020, Andrew Burgess > > wrote: > > > > > * Ahmad Nouralizadeh via Gdb [2020-06-23 16:18:42 > > > +0430]: > > > > > > > Thanks for the answer! Could you tell me why is an inline unwinder > used? > > > > > > What you saw in your GDB backtrace was this: > > > > > > #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 > > > , 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 ) at frame-unwind.c:106 > > > > > > So GDB hasn't decided for sure that a frame is an inline frame, > > > instead it is running the inline_frame_sniffer to see if a particular > > > frame is an inline frame or not. > > > > > > In order to figure this out GDB needs to know the value of $pc in the > > > frame that is being sniffed. To get the $pc value GDB asks the next > > > frame (that would be a frame with a lower frame number in GDB terms) > > > to unwind the $pc register. You can see this happening between frames > > > #8 and #6 in the above, before finally in #5 we ask the next frame to > > > unwind the $pc. > > > > > > Almost every frame will have had the inline frame unwinder run on it > > > in order to figure out if it was an inline frame, that doesn't mean > > > the inline frame unwinder will claim the frame. > > > > > > Hope that helps, > > > Thanks, > > > Andrew > > > > > > > > > > > > > > > > > > > > > > > On Tuesday, 23 June 2020, Jan Kratochvil > > > wrote: > > > > > > > > > On Mon, 22 Jun 2020 23:55:30 +0200, Ahmad Nouralizadeh via Gdb > wrote: > > > > > > But knowing the GDB mechanism to get over the problem will be > > > helpful. > > > > > > > > > > GDB disassembles the code and tries to guess how to unwind it. > > > > > amd64-tdep.c amd64_analyze_prologue(), amd64_frame_cache_1() etc. > > > > > > > > > > That is just a last resort way of unwinding (=a bug in the > debuggee), > > > there > > > > > should always be .eh_frame in the debuggee, also for throwing > > > exceptions > > > > > across such .eh_frame-less functions if there is any callback > there. > > > > > > > > > > > > > > > Jan > > > > > > > > > > > > > >