Description of problem: The most significant function for debugging the Python runtime is probably "PyEval_EvalFrameEx", and the two most significant variables within it are the local "PyObject* co" and the parameter "PyFrameObject *f" (this is a complicated function; see http://svn.python.org/view/python/trunk/Python/ceval.c?view=markup for the implementation). In F-12 and earlier, these variables were queryable in gdb. In rawhide, these variables are no longer queryable, and this makes it almost impossible to debug issues within the runtime (see e.g. bug 556584) - I need to be able to access these variables to determine what Python-level code is being executed. I'm seeing similar behavior in a local rebuild of the Python rpm: (gdb) frame 9 #9 PyEval_EvalFrameEx (f=<value optimized out>, throwflag=<value optimized out>) at Python/ceval.c:2389 2389 x = call_function(&sp, oparg); (gdb) p co $1 = <value optimized out> (gdb) p f $7 = <value optimized out> local build of python-2.6.2-3.fc12.i386, built with gcc-4.4.2-20.fc12.i686; investigating with "eu-readelf -w /usr/lib/debug/usr/lib/libpython2.6.so.debug" shows: [ 9178a] subprogram external Yes name "PyEval_EvalFrameEx" decl_file 1 decl_line 542 prototyped Yes type [ 8ee95] low_pc +0x000bf410 <PyEval_EvalFrameEx> high_pc +0x000c4e86 frame_base [ 0] call_frame_cfa sibling [ 92543] (snip) [ 917a6] formal_parameter name "f" decl_file 1 decl_line 542 type [ 9046a] location location list [ 5c893] (snip) [ 918b2] variable name "co" decl_file 1 decl_line 562 type [ 90219] (no location in that last one) f's location: [ 5c893] +0x000012c0..+0x00001306 [ 0] fbreg 0 +0x00001ae7..+0x00001af4 [ 0] fbreg 0 Any ideas what I can do to get visibility back on these variables? Is there a way of hinting to the toolchain that a variable is important for debugging? (I'd rather not turn down optimization if possible; this is a performance-critical part of the code). Could this be a recent change in gcc? I'm willing to do some experimental rebuilds if you can give me some pointers on other gcc versions. This is blocking: https://fedoraproject.org/wiki/Features/Python3F13 See also http://sourceware.org/ml/archer/2009-q4/msg00129.html Seen whilst debugging bug 556584: python-2.6.4-6.fc13: i686 build here: http://koji.fedoraproject.org/koji/taskinfo?taskID=1930187 Buildroot components here: http://koji.fedoraproject.org/koji/rpmlist?buildrootID=693709&type=component giving: gcc-4.4.2-20.fc13.i686.rpm Version-Release number of selected component (if applicable): gcc-4.4.2-20.fc13.i686.rpm
> This is blocking: https://fedoraproject.org/wiki/Features/Python3F13 Oops; this should have been: https://fedoraproject.org/wiki/Features/EasierPythonDebugging
Please attach preprocessed source and gcc options used to compile it, on which this can be investigated. This could very well be http://gcc.gnu.org/PR42782 for which Alex posted yesterday a patch: http://gcc.gnu.org/ml/gcc-patches/2010-01/msg01027.html
Thanks. Looks like I'm getting "almost everything" optimized out in my builds. [david@brick Python-2.6.2]$ rpm -q gcc gcc-4.4.2-20.fc12.i686 Command line used in the build: [david@brick Python-2.6.2]$ gcc -pthread -c -fno-strict-aliasing -DNDEBUG -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector --param=ssp-buffer-size=4 -m32 -march=i386 -mtune=generic -fasynchronous-unwind-tables -D_GNU_SOURCE -fPIC -I. -IInclude -I./Include -I/usr/lib/libffi-3.0.5/include -fPIC -DPy_BUILD_CORE -o Python/ceval.o Python/ceval.c Adding "-E" to front to as per "man gcc" (this is for my own reference, I had to look this one up): -E Stop after the preprocessing stage; do not run the compiler proper. The output is in the form of preprocessed source code, which is sent to the standard output. [david@brick Python-2.6.2]$ gcc -E -pthread -c -fno-strict-aliasing -DNDEBUG -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector --param=ssp-buffer-size=4 -m32 -march=i386 -mtune=generic -fasynchronous-unwind-tables -D_GNU_SOURCE -fPIC -I. -IInclude -I./Include -I/usr/lib/libffi-3.0.5/include -fPIC -DPy_BUILD_CORE -o Python/ceval.o Python/ceval.c leading to Python/ceval.o being the postprocessed source, which I'll attach directly.
Created attachment 385701 [details] Postprocessed code via gcc -E Please let me know if there's any other information you need
(In reply to comment #3) > Thanks. > > Looks like I'm getting "almost everything" optimized out in my builds. What I meant by this is that almost all of the parameters in the following backtrace read "<value optimized out>", and, within the frames, most locals appear to be "<value optimized out>" as well: [david@brick Python-2.6.2]$ gdb ./python GNU gdb (GDB) 7.0 [ snip ] (gdb) run Starting program: /home/david/coding/cvs-fedora/python/F-12/Python-2.6.2/python [Thread debugging using libthread_db enabled] Python 2.6.2 (r262:71600, Jan 17 2010, 11:06:21) [GCC 4.4.2 20091222 (Red Hat 4.4.2-20)] on linux2 Type "help", "copyright", "credits" or "license" for more information. >>> Program received signal SIGINT, Interrupt. 0x001ec424 in __kernel_vsyscall () (gdb) bt #0 0x001ec424 in __kernel_vsyscall () #1 0x00516ded in ___newselect_nocancel () at ../sysdeps/unix/syscall-template.S:82 #2 0x00977a4c in readline_until_enter_or_signal (sys_stdin=<value optimized out>, sys_stdout=<value optimized out>, prompt=<value optimized out>) at ./Modules/readline.c:864 #3 call_readline (sys_stdin=<value optimized out>, sys_stdout=<value optimized out>, prompt=<value optimized out>) at ./Modules/readline.c:958 #4 0x04efd6f0 in PyOS_Readline (sys_stdin=<value optimized out>, sys_stdout=<value optimized out>, prompt=<value optimized out>) at Parser/myreadline.c:208 #5 0x04efecda in tok_nextc (tok=<value optimized out>) at Parser/tokenizer.c:784 #6 0x04eff4a7 in tok_get (tok=<value optimized out>, p_start=<value optimized out>, p_end=<value optimized out>) at Parser/tokenizer.c:1131 #7 PyTokenizer_Get (tok=<value optimized out>, p_start=<value optimized out>, p_end=<value optimized out>) at Parser/tokenizer.c:1571 #8 0x04efa877 in parsetok (tok=<value optimized out>, g=<value optimized out>, start=<value optimized out>, err_ret=<value optimized out>, flags=<value optimized out>) at Parser/parsetok.c:159 #9 0x04fba54c in PyParser_ASTFromFile (fp=<value optimized out>, filename=<value optimized out>, start=<value optimized out>, ps1=<value optimized out>, ps2=<value optimized out>, flags=<value optimized out>, errcode=<value optimized out>, arena=<value optimized out>) at Python/pythonrun.c:1458 #10 0x04fbc434 in PyRun_InteractiveOneFlags (fp=<value optimized out>, filename=<value optimized out>, flags=<value optimized out>) at Python/pythonrun.c:820 #11 0x04fbc6ab in PyRun_InteractiveLoopFlags (fp=<value optimized out>, filename=<value optimized out>, flags=<value optimized out>) at Python/pythonrun.c:760 #12 0x04fbc7eb in PyRun_AnyFileExFlags (fp=<value optimized out>, filename=<value optimized out>, closeit=<value optimized out>, flags=<value optimized out>) at Python/pythonrun.c:729 #13 0x04fc9212 in Py_Main (argc=<value optimized out>, argv=<value optimized out>) at Modules/main.c:599 #14 0x080485c7 in main (argc=<value optimized out>, argv=<value optimized out>) at ./Modules/python.c:23
Please try gcc-4.4.2-28.fc12 (in koji).
Thanks. Having done a "make clean; make" with gcc-4.4.2-28.fc12.i686 there is a slight improvement in the case given in comment #5, but unfortunately the case described in comment #0 still optimizes away the critical variables. Specifically (re comment #5: starting the rebuilt "python" in interactive mode then breaking into gdb), the gdb backtrace contains more variables with queryable values than in comment #5, although many are still "<variable optimized out>": (gdb) bt #0 0x002e5424 in __kernel_vsyscall () #1 0x00516ded in ___newselect_nocancel () at ../sysdeps/unix/syscall-template.S:82 #2 0x0011ea4c in readline_until_enter_or_signal (sys_stdin=0x5b5420, sys_stdout=0x5b54c0, prompt=0xb7f495f4 ">>> ") at ./Modules/readline.c:864 #3 call_readline (sys_stdin=0x5b5420, sys_stdout=0x5b54c0, prompt=0xb7f495f4 ">>> ") at ./Modules/readline.c:958 #4 0x04efd6f0 in PyOS_Readline (sys_stdin=<value optimized out>, sys_stdout=<value optimized out>, prompt=<value optimized out>) at Parser/myreadline.c:208 #5 0x04efecda in tok_nextc (tok=<value optimized out>) at Parser/tokenizer.c:784 #6 0x04eff4a7 in tok_get (tok=<value optimized out>, p_start=<value optimized out>, p_end=<value optimized out>) at Parser/tokenizer.c:1131 #7 PyTokenizer_Get (tok=<value optimized out>, p_start=<value optimized out>, p_end=<value optimized out>) at Parser/tokenizer.c:1571 #8 0x04efa877 in parsetok (tok=<value optimized out>, g=<value optimized out>, start=<value optimized out>, err_ret=<value optimized out>, flags=<value optimized out>) at Parser/parsetok.c:159 #9 0x04fba54c in PyParser_ASTFromFile (fp=<value optimized out>, filename=<value optimized out>, start=<value optimized out>, ps1=<value optimized out>, ps2=<value optimized out>, flags=<value optimized out>, errcode=<value optimized out>, arena=<value optimized out>) at Python/pythonrun.c:1458 #10 0x04fbc434 in PyRun_InteractiveOneFlags (fp=<value optimized out>, filename=<value optimized out>, flags=<value optimized out>) at Python/pythonrun.c:820 #11 0x04fbc6ab in PyRun_InteractiveLoopFlags (fp=<value optimized out>, filename=<value optimized out>, flags=<value optimized out>) at Python/pythonrun.c:760 #12 0x04fbc7eb in PyRun_AnyFileExFlags (fp=<value optimized out>, filename=<value optimized out>, closeit=<value optimized out>, flags=<value optimized out>) at Python/pythonrun.c:729 #13 0x04fc9212 in Py_Main (argc=<value optimized out>, argv=<value optimized out>) at Modules/main.c:599 #14 0x080485c7 in main (argc=1, argv=0xbffff374) at ./Modules/python.c:23 However, upon (e.g. debugging a PyGTK app) the PyEval_EvalFrameEx function is still optimizing away the critical "co" and "f" variables: (gdb) bt #0 0x004cb424 in __kernel_vsyscall () #1 0x001dfe0b in __poll (fds=<value optimized out>, nfds=<value optimized out>, timeout=<value optimized out>) at ../sysdeps/unix/sysv/linux/poll.c:83 #2 0x00691a0c in IA__g_poll (fds=<value optimized out>, nfds=<value optimized out>, timeout=<value optimized out>) at gpoll.c:127 #3 0x00684883 in g_main_context_poll (context=<value optimized out>, block=<value optimized out>, dispatch=<value optimized out>, self=<value optimized out>) at gmain.c:2904 #4 g_main_context_iterate (context=<value optimized out>, block=<value optimized out>, dispatch=<value optimized out>, self=<value optimized out>) at gmain.c:2586 #5 0x00684ebf in IA__g_main_loop_run (loop=<value optimized out>) at gmain.c:2799 #6 0x06c31ac9 in IA__gtk_main () at gtkmain.c:1218 #7 0x010eec49 in _wrap_gtk_main (self=0x0) at ./gtk.override:1241 #8 0x04f9d723 in call_function (f=<value optimized out>, throwflag=<value optimized out>) at Python/ceval.c:3690 #9 PyEval_EvalFrameEx (f=<value optimized out>, throwflag=<value optimized out>) at Python/ceval.c:2389 #10 0x04f9eb79 in fast_function (f=<value optimized out>, throwflag=<value optimized out>) at Python/ceval.c:3792 #11 call_function (f=<value optimized out>, throwflag=<value optimized out>) at Python/ceval.c:3727 #12 PyEval_EvalFrameEx (f=<value optimized out>, throwflag=<value optimized out>) at Python/ceval.c:2389 #13 0x04f9f642 in PyEval_EvalCodeEx (co=<value optimized out>, globals=<value optimized out>, locals=<value optimized out>, args=<value optimized out>, argcount=<value optimized out>, kws=<value optimized out>, kwcount=<value optimized out>, defs=<value optimized out>, defcount=<value optimized out>, closure=<value optimized out>) at Python/ceval.c:2968 #14 0x04f9f7a3 in PyEval_EvalCode (co=<value optimized out>, globals=<value optimized out>, locals=<value optimized out>) at Python/ceval.c:522 #15 0x04fba94b in run_mod (mod=<value optimized out>, filename=<value optimized out>, globals=<value optimized out>, locals=<value optimized out>, flags=<value optimized out>, arena=<value optimized out>) at Python/pythonrun.c:1335 #16 0x04fbaa12 in PyRun_FileExFlags (fp=<value optimized out>, filename=<value optimized out>, start=<value optimized out>, globals=<value optimized out>, locals=<value optimized out>, closeit=<value optimized out>, flags=<value optimized out>) at Python/pythonrun.c:1321 #17 0x04fbbf9c in PyRun_SimpleFileExFlags (fp=<value optimized out>, filename=<value optimized out>, closeit=<value optimized out>, flags=<value optimized out>) at Python/pythonrun.c:931 #18 0x04fbc822 in PyRun_AnyFileExFlags (fp=<value optimized out>, filename=<value optimized out>, closeit=<value optimized out>, flags=<value optimized out>) at Python/pythonrun.c:735 #19 0x04fc9212 in Py_Main (argc=<value optimized out>, argv=<value optimized out>) at Modules/main.c:599 #20 0x080485c7 in main (argc=2, argv=0xbffff364) at ./Modules/python.c:23 (gdb) frame 12 #12 PyEval_EvalFrameEx (f=<value optimized out>, throwflag=<value optimized out>) at Python/ceval.c:2389 2389 x = call_function(&sp, oparg); (gdb) p co $1 = <value optimized out> (gdb) p f $2 = <value optimized out> I notice with the above that glibc and GTK are also showing all parameters as "<value optimized out>", so perhaps this is a gdb bug, or perhaps simply that those rpms were built with a toolchain that optimizes the vars away. For what it's worth this is with: gcc-4.4.2-28.fc12.i686 gdb-7.0.1-26.fc12.i686 gtk2-2.18.3-21.fc12.i686 Is there any other information that would be useful in tracking this down?
I see <1><2d04>: Abbrev Number: 34 (DW_TAG_subprogram) <2d05> DW_AT_name : (indirect string, offset: 0x1c85): call_function <2d09> DW_AT_decl_file : 1 <2d0a> DW_AT_decl_line : 3665 <2d0c> DW_AT_prototyped : 1 <2d0d> DW_AT_type : <0x6d2> <2d11> DW_AT_inline : 1 (inlined) <2d12> DW_AT_sibling : <0x2de1> <2><2d16>: Abbrev Number: 35 (DW_TAG_formal_parameter) <2d17> DW_AT_name : (indirect string, offset: 0x17b7): pp_stack <2d1b> DW_AT_decl_file : 1 <2d1c> DW_AT_decl_line : 3665 <2d1e> DW_AT_type : <0x1d66> <2><2d22>: Abbrev Number: 35 (DW_TAG_formal_parameter) <2d23> DW_AT_name : (indirect string, offset: 0x855): oparg <2d27> DW_AT_decl_file : 1 <2d28> DW_AT_decl_line : 3665 <2d2a> DW_AT_type : <0x5a> ... <1><30ea>: Abbrev Number: 45 (DW_TAG_subprogram) <30eb> DW_AT_external : 1 <30ec> DW_AT_name : (indirect string, offset: 0x14c6): PyEval_EvalFrameEx <30f0> DW_AT_decl_file : 1 <30f1> DW_AT_decl_line : 542 <30f3> DW_AT_prototyped : 1 <30f4> DW_AT_type : <0x6d2> <30f8> DW_AT_low_pc : 0x1270 <30fc> DW_AT_high_pc : 0x6ac6 <3100> DW_AT_frame_base : 0x1159 (location list) <3104> DW_AT_sibling : <0x3f1d> <2><3108>: Abbrev Number: 47 (DW_TAG_formal_parameter) <3109> DW_AT_name : f <310b> DW_AT_decl_file : 1 <310c> DW_AT_decl_line : 542 <310e> DW_AT_type : <0x1e5e> <3112> DW_AT_location : 2 byte block: 91 0 (DW_OP_fbreg: 0) <2><3115>: Abbrev Number: 46 (DW_TAG_formal_parameter) <3116> DW_AT_name : (indirect string, offset: 0x1c54): throwflag <311a> DW_AT_decl_file : 1 <311b> DW_AT_decl_line : 542 <311d> DW_AT_type : <0x5a> <3121> DW_AT_location : 2 byte block: 91 4 (DW_OP_fbreg: 4) ... <3><3913>: Abbrev Number: 66 (DW_TAG_inlined_subroutine) <3914> DW_AT_abstract_origin: <0x2d04> <3918> DW_AT_entry_pc : 0x34fe <391c> DW_AT_ranges : 0x7d0 <3920> DW_AT_call_file : 1 <3921> DW_AT_call_line : 2389 <4><3923>: Abbrev Number: 68 (DW_TAG_formal_parameter) <3924> DW_AT_abstract_origin: <0x2d22> <4><3928>: Abbrev Number: 67 (DW_TAG_formal_parameter) <3929> DW_AT_abstract_origin: <0x2d16> <392d> DW_AT_location : 0x488d (location list) which means that PyEval_EvalFrameEx's both arguments should be available through the whole lifetime of the function and call_function (and fast_function too) are inlined and definitely have different arguments from those printed in the (virtual) backtrace. call_function's pp_stack argument has some location list, so is valid at least in some places.
gcc-4.4.3-1.fc13 is now in dist-f13, perhaps best would be if you could do a dist-f13 python rebuild, then we can look all at the same binaries and the same debug info.
Sorry, those parameters of inlined functions was a regression of Fedora GDB against FSF GDB by me, fixed (disabled break-by-name on inlined functions, non-backtrace debugging of inlined code still does not work well anyway): gdb-7.0.50.20100121-5.fc13 gcc-4.4.3-1.fc13 rebuilt python: #0 0x00956430 in __kernel_vsyscall () #1 0x004cb79d in ___newselect_nocancel () at ../sysdeps/unix/syscall-template.S:82 #2 0x002a3a8d in readline_until_enter_or_signal (sys_stdin=0x56e420, sys_stdout=0x56e4c0, prompt=0x80a1f74 ">>> ") at Modules/readline.c:864 #3 call_readline (sys_stdin=0x56e420, sys_stdout=0x56e4c0, prompt=0x80a1f74 ">>> ") at Modules/readline.c:958 #4 0x001338d8 in PyOS_Readline (sys_stdin=0x56e420, sys_stdout=0x56e4c0, prompt=0x80a1f74 ">>> ") at Parser/myreadline.c:208 #5 0x00134ebf in tok_nextc (tok=0x8107e78) at Parser/tokenizer.c:784 #6 0x00135687 in tok_get (tok=0x8107e78, p_start=0xffffc28c, p_end=0xffffc288) at Parser/tokenizer.c:1131 #7 PyTokenizer_Get (tok=0x8107e78, p_start=0xffffc28c, p_end=0xffffc288) at Parser/tokenizer.c:1571 #8 0x00130a2b in parsetok (tok=<value optimized out>, g=<value optimized out>, start=256, err_ret=0xffffc2ec, flags=0xffffc308) at Parser/parsetok.c:159 #9 0x001f1c9d in PyParser_ASTFromFile (fp=0x56e420, filename=0x238d9d "<stdin>", start=256, ps1=0x80a1f74 ">>> ", ps2=0x80a5314 "... ", flags=0xffffc4dc, errcode=0xffffc36c, arena=0x804da68) at Python/pythonrun.c:1458 #10 0x001f3b95 in PyRun_InteractiveOneFlags (fp=0x56e420, filename=0x238d9d "<stdin>", flags=0xffffc4dc) at Python/pythonrun.c:820 #11 0x001f3e23 in PyRun_InteractiveLoopFlags (fp=0x56e420, filename=0x238d9d "<stdin>", flags=0xffffc4dc) at Python/pythonrun.c:760 #12 0x001f3f6f in PyRun_AnyFileExFlags (fp=0x56e420, filename=0x238d9d "<stdin>", closeit=0, flags=0xffffc4dc) at Python/pythonrun.c:729 #13 0x00200a45 in Py_Main (argc=1, argv=0xffffc5d4) at Modules/main.c:599 #14 0x080485c8 in main (argc=1, argv=0xffffc5d4) at Modules/python.c:23 Fedora was displaying now: #2 0x002a3a8d in readline_until_enter_or_signal (signal=<value optimized out>, prompt=<value optimized out>) at Modules/readline.c:864
(In reply to comment #9) > gcc-4.4.3-1.fc13 is now in dist-f13, perhaps best would be if you could do a > dist-f13 python rebuild, then we can look all at the same binaries and the same > debug info. Rebuilt as python-2.6.4-8: - http://koji.fedoraproject.org/koji/taskinfo?taskID=1939018 - x86-64 built using: gcc-4.4.3-1.fc13.x86_64.rpm (buildroot: http://koji.fedoraproject.org/koji/rpmlist?buildrootID=697195&type=component ) - i686 built using: gcc-4.4.3-1.fc13.i686.rpm (buildroot: http://koji.fedoraproject.org/koji/rpmlist?buildrootID=697196&type=component ) (In reply to comment #10) > Sorry, those parameters of inlined functions was a regression of Fedora GDB > against FSF GDB by me, fixed (disabled break-by-name on inlined functions, > non-backtrace debugging of inlined code still does not work well anyway): > gdb-7.0.50.20100121-5.fc13 > > gcc-4.4.3-1.fc13 rebuilt python: [snip] Sorry, but I'm now confused; is this a bug in GDB, in GCC, or both? If this is a GCC bug, to what extent is it likely to affect the entire distribution? (and is a full rebuilt warranted?) (Sorry for my ignorance here)
(In reply to comment #11) > Sorry, but I'm now confused; is this a bug in GDB, in GCC, or both? In the "virtual" frames for inlined functions it was a GDB bug. It is not visible from a single backtrace whether a frame is for inlined function or not - that is printed in `info frame'. The other cases were a GCC bug. The single remaining one in Comment 10: #8 0x00130a2b in parsetok (tok=<value optimized out>, ... is not a GDB bug; I did not investigate more if it is a GCC VTA suboptimal case or not.
parsetok is not necessarily a GCC bug either, the value really might not be available at all. GCC chose to use a regparm(2) calling convention for the static function, and with that calling convention the argument is not necessarily live through the whole function. That said, in this case I'd say tok should be live. At the beginning of function %eax (the incoming tok register) is copied to %esi and var-tracking correctly says that tok is live in %esi. But then there is barrier and code in it uses %esi for a different variable (str), which var-tracking also correctly notes. The code later on moves %esi to %edx and notes that str is live in %edx, but fails to notice that tok is now live again in %esi (restored from spill slot): (note 531 345 375 6 (var_location tok (expr_list:REG_DEP_TRUE (reg/v/f:SI 4 si [orig:81 tok ] [81]) (const_int 0 [0x0]))) NOTE_INSN_VAR_LOCATION) (insn 375 531 391 6 (set (mem/c:SI (plus:SI (reg/f:SI 6 bp) (const_int -44 [0xffffffd4])) [0 %sfp+-20 S4 A32]) (reg/v/f:SI 4 si [orig:81 tok ] [81])) 41 {*movsi_1} (expr_list:REG_DEAD (reg/v/f:SI 4 si [orig:81 tok ] [81]) (nil))) ... (note 585 186 379 19 (var_location str (expr_list:REG_DEP_TRUE (reg/v/f:SI 4 si [orig:67 str ] [67]) (const_int 0 [0x0]))) NOTE_INSN_VAR_LOCATION) (insn 379 585 380 19 (set (reg/v/f:SI 1 dx [orig:67 str ] [67]) (reg/v/f:SI 4 si [orig:67 str ] [67])) 41 {*movsi_1} (expr_list:REG_DEAD (reg/v/f:SI 4 si [orig:67 str ] [67]) (nil))) (insn:TI 380 379 586 19 (set (reg/v/f:SI 4 si [orig:81 tok ] [81]) (mem/c:SI (plus:SI (reg/f:SI 6 bp) (const_int -44 [0xffffffd4])) [0 %sfp+-20 S4 A32])) 41 {*movsi_1} (nil)) (note 586 380 187 19 (var_location str (expr_list:REG_DEP_TRUE (reg/v/f:SI 1 dx [orig:67 str ] [67]) (const_int 0 [0x0]))) NOTE_INSN_VAR_LOCATION) I guess the issue is that we don't track values in the spill slots (%sfp+X) slots since http://gcc.gnu.org/PR37447 change. At least in the easy cases where one spill slot is used solely for one variable this shouldn't be terribly difficult (that's the case here), we'd just have to map the various sfp offsets to actual decls using some hash table. For the easy case we'd just clear it when we see it used for more than one different value. And, if we track anything in the %sfp slots, we should never consider those MEMs to die at call - I believe spill slots can't ever have their address taken in the original program sense, so mem_dies_at_call, though perhaps may_be_aliased already handles that case well.
Created attachment 386582 [details] parsetok.c.bz2 Corresponding preprocessed source with dg-options to compile. Similar problem exists also in the trunk, just it is not %esi, but %ebx, but anyway, while the tok argument clearly has to live at least till the PyTokenizer_Free call immediately before returning, there are several places in the code where var-tracking thinks it isn't live anywhere.
Just to clarify, from my perspective, the most important function for python debuggability is PyEval_EvalFrameEx, and the vars "co" and "f" (see comment #0). A reproducer to investigate this is: $ gdb --args python -c "pass" (gdb) break PyEval_EvalFrameEx (gdb) run Starting program: /usr/bin/python -c pass [Thread debugging using libthread_db enabled] Breakpoint 1, PyEval_EvalFrameEx (f=0x8063b0c, throwflag=0) at Python/ceval.c:543 543 { (gdb) p f $1 = (PyFrameObject *) 0x8063b0c (gdb) p co $2 = <value optimized out> (this is as seen on my F-12 with a local build of python). Ideally both "f" and "co" should be printable; co == f->f_code, so co being unprintable isn't a disaster, though it makes it that much harder to implement gdb-archer prettyprinting code if vars aren't available. (gdb) p f->f_lineno $4 = 59 (gdb) p f->f_code $5 = (PyCodeObject *) 0xb7fd1068 (gdb) p (char*)(((PyStringObject*)f->f_code->co_name)->ob_sval) $6 = 0xb7fcbf34 "<module>" (gdb) p (char*)(((PyStringObject*)f->f_code->co_filename)->ob_sval) $7 = 0xb7fadedc "/usr/lib/python2.6/site.py" (i.e. in this case, the do-nothing "pass" case is executing the code in site.py, as expected; hopefully this illustrates the idea)
gcc-4.4.3-4.{fc12,fc13,el6} should fix even the incomplete location coverage of the tok argument in parsetok.
Reopening, alas. I've been testing: https://fedoraproject.org/wiki/Features/EasierPythonDebugging and am running into the symptoms described in comment #0, specifically that parameter "f" to "PyEval_EvalFrameEx" is showing up in gdb as "variable optimized out". Unfortunately this code and variable are very important: the function is the central python bytecode execution loop, and "f" is the frame information on what python code we're using. I'm assigning this to component "gdb", but obviously I could be wrong on this. This is on a Fedora 13 x86_64 machine with: gdb-7.0.50.20100203-15.fc13.x86_64 [david@f13 ~]$ rpm -q python python-libs python-debuginfo python-2.6.4-23.fc13.x86_64 python-libs-2.6.4-23.fc13.x86_64 python-debuginfo-2.6.4-23.fc13.x86_64 but I've seen this on other recent builds of python. To reproduce, I've been doing: $ sudo yum update CTRL-Z $ sudo gdb attach $(pidof -x yum) (gdb) bt and then looking at PyEval_EvalFrameEx frames Looking at the DWARF data: [david@f13 ~]$ eu-readelf -w /usr/lib/debug/usr/lib64/libpython2.6.so.debug |less (and search for "PyEval_EvalFrameEx") [ 9bd4e] subprogram external Yes name "PyEval_EvalFrameEx" decl_file 1 decl_line 595 prototyped Yes type [ 9926a] low_pc +0x00000000000d8510 <PyEval_EvalFrameEx> high_pc +0x00000000000deb19 frame_base [ 0] call_frame_cfa sibling [ 9ce31] [ 9bd72] formal_parameter name "f" decl_file 1 decl_line 595 type [ 9a8be] location location list [ ee66d] [ 9bd80] formal_parameter name "throwflag" decl_file 1 decl_line 595 type [ 98c70] location location list [ ee6ef] (snip) [ 9be86] variable name "co" decl_file 1 decl_line 615 type [ 9a68b] location location list [ f539c] (snip) and the location for "f" shows up later in the eu-readelf output as: [ ee66d] +0x0000000000001070..+0x00000000000010b6 [ 0] reg5 +0x00000000000010b6..+0x000000000000118b [ 0] reg6 +0x000000000000128a..+0x00000000000012c5 [ 0] reg6 +0x0000000000001307..+0x0000000000001408 [ 0] reg6 +0x0000000000001a8a..+0x0000000000001a97 [ 0] reg5 +0x0000000000001a97..+0x0000000000001ab5 [ 0] reg6 So if I'm reading this right, I believe "f" ought to be visible (in reg5 or reg6?) (or are those PC ranges in which it lives in that register? maybe that's the issue?) Looking at: (gdb) info registers rax 0x442457b 71452027 rbx 0x5 5 rcx 0x34 52 rdx 0x13e 318 rsi 0x440a401 71345153 rdi 0x8 8 rbp 0x3be96d0 0x3be96d0 rsp 0x7fffed1a5030 0x7fffed1a5030 r8 0x4454a48 71649864 r9 0x40b 1035 r10 0x8 8 r11 0x440a4e0 71345376 r12 0x174f0a0 24440992 r13 0x7fbfcaadf144 140461715878212 r14 0x6 6 r15 0xffffffff 4294967295 rip 0x355eedd78c 0x355eedd78c <PyEval_EvalFrameEx+21116> eflags 0x202 [ IF ] cs 0x33 51 ss 0x2b 43 ds 0x0 0 es 0x0 0 fs 0x0 0 gs 0x0 0 fctrl 0x37f 895 fstat 0x0 0 ftag 0xffff 65535 fiseg 0x0 0 fioff 0xd527a1c8 -718822968 foseg 0x0 0 fooff 0xed1a5bc8 -317039672 fop 0x55c 1372 mxcsr 0x1fa0 [ PE IM DM ZM OM UM PM ] and counting down from r9, r8, I guessed "rbp"="reg6", and: (gdb) p (PyFrameObject*)$rbp seems to contain a credible value for f So it looks like the data's there in the "rbp" register, just not being picked up by gdb (does that DWARF data look complete and correct?) Any ideas? Let me know if there's anything I can do to help fix this: I'm very keen on getting this fixed, as without this variable it's significantly harder to debug python. Thanks.
The specific python build I've been testing with is: http://koji.fedoraproject.org/koji/buildinfo?buildID=163534 on x86_64, which was built with this buildroot: http://koji.fedoraproject.org/koji/buildrootinfo?buildrootID=747495 which had: gcc-4.4.3-8.fc13.x86_64.rpm
(In reply to comment #17) > and the location for "f" shows up later in the eu-readelf output as: > > [ ee66d] +0x0000000000001070..+0x00000000000010b6 [ 0] reg5 > +0x00000000000010b6..+0x000000000000118b [ 0] reg6 > +0x000000000000128a..+0x00000000000012c5 [ 0] reg6 > +0x0000000000001307..+0x0000000000001408 [ 0] reg6 > +0x0000000000001a8a..+0x0000000000001a97 [ 0] reg5 > +0x0000000000001a97..+0x0000000000001ab5 [ 0] reg6 > > So if I'm reading this right, I believe "f" ought to be visible (in reg5 or > reg6?) (or are those PC ranges in which it lives in that register? maybe > that's the issue?) Yes, you would have to know also the PC to choose the right line. Tried to rebuild python with gcc-4.4.3-12.fc13.x86_64 but the problem remains. #6 0x00007f85dd56e1b5 in PyEval_EvalFrameEx (f=<value optimized out>, throwflag=<value optimized out>) at Python/ceval.c:2305 PC = 0xd91b5 <1><9c578>: Abbrev Number: 47 (DW_TAG_subprogram) <9c57a> DW_AT_name : (indirect string, offset: 0x10941): PyEval_EvalFrameEx <9c586> DW_AT_low_pc : 0xd8510 <9c58e> DW_AT_high_pc : 0xdeb19 <2><9c59c>: Abbrev Number: 56 (DW_TAG_formal_parameter) <9c59d> DW_AT_name : f <9c5a6> DW_AT_location : 0xf875e (location list) 000f875e 00000000000d8510 00000000000d8556 (DW_OP_reg5) 000f875e 00000000000d8556 00000000000d862b (DW_OP_reg6) 000f875e 00000000000d872a 00000000000d8765 (DW_OP_reg6) 000f875e 00000000000d87a7 00000000000d88a8 (DW_OP_reg6) 000f875e 00000000000d8f2a 00000000000d8f37 (DW_OP_reg5) 000f875e 00000000000d8f37 00000000000d8f55 (DW_OP_reg6) 000f875e <End of list>
(In reply to comment #17) > and counting down from r9, r8, I guessed "rbp"="reg6", and: Besides there is no indication it is in reg5/reg6 still you had a luck. You would have to check: http://www.x86-64.org/documentation/abi.pdf Figure 3.36: DWARF Register Number Mapping Register Name Number Abbreviation General Purpose Register RDI 5 %rdi Frame Pointer Register RBP 6 %rbp GDB cannot directly print the internal DWARF number of a register.
Created attachment 402775 [details] ceval.i.bz2 Well, now you are talking about a different architecture, which has completely different ABI. Unlike i?86 where if the f argument isn't modified, you can always find it in the incoming argument stack slot, here the variable is passed in register (%rdi), which is shortly afterwards clobbered. While the variable is copied into %rbp, apparently f isn't the only thing that is kept in %rbp, in some places this register holds e.g. pos instead and in those locations f isn't available anywhere. So I believe it is correct that gcc says f isn't available everywhere in the function, it is certainly not available where %rbp holds pos, and in places which are reachable either from the locations where %rbp holds f, but also reachable from locations where %rbp holds pos we can't say f lives in %rbp either - while you might see %rbp containing expected value of f in there, it would be because you arrived there through location where f was known to live in %rbp, but the same code could be reached when %rbp would hold some previous pos value. Attached is preprocessed source, here are command line options. -dA -fverbose-asm -fno-strict-aliasing -O2 -g -fexceptions -fstack-protector --param ssp-buffer-size=4 -m64 -mtune=generic -fPIC -o ceval.s ceval.i I guess if you said what exact location do you care about in the function, I could look in more detail whether it isn't some var-tracking bug rather than simply the sad state of things in the optimized huge function. That said, as f isn't really modified in the function, this would be a perfect example where DW_OP_entry_value/DW_TAG_call_site stuff we've been discussing would help, but we still need to discuss it, then propose to DWARF, get some agreement on it and then actually implement it, so that's at least a year away from now.
(In reply to comment #21) > Well, now you are talking about a different architecture, which has completely > different ABI. Unlike i?86 where if the f argument isn't modified, you can Aha; please forgive me here - yes, I'm seeing this issue on x86_64. I've doublechecked, and it's working nicely on i686 - I've tested: python-2.6.4-20.fc13.i686 python-2.6.4-23.fc13.i686 python-2.6.4-24.fc13.i686 and the value of "f" is visible in gdb with all of them. So yes, this is affecting x86_64 only at this point. Am investigating...
This message is a reminder that Fedora 13 is nearing its end of life. Approximately 30 (thirty) days from now Fedora will stop maintaining and issuing updates for Fedora 13. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as WONTFIX if it remains open with a Fedora 'version' of '13'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version prior to Fedora 13's end of life. Bug Reporter: Thank you for reporting this issue and we are sorry that we may not be able to fix it before Fedora 13 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora please change the 'version' of this bug to the applicable version. If you are unable to change the version, please add a comment here and someone will do it for you. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete. The process we are following is described here: http://fedoraproject.org/wiki/BugZappers/HouseKeeping
gcc-4.6.0-10.fc16 has DW_OP_GNU_entry_value support (and typed DWARF stack support), so when F16 gdb gets corresponding support, some of these problems might go away.
Created attachment 538379 [details] sdsdfd dsad
This bug appears to have been reported against 'rawhide' during the Fedora 19 development cycle. Changing version to '19'. (As we did not run this process for some time, it could affect also pre-Fedora 19 development cycle bugs. We are very sorry. It will help us with cleanup during Fedora 19 End Of Life. Thank you.) More information and reason for this action is here: https://fedoraproject.org/wiki/BugZappers/HouseKeeping/Fedora19
FWIW this is still an issue on x86-64 Fedora 18. Now, the 'f' variable in ceval.c:fast_function is optimized away. This prevents "py-bt" from working (and in the future will prevent a python frame filter from working). (top-gdb) down #3 0x00000035264dcef1 in fast_function (nk=<optimized out>, na=0, n=<optimized out>, pp_stack=0x7fffffffdd28, func= <function at remote 0x21bf9b0>) at /usr/src/debug/Python-2.7.3/Python/ceval.c:4184 (top-gdb) p f $4 = <optimized out> One idea was to force this variable to be kept around using an asm. I'd prefer a fix in gcc, I think, but if that is not possible, perhaps this could be reassigned to Python and someone could provide the asm patch.
retval = PyEval_EvalFrameEx(f,0); $pc -> ++tstate->recursion_depth; Py_DECREF(f); 0x3e27cdcee4: mov %rdx,%rdi 0x3e27cdcee7: mov %rdx,0x38(%rsp) 0x3e27cdceec: callq 0x3e27c3c490 <PyEval_EvalFrameEx@plt> => 0x3e27cdcef1: addl $0x1,0x18(%r14) 0x3e27cdcef6: mov %rax,%r15 0x3e27cdcef9: mov 0x38(%rsp),%rdx 0x3e27cdcefe: subq $0x1,(%rdx) 0x3e27cdcf02: jne 0x3e27cdcf0e <PyEval_EvalFrameEx+22046> (gdb) info addr f Symbol "f" is multi-location: Range 0x3e27cdcea1-0x3e27cdceb7: a variable in $rax Range 0x3e27cdceb7-0x3e27cdcef0: a variable in $rdx Range 0x3e27cdcf36-0x3e27cdcf3e: a variable in $rax . So 'f' is stored at 0x38(%rsp) at $pc == 0x3e27cdcef1 .
I'd like to ping this bug again. This bug prevents us from writing a decent gdb frame filter for Python. I would appreciate a fix for it. In an earlier discussion someone (perhaps Jakub, I forget) brought up the issue that such bugs can always reappear, because they are dependent on changes in the optimizers. That is true in general, but in this particular case, if we can write a frame filter, we'll also write a test for it, and this at least will let us detect regressions (perhaps at some distance, after a Python rebuild with a new gcc -- but better than nothing).
This message is a notice that Fedora 19 is now at end of life. Fedora has stopped maintaining and issuing updates for Fedora 19. It is Fedora's policy to close all bug reports from releases that are no longer maintained. Approximately 4 (four) weeks from now this bug will be closed as EOL if it remains open with a Fedora 'version' of '19'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora 19 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged change the 'version' to a later Fedora version prior this bug is closed as described in the policy above. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete.
Fedora 19 changed to end-of-life (EOL) status on 2015-01-06. Fedora 19 is no longer maintained, which means that it will not receive any further security or bug fix updates. As a result we are closing this bug. If you can reproduce this bug against a currently maintained version of Fedora please feel free to reopen this bug against that version. If you are unable to reopen this bug, please file a new report against the current release. If you experience problems, please add a comment to this bug. Thank you for reporting this bug and we are sorry it could not be fixed.