Bug 487970 - tracing library calls from python programs fails
tracing library calls from python programs fails
Status: CLOSED DUPLICATE of bug 201910
Product: Fedora
Classification: Fedora
Component: ltrace (Show other bugs)
10
All Linux
medium Severity medium
: ---
: ---
Assigned To: Petr Machata
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2009-03-01 16:42 EST by Nils Philippsen
Modified: 2015-05-04 21:34 EDT (History)
4 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2009-12-18 03:56:06 EST
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Nils Philippsen 2009-03-01 16:42:48 EST
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):
ltrace-0.5-12.45svn.fc10.x86_64

How reproducible:
Reproducible.

Steps to Reproduce:
1. Have a small python program which makes library calls, e.g. this one:

--- 8< --- foo.py ---
#!/usr/bin/python

import gtk
--- >8 --------------

2. ltrace python foo.py
  
Actual results:

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) +++
nils@gibraltar:~/test/python> 

Expected results:
E.g. a call to gtk_init() is detected.

Additional info:
Googling suggests that this works elsewhere (you don't find anything about this particular problem, but successful traces of python programs).
Comment 1 Petr Machata 2009-03-01 20:16:50 EST
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.
Comment 2 Nils Philippsen 2009-03-02 03:55:01 EST
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?
Comment 3 Petr Machata 2009-03-02 06:57:09 EST
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.
Comment 4 Nils Philippsen 2009-03-02 08:50:09 EST
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)?
Comment 5 Petr Machata 2009-03-02 09:26:22 EST
May be.

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;'
Comment 6 Frank Ch. Eigler 2009-03-16 11:39:41 EDT
# 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 \
  'process("/usr/lib64/libpython2.5.so").function("*")' \
  -c 'yum help'  # or some other python command  

... generates two lines per function call within (not just entering)
    the named shared library
Comment 7 Nils Philippsen 2009-03-28 09:42:16 EDT
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[0]
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.
Comment 8 Nils Philippsen 2009-03-28 09:43:35 EDT
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).
Comment 9 Frank Ch. Eigler 2009-03-28 14:05:01 EDT
(In reply to comment #7)
> Hi Frank, thanks for the info about systemtap. [...]
> nils@wombat:~> stap
> /usr/share/doc/systemtap-0.8/examples/general/para-callgraph.stp 
> '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
again.
Comment 10 Nils Philippsen 2009-03-31 07:10:57 EDT
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).
Comment 11 Frank Ch. Eigler 2009-03-31 07:25:09 EDT
> 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.
Comment 12 Bug Zapper 2009-11-18 04:11:35 EST
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: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping
Comment 13 Bug Zapper 2009-12-18 03:56:06 EST
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.
Comment 14 Petr Machata 2012-11-25 17:15:20 EST
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 ***

Note You need to log in before you can comment on or make changes to this bug.