96

In debugging a Python script, I'd really like to know the entire call stack for my entire program. An ideal situation would be if there were a command-line flag for python that would cause Python to print all function names as they are called (I checked man Python2.7, but didn't find anything of this sort).

Because of the number of functions in this script, I'd prefer not to add a print statement to the beginning of each function and/or class, if possible.

An intermediate solution would be to use PyDev's debugger, place a couple breakpoints and check the call stack for given points in my program, so I'll use this approach for the time being.

I'd still prefer to see a complete list of all functions called throughout the life of the program, if such a method exists.

martineau
  • 119,623
  • 25
  • 170
  • 301
James
  • 1,485
  • 2
  • 16
  • 21
  • 4
    profilers tell you all the functions called e.g. http://docs.python.org/library/profile.html but not exactly what you asked for - is this sufficient? – mmmmmm Nov 29 '11 at 18:07

9 Answers9

136

You can do this with a trace function (props to Spacedman for improving the original version of this to trace returns and use some nice indenting):

def tracefunc(frame, event, arg, indent=[0]):
      if event == "call":
          indent[0] += 2
          print("-" * indent[0] + "> call function", frame.f_code.co_name)
      elif event == "return":
          print("<" + "-" * indent[0], "exit function", frame.f_code.co_name)
          indent[0] -= 2
      return tracefunc

import sys
sys.setprofile(tracefunc)

main()   # or whatever kicks off your script

Note that a function's code object usually has the same name as the associated function, but not always, since functions can be created dynamically. Unfortunately, Python doesn't track the function objects on the stack (I've sometimes fantasized about submitting a patch for this). Still, this is certainly "good enough" in most cases.

If this becomes an issue, you could extract the "real" function name from the source code—Python does track the filename and line number—or ask the garbage collector find out which function object refers to the code object. There could be more than one function sharing the code object, but any of their names might be good enough.

Coming back to revisit this four years later, it behooves me to mention that in Python 2.6 and later, you can get better performance by using sys.setprofile() rather than sys.settrace(). The same trace function can be used; it's just that the profile function is called only when a function is entered or exited, so what's inside the function executes at full speed.

mdaoust
  • 6,242
  • 3
  • 28
  • 29
kindall
  • 178,883
  • 35
  • 278
  • 309
  • sure, the more the merrier :-) – kindall Nov 29 '11 at 18:18
  • You can also use a global variable to track the nesting level and indent the trace nicely. – Spacedman Nov 29 '11 at 18:21
  • 1
    cheers - hate the globals. Couldn't think of another way to do it quickly. Nice technique. – Spacedman Nov 29 '11 at 18:33
  • 8
    This is awesome. I ended up adding `os.path.basename(frame.f_code.co_filename)` to this trace function to print the file containing the function called. – James Nov 30 '11 at 18:01
  • 1
    How to get the function name if event is `'c_call'`? `frame.f_code.co_name` does not work here. – kawing-chiu Feb 12 '17 at 13:41
  • 1
    Is there any quick way to make this less verbose, printing only calls to functions that I defined in my code and not all of Python's internal ones? At least in Python 3.4 (didn't try with 2.7), the log is full of calls to `notify`, `__getattr__` etc... – Dirk Mar 17 '17 at 15:43
  • 2
    You could check `frame.f_code.co_filename`. This should be the full path to the file that contains the function. Check to see whether the path contains `Python` followed by `lib`, perhaps, and if so, don't print anything... – kindall Oct 17 '17 at 21:53
  • 2
    @Dirk: Seems like you could simply use `frame.f_code.co_filename` to check whether the function is in one (or more) of your source files and ignore it otherwise—as opposed to checking whether it's a Python internal. – martineau Oct 21 '18 at 18:03
  • Is there a way to see the class when we get a method ? Maybe from the first argument of the function ? – kriss Dec 31 '19 at 13:33
  • @kriss You could try something like `if "self" in frame.f_locals: print(type(self).__qualname__)` – kindall Jan 01 '20 at 06:23
  • er, that should be `if "self" in frame.f_locals: print(type(frame.f_locals["self"]).__qualname__)` – kindall Jan 01 '20 at 07:04
  • I found a way before getting your comment. I used: 'frame.f_locals.get('self').__class__.__name__' (with the proper checks) – kriss Jan 01 '20 at 10:38
  • Do you know if a similar task is possible: to print the return value whenever a function is called. E.g. if I have a function `Prime(x)` and I call `Prime(3)`, in the shell I should see an output `true` even if I didn't explicitly ask to print the output – mercury0114 Oct 28 '20 at 12:46
  • @kawing-chiu for c_call, use `arg.__name__`. I don't think there's any way to get the arguments, though. – Edward Falk Jan 30 '23 at 23:42
  • You could do that using a decorator, but not as part of a trace function. – kindall Jan 31 '23 at 18:52
25

Another good tool to be aware of is the trace module. There are 3 options of showing function names.

Example foo.py:

def foo():
   bar()

def bar():
   print("in bar!")

foo()
  1. Using -l/--listfuncs to list funtions:
$ python -m trace --listfuncs foo.py
in bar!

functions called:
filename: /System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/trace.py, modulename: trace, funcname: _unsettrace
filename: foo.py, modulename: foo, funcname: <module>
filename: foo.py, modulename: foo, funcname: bar
filename: foo.py, modulename: foo, funcname: foo
  1. Using -t/--trace to list lines as they are executed.
$python -m trace --trace foo.py
 --- modulename: foo, funcname: <module>
foo.py(1): def foo():
foo.py(4): def bar():
foo.py(7): foo()
 --- modulename: foo, funcname: foo
foo.py(2):    bar()
 --- modulename: foo, funcname: bar
foo.py(5):    print("in bar!")
in bar!
  1. Using -T/--trackcalls to list what calls what
$ python -m trace --trackcalls foo.py
in bar!

calling relationships:

*** /usr/lib/python3.8/trace.py ***
  --> foo.py
    trace.Trace.runctx -> foo.<module>

*** foo.py ***
    foo.<module> -> foo.foo
    foo.foo -> foo.bar
vlz
  • 911
  • 1
  • 10
  • 18
David Wolever
  • 148,955
  • 89
  • 346
  • 502
15

I took kindall's answer and built on it. I made the following module:

"""traceit.py

Traces the call stack.

Usage:

import sys
import traceit

sys.setprofile(traceit.traceit)
"""

import sys


WHITE_LIST = {'trade'}      # Look for these words in the file path.
EXCLUSIONS = {'<'}          # Ignore <listcomp>, etc. in the function name.


def tracefunc(frame, event, arg):

    if event == "call":
        tracefunc.stack_level += 1

        unique_id = frame.f_code.co_filename+str(frame.f_lineno)
        if unique_id in tracefunc.memorized:
            return

        # Part of filename MUST be in white list.
        if any(x in frame.f_code.co_filename for x in WHITE_LIST) \
            and \
          not any(x in frame.f_code.co_name for x in EXCLUSIONS):

            if 'self' in frame.f_locals:
                class_name = frame.f_locals['self'].__class__.__name__
                func_name = class_name + '.' + frame.f_code.co_name
            else:
                func_name = frame.f_code.co_name

            func_name = '{name:->{indent}s}()'.format(
                    indent=tracefunc.stack_level*2, name=func_name)
            txt = '{: <40} # {}, {}'.format(
                    func_name, frame.f_code.co_filename, frame.f_lineno)
            print(txt)

            tracefunc.memorized.add(unique_id)

    elif event == "return":
        tracefunc.stack_level -= 1


tracefunc.memorized = set()
tracefunc.stack_level = 0

Sample usage

import traceit

sys.setprofile(traceit.tracefunc)

Sample output:

API.getFills()                           # C:\Python37-32\lib\site-packages\helpers\trade\tws3.py, 331
API._get_req_id()                        # C:\Python37-32\lib\site-packages\helpers\trade\tws3.py, 1053
API._wait_till_done()                    # C:\Python37-32\lib\site-packages\helpers\trade\tws3.py, 1026
---API.execDetails()                     # C:\Python37-32\lib\site-packages\helpers\trade\tws3.py, 1187
-------Fill.__init__()                   # C:\Python37-32\lib\site-packages\helpers\trade\mdb.py, 256
--------Price.__init__()                 # C:\Python37-32\lib\site-packages\helpers\trade\mdb.py, 237
-deserialize_order_ref()                 # C:\Python37-32\lib\site-packages\helpers\trade\mdb.py, 644
--------------------Port()               # C:\Python37-32\lib\site-packages\helpers\trade\mdb.py, 647
API.commissionReport()                   # C:\Python37-32\lib\site-packages\helpers\trade\tws3.py, 1118

Features:

  • Ignores Python language internal functions.
  • Ignores repeated function calls (optional).
  • Uses sys.setprofile() instead of sys.settrace() for speed.
ChaimG
  • 7,024
  • 4
  • 38
  • 46
9

There are a few options. If a debugger isn't enough, you can set a trace function using sys.settrace(). This function will be essentially called on every line of Python code executed, but it easy to identify the function calls -- see the linked documentation.

You might also be interested in the trace module, though it doesn't do exactly what you asked for. Be sure to look into the --trackcalls option.

Lesmana
  • 25,663
  • 9
  • 82
  • 87
Sven Marnach
  • 574,206
  • 118
  • 941
  • 841
  • Yeah, `sys.settrace()`, in conjunction with @kindall's suggested trace function above worked like a charm. :) The `trace` module looks really useful, too ... I'll keep it in mind for future debugging projects. – James Nov 30 '11 at 18:09
7
import traceback
def foo():
    traceback.print_stack()
def bar():
    foo()
def car():
    bar():

car()
File "<string>", line 1, in <module>
File "C:\Python27\lib\idlelib\run.py", line 97, in main
  ret = method(*args, **kwargs)
File "C:\Python27\lib\idlelib\run.py", line 298, in runcode
    exec code in self.locals
File "<pyshell#494>", line 1, in <module>
File "<pyshell#493>", line 2, in car
File "<pyshell#490>", line 2, in bar
File "<pyshell#486>", line 2, in foo

traceback

Abhijit
  • 62,056
  • 18
  • 131
  • 204
  • 1
    This is just a less convenient and less flexible way of doing what the OP already did using a debugger and breakpoints. – Sven Marnach Nov 29 '11 at 18:12
6

The hunter tool does exactly this, and more. For example, given:

test.py:

def foo(x):
    print(f'foo({x})')

def bar(x):
    foo(x)

bar()

The output looks like:

$ PYTHONHUNTER='module="__main__"' python test.py
                                 test.py:1     call      => <module>()
                                 test.py:1     line         def foo(x):
                                 test.py:4     line         def bar(x):
                                 test.py:7     line         bar('abc')
                                 test.py:4     call         => bar(x='abc')
                                 test.py:5     line            foo(x)
                                 test.py:1     call            => foo(x='abc')
                                 test.py:2     line               print(f'foo({x})')
foo(abc)
                                 test.py:2     return          <= foo: None
                                 test.py:5     return       <= bar: None
                                 test.py:7     return    <= <module>: None

It also provides a pretty flexible query syntax that allows specifying module, file/lineno, function, etc which helps because the default output (which includes standard library function calls) can be pretty big.

Chris Hunt
  • 3,840
  • 3
  • 30
  • 46
2

You could use settrace, as outlined here: Tracing python code. Use the version near the end of the page. I stick the code of that page into my code to see exactly what lines are executed when my code is running. You can also filter so that you only see the names of functions called.

jeorgen
  • 656
  • 5
  • 14
1

You can also use a decorator for specific functions you want to trace (with their arguments):

import sys
from functools import wraps

class TraceCalls(object):
    """ Use as a decorator on functions that should be traced. Several
        functions can be decorated - they will all be indented according
        to their call depth.
    """
    def __init__(self, stream=sys.stdout, indent_step=2, show_ret=False):
        self.stream = stream
        self.indent_step = indent_step
        self.show_ret = show_ret

        # This is a class attribute since we want to share the indentation
        # level between different traced functions, in case they call
        # each other.
        TraceCalls.cur_indent = 0

    def __call__(self, fn):
        @wraps(fn)
        def wrapper(*args, **kwargs):
            indent = ' ' * TraceCalls.cur_indent
            argstr = ', '.join(
                [repr(a) for a in args] +
                ["%s=%s" % (a, repr(b)) for a, b in kwargs.items()])
            self.stream.write('%s%s(%s)\n' % (indent, fn.__name__, argstr))

            TraceCalls.cur_indent += self.indent_step
            ret = fn(*args, **kwargs)
            TraceCalls.cur_indent -= self.indent_step

            if self.show_ret:
                self.stream.write('%s--> %s\n' % (indent, ret))
            return ret
        return wrapper

Just import this file and add a @TraceCalls() before the function/method you want to trace.

Vincent Fenet
  • 383
  • 2
  • 6
  • I like your answer, but think it could be improved by using the [Creating decorator with optional arguments](https://wiki.python.org/moin/PythonDecoratorLibrary#Creating_decorator_with_optional_arguments) recipe which would make using it more "traditional": i.e. `@TraceCalls` instead of `@TraceCalls()`. Also—for the same reason—I suggest making the class name all lowercase (even though technically that wouldn't be following the PEP 8 guidelines) to allow it be used as `@tracecalls`. – martineau Feb 21 '19 at 20:40
1

Variation on kindall's answer, return just the called functions in a package.

def tracefunc(frame, event, arg, indent=[0]):
    package_name = __name__.split('.')[0]

    if event == "call" and (package_name in str(frame)):
        indent[0] += 2
        print("-" * indent[0] + "> call function", frame.f_code.co_name)
    return tracefunc

import sys
sys.settrace(tracefunc)

e.g. In a package called Dog, this should only show you functions called that were defined in the Dog package.

martineau
  • 119,623
  • 25
  • 170
  • 301
ObjectNameDisplay
  • 411
  • 8
  • 21