How to debug python code using GDB on FreeBSD without compromising your system


GDB all the things!

September 2016.
GDB's logo Image The FreeBSD logo

Introduction


We want to be able to use GDB to debug python code efficiently.

Let's say we have the following code:

from threading import Event
import random
from time import sleep

def blocking_function_one():
while True:
sleep(1)

def blocking_function_two():
e = Event()
e.wait()

if random.random() > 0.5:
blocking_function_one()
else:
blocking_function_two()

That code will block, and since it doesn't output anything, we have no way of knowing if we went into blocking_function_one or blocking_function_two. Or do we?

For reference, I'm running a 10.2-RELEASE:

# uname -a
FreeBSD bsdlab 10.2-RELEASE FreeBSD 10.2-RELEASE #0 r286666: Wed Aug 12 15:26:37 UTC 2015 root@releng1.nyi.freebsd.org:/usr/obj/usr/src/sys/GENERIC amd64

Step 1: installing a debug version of python



We're going to work in a separate directory, in order not to alter our installation. If we need this in production, we want to be able to let the system as clean as possible when we leave.

# mkdir /usr/local/python-debug

Build python 3.4 from the port collection and set it to be installed in the directory we just created:

# cd /usr/ports/lang/python34
# make install PREFIX=/usr/local/python-debug OPTIONS_FILE_SET+=DEBUG BATCH=1


Normally we would have used NO_PKG_REGISTER=1 to install the package without registering it on the system. Unfortunately, this option is not working anymore (see bug https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=182347).

So, let's copy the files ourselves:

# cp -r work/stage/usr/local/python-debug/* /usr/local/python-debug/

Let's try to run that new python installation:

# setenv LD_LIBRARY_PATH /usr/local/python-debug/lib
# /usr/local/python-debug/bin/python3.4dm
Python 3.4.5 (default, Sep 4 2016, 00:42:59)
[GCC 4.2.1 Compatible FreeBSD Clang 3.4.1 (tags/RELEASE_34/dot1-final 208032)] on freebsd10
Type "help", "copyright", "credits" or "license" for more information.
>>>

The "d" in "dm" means "debug".

Building python also produced an important file that we need to save for later before cleaning the work tree:

# cp work/Python-3.4.5/python-gdb.py ~/

Step 2: building a python aware GDB



Build GDB from the port collection:


# ln -s python3.4 /usr/local/python-debug/bin/python
# cd /usr/ports/devel/gdb
# make PREFIX=/usr/local/python-debug \
OPTIONS_FILE_SET+=PYTHON \
PYTHON_CMD=/usr/local/python-debug/bin \
BATCH=1 \
CFLAGS+="-I/usr/local/python-debug/include -L/usr/local/python-debug/lib" \
CXXFLAGS+="-I/usr/local/python-debug/include -L/usr/local/python-debug/lib"

Also copy that installation manually to our special directory:

# cp -r work/stage/usr/local/python-debug/* /usr/local/python-debug/

Let's check that it's working and has the python extensions:

# /usr/local/python-debug/bin/gdb
GNU gdb (GDB) 7.11.1 [GDB v7.11.1 for FreeBSD]
[...]
(gdb) python
>import gdb
>end
(gdb)

Step 3: wire it all together



Now we have:

Copy the GDB script somewhere where Python can load it:

# mkdir ~/.python_lib
# mv ~/python-gdb.py ~/.python_lib/python34_gdb.py

Let's run our stupid blocking script:

# setenv PATH "/usr/local/python-debug/bin/:${PATH}"
# python where-am-i-blocking.py
[blocked]

In another shell, find the PID of the script, and attach GDB there.

# ps auxw | grep python
root 24226 0.0 0.7 48664 15492 3 I+ 3:00AM 0:00.13 python where-am-i-blocking.py (python3.4)
root 24235 0.0 0.1 18824 2004 4 S+ 3:00AM 0:00.00 grep python

# setenv PATH "/usr/local/python-debug/bin/:${PATH}"
# gdb python 24226
GNU gdb (GDB) 7.11.1 [GDB v7.11.1 for FreeBSD]
[...]
[Switching to LWP 100160 of process 24226]
0x00000008018e3f18 in _umtx_op () from /lib/libc.so.7
(gdb)

Load the GDB python script:

(gdb) python
>import sys
>sys.path.append('/root/.python_lib')
>import python34_gdb
>end

The python macros are now loaded:

(gdb) py
py-bt py-down py-locals py-up python-interactive
py-bt-full py-list py-print python

Let's see where we are:

(gdb) py-bt
Traceback (most recent call first):
<built-in method acquire of _thread.lock object at remote 0x80075c2a8>
File "/usr/local/python-debug/lib/python3.4/threading.py", line 290, in wait
waiter.acquire()
File "/usr/local/python-debug/lib/python3.4/threading.py", line 546, in wait
signaled = self._cond.wait(timeout)
File "where-am-i-blocking.py", line 11, in blocking_function_two
e.wait()
File "where-am-i-blocking.py", line 16, in <module>
blocking_function_two()

We're in blocking_function_two.

Let's check the wait's frame local variables:

(gdb) bt
#0 0x00000008018e3f18 in _umtx_op () from /lib/libc.so.7
#1 0x00000008018d3604 in sem_timedwait () from /lib/libc.so.7
#2 0x0000000800eb0421 in PyThread_acquire_lock_timed (lock=0x802417590, microseconds=-1, intr_flag=1) at Python/thread_pthread.h:352
#3 0x0000000800eba84f in acquire_timed (lock=0x802417590, microseconds=-1) at ./Modules/_threadmodule.c:71
#4 0x0000000800ebab82 in lock_PyThread_acquire_lock (self=0x80075c2a8, args=(), kwds=0x0) at ./Modules/_threadmodule.c:139
#5 0x0000000800cfa963 in PyCFunction_Call (func=<built-in method acquire of _thread.lock object at remote 0x80075c2a8>, arg=(), kw=0x0)
at Objects/methodobject.c:99
#6 0x0000000800e31716 in call_function (pp_stack=0x7fffffff5a00, oparg=0) at Python/ceval.c:4237
#7 0x0000000800e29fc0 in PyEval_EvalFrameEx (
f=Frame 0x80245d738, for file /usr/local/python-debug/lib/python3.4/threading.py, line 290, in wait (self=<Condition(_lock=<_thread.l
ock at remote 0x80075c510>, _waiters=<collections.deque at remote 0x800b0e9d8>, release=<built-in method release of _thread.lock object a
t remote 0x80075c510>, acquire=<built-in method acquire of _thread.lock object at remote 0x80075c510>) at remote 0x800a6fc88>, timeout=No
ne, waiter=<_thread.lock at remote 0x80075c2a8>, saved_state=None, gotit=False), throwflag=0) at Python/ceval.c:2838
[...]
#25 0x0000000800eb4e86 in run_file (fp=0x801c1e140, filename=0x802418090 L"where-am-i-blocking.py", p_cf=0x7fffffffe978)
at Modules/main.c:319
#26 0x0000000800eb3ab7 in Py_Main (argc=2, argv=0x802416090) at Modules/main.c:751
#27 0x0000000000400cae in main (argc=2, argv=0x7fffffffeaa8) at ./Modules/python.c:69

(gdb) frame 7
#7 0x0000000800e29fc0 in PyEval_EvalFrameEx (
f=Frame 0x80245d738, for file /usr/local/python-debug/lib/python3.4/threading.py, line 290, in wait (self=<Condition(_lock=<_thread.lock at remote 0x80075c510>, _waiters=<collections.deque at remote 0x800b0e9d8>, release=<built-in method release of _thread.lock object at remote 0x80075c510>, acquire=<built-in method acquire of _thread.lock object at remote 0x80075c510>) at remote 0x800a6fc88>, timeout=None, waiter=<_thread.lock at remote 0x80075c2a8>, saved_state=None, gotit=False), throwflag=0) at Python/ceval.c:2838
2838 res = call_function(&sp, oparg);

(gdb) py-locals
self = <Condition(_lock=<_thread.lock at remote 0x80075c510>, _waiters=<collections.deque at remote 0x800b0e9d8>, release=<built-in method release of _thread.lock object at remote 0x80075c510>, acquire=<built-in method acquire of _thread.lock object at remote 0x80075c510>) at remote 0x800a6fc88>
timeout = None
waiter = <_thread.lock at remote 0x80075c2a8>
saved_state = None
gotit = False

If you don't want to or can't attach to the running process, you can do the same thing with a core dump:

# gcore 24226
# gdb python core.24226

If you don't want to add the lib directory to the path of python everytime you use GDB, add it to your profile's GDB init script:

cat > ~/.gdbinit <<EOF
python
import sys
sys.path.append('/root/.python_lib')
end
EOF

You'll only need to import the module (python import python34_gdb) and you'll be good to go.

More ressources



Bonus problem: loading Debian's libc's debug info on a armhf



I've done the exact same thing on a Beagle Bone Black system running Debian.

Unfortunately GDB was complaining that the stack was corrupt.

# gdb /usr/local/opt/python-3.4.4/bin/python3.4dm core.18513
GNU gdb (GDB) 7.11
[...]
Reading symbols from /usr/local/opt/python-3.4.4/bin/python3.4dm...done.
[New LWP 18513]
[New LWP 18531]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/arm-linux-gnueabihf/libthread_db.so.1".
Core was generated by `python3.4dm'.
#0 0xb6f7d7e0 in recv () from /lib/arm-linux-gnueabihf/libpthread.so.0
[Current thread is 1 (Thread 0xb6fac000 (LWP 18513))]
(gdb) bt
#0 0xb6f7d7e0 in recv () from /lib/arm-linux-gnueabihf/libpthread.so.0
#1 0xb6f7d7d4 in recv () from /lib/arm-linux-gnueabihf/libpthread.so.0
#2 0xb64ae6f8 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb)

A search on the internet indicated that it was because I was missing package libc6-dbg, but that package was installed.


# apt-get install libc6-dbg
Reading package lists... Done
Building dependency tree
Reading state information... Done
libc6-dbg is already the newest version.
0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.

The problem was that using my custom installation directory had GDB look for these files in the wrong place.

(gdb) show debug-file-directory
The directory where separate debug symbols are searched for is "/usr/local/opt/python-3.4.4/lib/debug".

Setting that variable in the init file solves the problem:

cat >> ~/.gdbinit <<EOF
set debug-file-directory /usr/lib/debug
EOF


[Current thread is 1 (Thread 0xb6fac000 (LWP 18513))]
(gdb) bt
#0 0xb6f7d7e0 in recv () at ../sysdeps/unix/syscall-template.S:82
#1 0xb68fe18e in sock_recv_guts (s=0xb64ae6f8, cbuf=0x50e2e8 '\313' <repeats 199 times>, <incomplete sequence \313>..., len=65536, flags=0)
at /tmp/Python-3.4.4/Modules/socketmodule.c:2600
[...]
#38 0x00025752 in PyRun_AnyFileExFlags (fp=0x32bcc8, filename=0xb6be5310 "main.py", closeit=1, flags=0xbed1db20) at Python/pythonrun.c:1287
#39 0x0003b1ee in run_file (fp=0x32bcc8, filename=0x2c99f0 L"main.py", p_cf=0xbed1db20) at Modules/main.c:319
#40 0x0003beb8 in Py_Main (argc=2, argv=0x2c9010) at Modules/main.c:751
#41 0x000208d8 in main (argc=2, argv=0xbed1dd14) at ./Modules/python.c:69