Trace in Python

Python allows you to trace in detail the execution of a script. The function is provided by sys.settrace ans sys.setprofile

Time Function Calls
Use the profile or cProfile module

python -m profile myscript.py python -m cProfile myscript.py

Count Function Calls
Use the trace module.

python -m trace --ignore-dir /opt -s --count --missing myscript.py

Write your own trace function
"""Development module to quickly trace a program""" import sys import time _trace=[] _processed = False _running = False def traceit(frame, event, arg): if event == "call": _trace.append( (True, frame.f_code, time.time) ) elif event == "return": _trace.append( (False, frame.f_code, time.time) ) # print "f_code         ", frame.f_code # print "f_locals       ", frame.f_locals # print "f_lineno       ", frame.f_lineno return traceit class Codecall: code         = None count        = 0 exclusivetime = 0.0 childtime    = 0.0 totaltime    = 0.0 def __init__(self, code): self.code = code self.count = 1 def incCallCount(self, inc=1): self.count += inc def incExclusiveTime(self, inc=1): self.exclusivetime += inc def incTotalTime(self, inc=1): self.totaltime += inc def name(self): return self.code.co_name def filename(self): return self.code.co_filename def firstlineno(self): return self.code.co_firstlineno class MyCode: co_name       = "__main__" co_filename   = "a file" co_firstlineno = 1 def processtrace: stop # _codecalls is a dictionary id(code object) => # tuple(code object, call count, time spent (excl child functions), time spent (incl child functions)) if len(_trace) == 0: raise Exception("No trace to process") codecalls = {} # list of tuples (id(code object), timestamp) stack = [] prevtime = None counter = 0 tracelen = len(_trace) for (state, code, time) in _trace: counter += 1 # print "process %s %s %f with stack %s" % (state, code.co_name, time, stack) print "%5d/%5d %6s %-20s %8f %s" % (counter, tracelen, state, code.co_name+'', time, stack) if len(stack) > 0: (prevcodeid, starttime) = stack[-1] codecalls[prevcodeid].incExclusiveTime(time-prevtime) prevtime = time codeid = id(code) if state: # call object; add to stack if not codeid in codecalls: codecalls[codeid] = Codecall(code) else: codecalls[codeid].incCallCount stack.append( (codeid,time) ) else: # return; remove from stack if len(stack) == 0 raise Exception("Stack is empty while processing return trace %d/%d of %s at t=%f" % (counter,tracelen,code.co_name,time)) stack.pop codecalls[prevcodeid].incTotalTime(time-starttime) for codecall in codecalls.values: codecall.childtime = codecall.totaltime - codecall.exclusive.time def summary(maxcalls=100): if not _processed: processtrace calllen = len(codecalls) counter = 0 print "Total: %d different functions called" % calllen print "%-20s %-30s %5s %5s %14s + %14s = %14s" % ("function name", "filename", "line", "calls", "time spent", "time in childs", "total time spent") for codecall in codecalls.values: counter += 1 print "%-20s %-30s %5d %5d %11f ms + %11f ms = %11f ms" % (codecall.name+'', codecall.filename, codecall.firstlineno, codecall.count, 1000*codecall.exclusivetime, 1000*codecall.childtime, 1000*codecall.totaltime) if counter > maxcalls: break def start: sys.settrace(traceit) if not _running: mycode = MyCode _trace.append( (True, mycode, time.time) ) _running = True def stop: if _running: _trace.append( (False, mycode, time.time) ) sys.settrace(None) _running = False
 * 1) !/usr/bin/env python
 * 2) -*- coding: utf-8 -*-
 * 1) _trace is a list of tuplets
 * 2) (True/False = call/return, code object, timestamp)