Python Profiler

Recently I had to profile some python code, unfortunately the cProlfier module didn't seem to be returning valid results. For some reason it suggested a crazy amount of time was spent sleeping, and indeed it was, but not in all threads of the application. After a bit of thought I came up with the following code snippet designed to time the particular functions we were interested in.


"""
The PyProf utility profiler
a pure python profiler for simple interigation of function times

Author: Tim Kelsey, tim.callidus@gmail.com
This code is in the public domain
"""

import time as Time

global callStack
callStack = []

global callStatsDict
callStatsDict = {}

class CallStats( object ):
""" object used to record per-callable stats """
def __init__( self ):
self.callCount = 0
self.acumTime = 0.0


def pushCallStack( info ):
""" push """
stats = None
if info not in callStatsDict:
stats = CallStats()
callStatsDict[ info ] = stats
else:
stats = callStatsDict[ info ]

stats.callCount += 1
callStack.append( ( stats, Time.time() ) )


def popCallStack( ):
""" pop """
info = callStack.pop()
info[0].acumTime += Time.time() - info[1]


def addProfiledCall( ns, funcName ):
"""
this replaces a callable in a give namespace with a wrapped version that
suports profiling
"""

def _PyProfFunc( *args, **kwds ):
""" wrapper function for insertion into the namespace """
pushCallStack( ns.__name__ + "." + funcName )
ret = ns.__dict__[ newFunc ]( *args, **kwds )
popCallStack()
return ret

newFunc = "__PyProf__" + funcName
ns.__dict__[ newFunc ] = ns.__dict__[ funcName ]
ns.__dict__[ funcName ] = _PyProfFunc


def getResults():
for name, val in callStatsDict.iteritems():
yield ( name, val.callCount, val.acumTime )
return



The power of pythons mutable namespaces and dynamic functions really shines through here. Maybe someone else will find this code handy, comments welcome ;-)