How do I print functions as they are called?

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.

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()

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

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!

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

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.

How do I print functions as they are called?

Related

Recent Posts