Tuesday, April 27, 2010

Tracing python programs

Coming with the easier python debugging enabled by the new gdb with python hooks is another awesome python feature coming in the new Fedora "Goddard" 13 release. That is tracing of python processes and their function calls. This feature is developed on top of systemtap, the linux analogue of Sun's awesome Dtrace system tracer.
So what does it mean? For the uninitiated, it implements hooks (tracepoints) in the python main shared libraries (libpython.so and libpython3.so) so that systemtap can trace whenever a python function is entered/exited in any python process on the system. This means you can anytime check a python process to see which functions are being called and how many times etc. This has really cool uses. More information about this feature is available at https://fedoraproject.org/wiki/Features/SystemtapStaticProbes#Python_2

Just to illustrate the use try the following examples (from the above link)
First install python-debuginfo. Now add yourself to stapdev and stapusr groups or run the following command as root:
    $ stap /usr/share/doc/python3-libs-3.1.2/pyfuntop.stp
This will display a top like output on the terminal showing the python functions which are called by all running processes and the number of times its being called. Its fun to watch, just run a python program and check all the functions being called :)
Here's a sample output from my laptop

PID                                                                         FILENAME   LINE                       FUNCTION  CALLS
 15479                                 /usr/lib/python2.6/site-packages/yum/packages.py    261                         verCMP  15768
 15479                                 /usr/lib/python2.6/site-packages/yum/packages.py    270                        __cmp__  15767
 15479                             /usr/lib/python2.6/site-packages/rpmUtils/updates.py    129                   returnNewest   9045
 15479                           /usr/lib/python2.6/site-packages/rpmUtils/miscutils.py     36                     compareEVR   1191
 15479                                 /usr/lib/python2.6/site-packages/yum/packages.py     48                   comparePoEVR    578
 15479                                 /usr/lib/python2.6/site-packages/yum/packages.py    296                          verEQ    556
 15479                                 /usr/lib/python2.6/site-packages/yum/packages.py     55                 comparePoEVREQ    556
 15479                                 /usr/lib/python2.6/site-packages/yum/__init__.py    778                             2
 15479                                 /usr/lib/python2.6/site-packages/yum/__init__.py    206                     _getConfig      2
 15479                                   /usr/lib/python2.6/site-packages/yum/config.py     69                        __get__      2
 15479                                         /usr/lib64/python2.6/logging/__init__.py   1026                          debug      1
 15479                                         /usr/lib64/python2.6/logging/__init__.py   1236                   isEnabledFor      1
 15479                                         /usr/lib64/python2.6/logging/__init__.py   1222              getEffectiveLevel      1
 15479                             /usr/lib/python2.6/site-packages/rpmUtils/updates.py    272                      doUpdates      1
This shows the functions called during a 1 second interval (the script updates the display every second) by checking of available updates by packagekit.
Another system script displays the python function call hierarchy of any program you run. Try this by running
    $ stap -v /usr/share/doc/python-libs-2.6.4/systemtap-example.stp -c python
Now you will get a python terminal after a long hierarchy of function calls. Here you can see all python functions called for each line you enter on the python terminal. Its not as much fun, but useful if you want to check where all those extra unneeded function calls are being made.
Read a short writeup from the developer of these features at http://fedoraproject.org/wiki/Python_in_Fedora_13 and also check http://press.redhat.com/2010/04/27/fedora-13-spotlight-feature-exploring-new-frontiers-of-python-development/

No comments:

Post a Comment