Red Hat Bugzilla – Bug 487970
tracing library calls from python programs fails
Last modified: 2015-05-04 21:34:31 EDT
Description of problem:
When using ltrace to trace library calls made from a python program (i.e. a module used by it), only __libc_start_main and Py_Main are detected.
Version-Release number of selected component (if applicable):
Steps to Reproduce:
1. Have a small python program which makes library calls, e.g. this one:
--- 8< --- foo.py ---
--- >8 --------------
2. ltrace python foo.py
nils@gibraltar:~/test/python> ltrace python foo.py
__libc_start_main(0x400710, 2, 0x7ffff71a1488, 0x400730, 0x400720 <unfinished ...>
Py_Main(2, 0x7ffff71a1488, 0x7ffff71a14a0, 0, 0x35e516d2e0) = 0
+++ exited (status 0) +++
E.g. a call to gtk_init() is detected.
Googling suggests that this works elsewhere (you don't find anything about this particular problem, but successful traces of python programs).
The way ltrace works is that it inspects the main binary, and places breakpoints to PLT slots that it finds there. The python binary only does one PLT call: to Py_Main (which gets resolved to libpython). The rest of the execution is driven by libpython, and ltrace never sees what's happening there, since it doesn't put its breakpoints in library PLTs.
I agree that this would be a nice feature to have, but I'm afraid I will not find a time to implement it.
Now why did http://mail.python.org/pipermail/python-list/2002-December/175133.html work then? Didn't libpython exist at that point (python 2.2), i.e. all execution was driven by the main program, not a library?
Probably. I'm looking into FC-1 package of python, and it looks like libpython is there. Perhaps the poster had python statically linked to libpython, and that dynamically linked to the rest of the system (i.e. separate libpython.so would be optional). Dunno. But that's the way ltrace always worked: put breakpoints in PLTs of main binary.
Hm, is there another way for me to trace library functions called from python modules short of running python in gdb and breaking on all library functions I can think of (which isn't really what I want -- I only want to know what functions get called in which order, I don't want the program to stop there)?
Chances are that systemtap is now far enough that it can trace user space.
If not, then ftrace from "frysk" suite could do what you need. The trouble is, Red Hat's involvement with Frysk was cancelled, and the project is just sitting there unfinished and buggy since then, and the Fedora package is no good either, it's not recent. So you would have to build from git to have a decent ftrace. If you do that, this will do something:
ftrace -sym '#libgtk*#*' -- python -c 'import gtk;'
# stap -V
-- with 0.8 or 0.9 you should be in good shape
# debuginfo-install python
# stap /usr/share/doc/systemtap*/examples/general/para-callgraph.stp \
-c 'yum help' # or some other python command
... generates two lines per function call within (not just entering)
the named shared library
Hi Frank, thanks for the info about systemtap. After installing the debuginfo packages, I ran "make" in /usr/share/systemtap/runtime/uprobes and added my user to the stapusr/stapdev groups. I got this:
nils@wombat:~> stap /usr/share/doc/systemtap-0.8/examples/general/para-callgraph.stp 'process("/usr/lib64/libsane.so").function("sane_*")' -c src/batch-scan/batch-scan.py
No devices found.
Traceback (most recent call last):
File "src/batch-scan/batch-scan.py", line 67, in <module>
devname = devnames
IndexError: list index out of range
0 batch-scan.py(4877):->sane_init vc=? cb=?
39 batch-scan.py(4877): ->sane_dll_init version_code=? authorize=?
43 batch-scan.py(4877): ->sane_dll_init version_code=? authorize=?
326 batch-scan.py(4877): <-sane_dll_init return=0x0
330 batch-scan.py(4877): <-sane_init return=0x0
348 batch-scan.py(4877): ->sane_get_devices dl=? local=?
376 batch-scan.py(4877): ->sane_dll_get_devices device_list=? local_only=?
71241 batch-scan.py(4877): <-sane_dll_get_devices return=0x0
71249 batch-scan.py(4877): <-sane_get_devices return=0x0
One question though: is there a way so that I can see what the arguments where in each function call? I guess that "?" means systemtap had problems finding that out.
NB: Petr, I also tried to use frysk as you described in comment #5, but unfortunately the version in git didn't build (at the time I attempted it).
(In reply to comment #7)
> Hi Frank, thanks for the info about systemtap. [...]
> nils@wombat:~> stap
> 'process("/usr/lib64/libsane.so").function("sane_*")' -c
Actually, systemtap 0.9 or later includes some fixes for data access
in shared libraries, so it may be worth your time upgrading and trying
Version 0.9.5 has just come in via F-10 updates, this looks better. Am I correct assuming that the callgraph is printed after the whole program has completed? I'd like to find out which calls correspond to which of my "high level" actions (e.g. python code, compared with pressing the "Scan" button in xsane).
> Am I correct assuming that the callgraph is printed after
> the whole program has completed?
No, the graph is printed "live", so with the simple para-callgraph.stp
script invocation, you can get a tremendous amount of data. Once you
know more specifically what you want to see, it may be possible to
tweak that so that the runtime impact and the trace quantity are less.
This message is a reminder that Fedora 10 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 10. 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 '10'.
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 10'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 10 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:
Fedora 10 changed to end-of-life (EOL) status on 2009-12-17. Fedora 10 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.
Thank you for reporting this bug and we are sorry it could not be fixed.
Note that this functionality is part of ltrace 0.7.0, which has been packaged for current Rawhide.
*** This bug has been marked as a duplicate of bug 201910 ***