From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mail-wm1-x333.google.com (mail-wm1-x333.google.com [IPv6:2a00:1450:4864:20::333]) by sourceware.org (Postfix) with ESMTPS id A0FD6385DC35 for ; Thu, 25 Jun 2020 16:51:40 +0000 (GMT) DMARC-Filter: OpenDMARC Filter v1.3.2 sourceware.org A0FD6385DC35 Authentication-Results: sourceware.org; dmarc=none (p=none dis=none) header.from=embecosm.com Authentication-Results: sourceware.org; spf=pass smtp.mailfrom=andrew.burgess@embecosm.com Received: by mail-wm1-x333.google.com with SMTP id 22so6254252wmg.1 for ; Thu, 25 Jun 2020 09:51:40 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=embecosm.com; s=google; h=date:from:to:cc:subject:message-id:references:mime-version :content-disposition:in-reply-to; bh=DezdwANeFzc4NqaDLnGgZIQHCIIJE8uyxNNICsqM/BY=; b=COqwc5SpVJxo8bCo3/Pao8mRdz4pn5lSkr9LJGyg3znqY8uzbdUzLKhl2eXmGLKLms 2cN7ruFLc1UEcH0vM9Ilkag3i7y0eU0NF/BA67M+L2zj5o89zCWiqF6YlxIlTGvqQPGu xgmmaslbOFp8fHj7vNN6YBkiTKQeLwUPH569O9RKqU7z9roFKfZzu2cjqYTeEpmnZPhX 7XaUbI97mwUAiO+umnWgHs506UOaOV7yQWGuA8EJCWQEopbnHEkRPSmMlgdKSbiU02uK vbkfw0oJNE36TpGBMoBjbIsfEqeHPCS+5Ucdb0jZ6I5OueN/asW5EOTYz9QkHmAwRCc0 v4Ow== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:date:from:to:cc:subject:message-id:references :mime-version:content-disposition:in-reply-to; bh=DezdwANeFzc4NqaDLnGgZIQHCIIJE8uyxNNICsqM/BY=; b=pPNV8FoW/xZvlyfPp4FL7RsixVmc/WQ6mpHpu6SJ87ZAUa2Sgip4KSpaXcskNmDma6 QF6J5seUTCw3bmhfb1DYzSj4rhynr9oCxuNCK9DDpKdiTsvByC+o+4KBMS2M5H4vNROO B8mxGyvB/p4MOmLw/RDQTQ/8o1KFcYMhnxinjHWdSt99ivt7+lxJg0F/H/2ArxdgXUc/ bzmnJb7BfAkr3IMAx6cO8MGL6qa/LfBL5P2dsQYSiZ3Dv9iE6Alr8Nyy13jdRgce07jo UJmX1rMONTKoZtVInqrdeLEXXvDQC7y4ZWbDJwup6Xu0NW2lahHKK0jfhQXWRd/TUYeO BaPg== X-Gm-Message-State: AOAM531luz4XbOOAwiI5X0qf/L7vRnIKgA/duue4F+jgbVYpUnHKd8KW dZP8ofacryjQJkiF0ZuQMHwuEA== X-Google-Smtp-Source: ABdhPJy1woblaRhVkOXWbGqf6h13rtk5vr4t6LYn6vQg1yQc3xKu+jtF1qvG2gkd4N2mtIS4p2FTkA== X-Received: by 2002:a1c:4c0d:: with SMTP id z13mr4122976wmf.97.1593103899563; Thu, 25 Jun 2020 09:51:39 -0700 (PDT) Received: from localhost (host86-128-12-16.range86-128.btcentralplus.com. [86.128.12.16]) by smtp.gmail.com with ESMTPSA id 2sm12733967wmo.44.2020.06.25.09.51.38 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Thu, 25 Jun 2020 09:51:38 -0700 (PDT) Date: Thu, 25 Jun 2020 17:51:37 +0100 From: Andrew Burgess To: Ahmad Nouralizadeh Cc: Jan Kratochvil , "gdb@sourceware.org" Subject: Re: GDB Frame Unwinding for Pure Assembly Code Message-ID: <20200625165137.GD3463@embecosm.com> References: <20200622213956.GA3486027@host1.jankratochvil.net> <20200623072654.GA3548953@host1.jankratochvil.net> <20200624150602.GN623665@embecosm.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: X-Operating-System: Linux/5.6.15-200.fc31.x86_64 (x86_64) X-Uptime: 17:46:07 up 17 days, 6:53, X-Editor: GNU Emacs [ http://www.gnu.org/software/emacs ] X-Spam-Status: No, score=-3.9 required=5.0 tests=BAYES_00, DKIM_SIGNED, DKIM_VALID, DKIM_VALID_AU, DKIM_VALID_EF, RCVD_IN_BARRACUDACENTRAL, RCVD_IN_DNSWL_NONE, SPF_HELO_NONE, SPF_PASS, TXREP autolearn=no autolearn_force=no version=3.4.2 X-Spam-Checker-Version: SpamAssassin 3.4.2 (2018-09-13) on server2.sourceware.org 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: Thu, 25 Jun 2020 16:51:42 -0000 * 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 > > > > > > > > > >