Jeremy Hylton : weblog : 2003-10-03

Tracing the Python Stack in GDB

Friday, October 03, 2003

When Python is hung or otherwise unresponsive, one option is to attach to the process with gdb and inspect if the C stack to find out what the interpreter is doing. It is straightforward if you are familiar with the Python internals; this note is intended to describe the basics for people who aren't.

info threads will show you each of the threads in the process. Example:

(gdb) info threads
  2 Thread 1147100464 (LWP 9881)  0xffffe002 in ?? ()
  1 Thread 1074906720 (LWP 8497)  0xffffe002 in ?? ()

where will display the C stack from the current frame up. up and down let you up and down on the stack. Look at the names of the C functions. Many of the lowest functions will have obvious names, like time_sleep or select_select; they'll tell you what system call the process is currently executing.

#0  0xffffe002 in ?? ()
#1  0x400236ca in time_sleep (self=0x0, args=0x41c7e734)
    at /home/jeremy/src/python/Modules/timemodule.c:208
#2  0x08108126 in PyCFunction_Call (func=0x403c237c, arg=0x41c7e734, kw=0x0)
    at ../Objects/methodobject.c:73
#3  0x080c07e4 in call_function (pp_stack=0xbfffc454, oparg=1)
    at ../Python/ceval.c:3439
#4  0x080bd0c9 in eval_frame (f=0x9397c5c) at ../Python/ceval.c:2116
#5  0x080bed95 in PyEval_EvalCodeEx (co=0x404f36b0, globals=0x403e7b74,
    locals=0x0, args=0x922fe54, argcount=2, kws=0x922fe5c, kwcount=0,
    defs=0x403f8208, defcount=1, closure=0x0) at ../Python/ceval.c:2663
#6  0x080c0bd9 in fast_function (func=0x403f9264, pp_stack=0xbfffc674, n=2,
    na=2, nk=0) at ../Python/ceval.c:3529
#7  0x080c0919 in call_function (pp_stack=0xbfffc674, oparg=1)
    at ../Python/ceval.c:3458
#8  0x080bd0c9 in eval_frame (f=0x922fcf4) at ../Python/ceval.c:2116

The eval_frame() function is important for inspecting the Python runtime. Each Python function call will produce a new eval_frame() call on the C stack. The argument f to eval_frame() is a PyFrameObject. The frame contains the current line number and a pointer to the PyCodeObject, which has the name of the function and the name of the file that contains it.

It is straightforward to print the line number, but extracting the file and filename strings is a little trickier. The PyCodeObject has PyObject * pointers, so you must cast them to PyStringObject * to extract the string contents.

(gdb) up 4
#4  0x080bd0c9 in eval_frame (f=0x9397c5c) at ../Python/ceval.c:2116
2116                            x = call_function(&stack_pointer, oparg);
(gdb) p f->f_lineno
$1 = 195
(gdb) x/s ((PyStringObject*)f->f_code->co_filename)->ob_sval
0x404f3674:      "/usr/local/lib/python2.4/threading.py"

The last line of Python code executed by this thread is line 195 of threading.py from the standard library. In Python 2.3 and later, the line number will point to the start of the function rather than the current line. This is a limitation of removal of SET_LINENO; it's not trivial to tell exactly what line the code is executing. This isn't usually a problem unless you've got very long functions. It would be possible to figure out what line number is executing by using f->f_lasti and examing the code's line number table, but I've never needed to do that.

Of course, it doesn't have to be that tedious. Define the following function in your .gdbinit, and you can call pyframe any time you are sitting in eval_frame().

define pyframe
x/s ((PyStringObject*)f->f_code->co_filename)->ob_sval
x/s ((PyStringObject*)f->f_code->co_name)->ob_sval
p f->f_lineno
end
#8  0x080bd0c9 in eval_frame (f=0x922fcf4) at ../Python/ceval.c:2116
2116                            x = call_function(&stack_pointer, oparg);
(gdb) pyframe
0x41a4474c:      "/home/jeremy/src/branches/Zope-2_7-branch/lib/python/ZEO/zrpc/client.py"
0x404b7c14:      "connect"
$2 = 165