Python Observing `str` calls by through sys.setprofile and frame inspection

Question

I am brand new to python frame introspection and I am trying to set a profiler or a tracer in order to keep track of str function calls. I have setup tracers in various ways but think I am missing some key understandings around frame introspection and how to get builtin function names (ie str)

def test_trace():
    sys.setprofile(trace_calls)
    hi = str('hellllo')
    stuff = []
    for i in range(10):
        stuff.append(str(random.randrange(0, 10000000000)))
    print(hi)
    os._exit(0)

def trace_calls(frame, event, arg):
    '''
    if event not in ('call', 'c_call'):
        return
    '''
    stack = collections.deque()
    stack.appendleft(_expand_arg(arg) + _expand_frame(frame))

    while frame.f_back is not None:
        stack.appendleft(_expand_arg(arg) + _expand_frame(frame))
        frame = frame.f_back

    print('-' * 100)
    for frame in stack:
        print(frame)

def _expand_arg(arg):
    if arg is None:
        return ()

    return (
        # arg.__name__,
    )

def _expand_frame(frame):
    code = frame.f_code
    c_class = ''
    c_module = ''
    if 'self' in frame.f_locals:
        c_class = frame.f_locals['self'].__class__.__name__
        c_module = frame.f_locals['self'].__class__.__module__

    return (
        code.co_filename,
        frame.f_lineno,
        frame.f_trace,
        code.co_name,
        code.co_firstlineno,
        c_class,
        c_module,
    )

When I run test_trace() I see no mention of any str calls in any of the profiled events. I would expect to see some mention of str or <string> in some of the call stacks but only see the random calls:

$ ipython
Python 3.5.2 (default, Nov 23 2017, 16:37:01)
Type 'copyright', 'credits' or 'license' for more information
IPython 6.4.0 -- An enhanced Interactive Python. Type '?' for help.

('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/__init__.py', 125, None, 'start_ipython', 99, '', '')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/traitlets/config/application.py', 658, None, 'launch_instance', 650, '', '')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/terminal/ipapp.py', 356, None, 'start', 350, 'TerminalIPythonApp', 'IPython.terminal.ipapp')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/terminal/interactiveshell.py', 485, None, 'mainloop', 478, 'TerminalInteractiveShell', 'IPython.terminal.in
teractiveshell')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/terminal/interactiveshell.py', 476, None, 'interact', 458, 'TerminalInteractiveShell', 'IPython.terminal.in
teractiveshell')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/core/interactiveshell.py', 2662, None, 'run_cell', 2636, 'TerminalInteractiveShell', 'IPython.terminal.inte
ractiveshell')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/core/interactiveshell.py', 2785, None, '_run_cell', 2669, 'TerminalInteractiveShell', 'IPython.terminal.int
eractiveshell')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/core/interactiveshell.py', 2909, None, 'run_ast_nodes', 2835, 'TerminalInteractiveShell', 'IPython.terminal
.interactiveshell')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/core/interactiveshell.py', 2963, None, 'run_code', 2933, 'TerminalInteractiveShell', 'IPython.terminal.inte
ractiveshell')
('<ipython-input-2-a29a88804d82>', 1, None, '<module>', 1, '', '')
('/vagrant_data/github.com/dm03514/python-apm/pythonapm/instruments/monkey.py', 35, None, 'test_trace', 30, '', '')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/random.py', 194, None, 'randrange', 170, 'Random', 'random')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/random.py', 232, None, '_randbelow', 220, 'Random', 'random')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/random.py', 232, None, '_randbelow', 220, 'Random', 'random')

('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/__init__.py', 125, None, 'start_ipython', 99, '', '')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/traitlets/config/application.py', 658, None, 'launch_instance', 650, '', '')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/terminal/ipapp.py', 356, None, 'start', 350, 'TerminalIPythonApp', 'IPython.terminal.ipapp')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/terminal/interactiveshell.py', 485, None, 'mainloop', 478, 'TerminalInteractiveShell', 'IPython.terminal.in
teractiveshell')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/terminal/interactiveshell.py', 476, None, 'interact', 458, 'TerminalInteractiveShell', 'IPython.terminal.in
teractiveshell')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/core/interactiveshell.py', 2662, None, 'run_cell', 2636, 'TerminalInteractiveShell', 'IPython.terminal.inte
ractiveshell')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/core/interactiveshell.py', 2785, None, '_run_cell', 2669, 'TerminalInteractiveShell', 'IPython.terminal.int
eractiveshell')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/core/interactiveshell.py', 2909, None, 'run_ast_nodes', 2835, 'TerminalInteractiveShell', 'IPython.terminal
.interactiveshell')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/site-packages/IPython/core/interactiveshell.py', 2963, None, 'run_code', 2933, 'TerminalInteractiveShell', 'IPython.terminal.inte
ractiveshell')
('<ipython-input-2-a29a88804d82>', 1, None, '<module>', 1, '', '')
('/vagrant_data/github.com/dm03514/python-apm/pythonapm/instruments/monkey.py', 35, None, 'test_trace', 30, '', '')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/random.py', 194, None, 'randrange', 170, 'Random', 'random')
('/home/ubuntu/.virtualenvs/papm/lib/python3.5/random.py', 194, None, 'randrange', 170, 'Random', 'random')

---

I've seen string calls in the python builtin profiles so I tried to look at how they get the c function names, in case that str was delegating to a c call.

I tried to get the c function calls by inspecting arg (both with setprofile and settrace but it didn't show any string calls either

    if event == "c_call":
        self.c_func_name = arg.__name__

Is anyone familiar with how to trace the python str or built in calls.

Answer 1

When I run test_trace() I see no mention of any str calls in any of the profiled events.

That's because str() is a type object defined entirely in C. Only function calls are traced, not type calls, so no c_call event is issued.

You could work around this by replacing the str built-in; you can alter Python's builtins via the builtins module:

import builtins

orig_str = builtins.str
def traceable_str(*args):
    return orig_str(*args)
builtins.str = traceable_str

You can now see traceable_str calls be passed to the profiling function.

However, note that only calls from Python code to str() will be traced! Anything implemented in C, like the print() function, doesn't even call the str() builtin, it just uses the C API to achieve the same results.