Pretty-printing backtraces when "python" is the inferior process

Pretty-printing backtraces when "python" is the inferior process

[David Malcolm]

I'm experimenting with archer, and adding python hooks for when the
inferior process is itself Python.

Python already has a gdbinit file with plenty of domain-specific hooks
for debugging CPython; it's written in the gdb language, rather than
python; you can see it here:
http://svn.python.org/view/python/trunk/Misc/gdbinit?view=markup

(is there a meaningful place to install that in distributions? In Fedora
we currently just drop it in a doc subdirectory in our python-devel rpm)


I get a lot of python and pygtk backtraces assigned to me in the Fedora
bug tracker, so I'm keen on extending the GLib backtrace hooks described
at:
http://tromey.com/blog/?p=522
so that Python parts of a gdb backtrace report the python source file,
line number and function, and perhaps even the locals as well
(ultimately I want to fully reimplement the gdbinit file above in
Python, which should be more robust since more logic and error handling
can be moved from the inferior process to gdb; backtrace handling is
probably the biggest win from my own sanity POV right now).


I've attempted to do this, but am running into an issue.  (this is on
Fedora 12 i386)

I've cloned the git repo, and checked out this branch:
$ git checkout --track -b archer-tromey-python origin/archer-tromey-python
$ ./configure --with-separate-debug-dir=/usr/lib/debug
$ make
$ sudo make install

I'm trying to use a freshly-built gdb to debug a pygtk app named
"istanbul" (using system python and system copy of instanbul):
$ ./gdb/gdb --args /usr/bin/python /usr/bin/istanbul
GNU gdb (GDB) 6.8.50.20090910-cvs
Copyright (C) 2009 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later
<http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show
copying"
and "show warranty" for details.
This GDB was configured as "i686-pc-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/bin/python...Reading symbols
from /usr/lib/debug/usr/bin/python2.6.debug...done.
(no debugging symbols found)...done.

(gdb) run
Starting program: /usr/bin/python /usr/bin/istanbul
[Thread debugging using libthread_db enabled]
(snip some debug prints from the pygtk app)
^C
Program received signal SIGINT, Interrupt.
0x00f68424 in __kernel_vsyscall ()

(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);

I'd like to access the local "PyCodeObject *co" at this point:
(gdb) p co
$5 = (PyCodeObject *) 0x81274e8

Doing so using the gdbinit macros mentioned above is fruitful:
(gdb) pyo co
object  : <code object main at 0x81274e8, file "/usr/lib/python2.6/site-packages/istanbul/main/main.py", line 87>
type    : code
refcount: 2
address : 0x81274e8
$4 = void

and I want to use analogous code to implement archer prettyprinting of
the python backtraces.

This API hook works:
(gdb) python print gdb.parse_and_eval("co")
0x81274e8

But this one doesn't:
(gdb) python print gdb.selected_frame().read_var('co')
Traceback (most recent call last):
  File "<string>", line 1, in <module>
ValueError: variable 'co' not found
Error while executing Python code.

I'm a novice at the internals of gdb; I've tried attaching to the first
gdb with a second and putting a breakpoint on py-frame.c's
frapy_read_var; ultimately

lookup_symbol (name=0xc3e1dc8 "co", block=0xcb6d904, domain=VAR_DOMAIN,
is_a_field_of_this=0x0) at symtab.c:1265

is returning NULL.

Any ideas on what's going wrong?


FWIW, The URL for my efforts is here:
https://fedoraproject.org/wiki/DaveMalcolm/FeatureEasierPythonDebugging#Detailed_Description

Thanks!
Dave

Re: Pretty-printing backtraces when "python" is the inferior process

[Tom Tromey]

>>>>> "David" == David Malcolm <dmalcolm@redhat.com> writes:

David> I'm experimenting with archer, and adding python hooks for when the
David> inferior process is itself Python.

Awesome.

David> I've attempted to do this, but am running into an issue.  (this is on
David> Fedora 12 i386)

David> $ git checkout --track -b archer-tromey-python origin/archer-tromey-python

David> (gdb) frame 9
David> #9  PyEval_EvalFrameEx (f=<value optimized out>, throwflag=<value
David> optimized out>) at Python/ceval.c:2389
David> 2389				x = call_function(&sp, oparg);

I tried this same example on my F11 box.

I am not sure exactly what bug you are hitting, but I think it is
something that is fixed either in CVS head or in some other Fedora
patch.  I say that because the example fails with archer-tromey-python,
but works with the F11 system gdb.  I think it has to do with the
representation of inlined frames -- when I trace into lookup_symbol, if
I look at the blocks I eventually see:

    (gdb) p *block.superblock.function
    $5 = {
      ginfo = {
        name = 0x92be5e8 "call_function", 

I don't fully understand this, because I would have expected the
selected frame to be PyEval_EvalFrameEx, not call_function.  However,
I'm planning to do a merge from trunk in early January, which may fix
the problem.  In the meantime, maybe using archer-jankratochvil-fedora12
would be better.  Or even using the system gdb... though that will make
it a bit harder if you need to modify the python libraries.

Tom

Re: Pretty-printing backtraces when "python" is the inferior process

[David Malcolm]

On Wed, 2009-12-23 at 12:32 -0700, Tom Tromey wrote:
> >>>>> "David" == David Malcolm <dmalcolm@redhat.com> writes:
> 
> David> I'm experimenting with archer, and adding python hooks for when the
> David> inferior process is itself Python.
> 
> Awesome.
> 
> David> I've attempted to do this, but am running into an issue.  (this is on
> David> Fedora 12 i386)
> 
> David> $ git checkout --track -b archer-tromey-python origin/archer-tromey-python
> 
> David> (gdb) frame 9
> David> #9  PyEval_EvalFrameEx (f=<value optimized out>, throwflag=<value
> David> optimized out>) at Python/ceval.c:2389
> David> 2389				x = call_function(&sp, oparg);
> 
> I tried this same example on my F11 box.
> 
> I am not sure exactly what bug you are hitting, but I think it is
> something that is fixed either in CVS head or in some other Fedora
> patch.  I say that because the example fails with archer-tromey-python,
> but works with the F11 system gdb.  I think it has to do with the
> representation of inlined frames -- when I trace into lookup_symbol, if
> I look at the blocks I eventually see:
> 
>     (gdb) p *block.superblock.function
>     $5 = {
>       ginfo = {
>         name = 0x92be5e8 "call_function", 
> 
> I don't fully understand this, because I would have expected the
> selected frame to be PyEval_EvalFrameEx, not call_function.  However,
> I'm planning to do a merge from trunk in early January, which may fix
> the problem.  In the meantime, maybe using archer-jankratochvil-fedora12
> would be better.  Or even using the system gdb... though that will make
> it a bit harder if you need to modify the python libraries.

Thanks for looking at this.

Unfortunately it seems to be failing with both the system Fedora 12 gdb
and with archer-jankratochvil-fedora12:

FWIW the function in question (PyEval_EvalFrameEx) is defined in
http://svn.python.org/view/python/trunk/Python/ceval.c?view=markup
and the local I'm most interested in is:
PyCodeObject *co;
this variable contains the interesting information on what's going on at
the python level in a python vm stack frame.

For example:
(gdb) p (char*)((PyStringObject*)co->co_filename)->ob_sval
$3 = 0x810c764 "/usr/lib/python2.6/site-packages/istanbul/main/main.py"
(gdb) p (char*)((PyStringObject*)co->co_name)->ob_sval
$4 = 0xb7fd9374 "main"
(gdb) p co->co_firstlineno
$5 = 87
(gdb) p *co
$6 = {ob_refcnt = 2, ob_type = 0x5039ae0, co_argcount = 1, co_nlocals =
4, co_stacksize = 3, co_flags = 67, co_code = 0xb7fb49e0, co_consts =
0x811f0d4, 
  co_names = 0x810c48c, co_varnames = 0x81261bc, co_freevars =
0xb7fa402c, co_cellvars = 0xb7fa402c, co_filename = 0x810c750, co_name =
0xb7fd9360, 
  co_firstlineno = 87, co_lnotab = 0x811f5d0, co_zombieframe = 0x0}

etc and this could be used to pretty-print the python-level info.

The errors I'm seeing are as before:

Fedora 12 system gdb:
$ /usr/bin/gdb --args /usr/bin/python /usr/bin/istanbul
GNU gdb (GDB) Fedora (7.0-7.fc12)
[snip]
(gdb) frame 9
#9  PyEval_EvalFrameEx (oparg=<value optimized out>, pp_stack=<value
optimized out>) at Python/ceval.c:2389
2389				x = call_function(&sp, oparg);
(gdb) python print gdb.parse_and_eval("co")
0x81274e8
(gdb) python print gdb.selected_frame().read_var('co')
Traceback (most recent call last):
  File "<string>", line 1, in <module>
ValueError: variable 'co' not found
Error while executing Python code.


With archer-jankratochvil-fedora12 it fails in the same way: 
$ ./gdb/gdb --args /usr/bin/python /usr/bin/istanbul
GNU gdb (GDB) 7.0
[snip]
(gdb) python print gdb.parse_and_eval("co")
0x81274e8
(gdb) python print gdb.selected_frame().read_var('co')
Traceback (most recent call last):
  File "<string>", line 1, in <module>
ValueError: variable 'co' not found
Error while executing Python code.



(this was only a shallow inspection; got to run to catch a plane.  This
could be error on my part of course; I know very little about the
innards of gdb).


Dave

Re: Pretty-printing backtraces when "python" is the inferior process

[Tom Tromey]

>>>>> "David" == David Malcolm <dmalcolm@redhat.com> writes:

[ replying to an old thread ]

David> I'm trying to use a freshly-built gdb to debug a pygtk app named
David> "istanbul" (using system python and system copy of instanbul):
[...]
David> I'd like to access the local "PyCodeObject *co" at this point:
David> (gdb) p co
David> $5 = (PyCodeObject *) 0x81274e8

David> This API hook works:
David> (gdb) python print gdb.parse_and_eval("co")
David> 0x81274e8

David> But this one doesn't:
David> (gdb) python print gdb.selected_frame().read_var('co')
David> Traceback (most recent call last):
David>   File "<string>", line 1, in <module>
David> ValueError: variable 'co' not found
David> Error while executing Python code.

I looked at this again and I found a bug in py-frame.c that accounts for
this behavior.  I am testing a patch.

The above isn't quite right though, even with the fix in place.  The
problem is that a given frame may have multiple blocks associated with
it ("block" is basically just a block in C).  In this case there are a
couple, and "co" appears in one of the outer ones.

I used this snippet to look at what symbols were in which block in the
frame:

b = gdb.selected_frame().block()
while True:
  for sym in b:
    print sym.name
  if b.function is not None:
    break
  print "== new block"
  b = b.superblock

I think you have to find the right block to pass to read_var.

Tom