cpython/Lib/profile.py

363 lines
9.1 KiB
Python
Executable File

#
# Class for profiling python code.
# Author: Sjoerd Mullender
# Hacked somewhat by: Guido van Rossum
#
# See the accompanying document profile.doc for more information.
import sys
import codehack
import os
import string
import fpformat
import marshal
class Profile():
def init(self):
self.timings = {}
self.debug = None
self.call_level = 0
self.profile_func = None
self.profiling = 0
return self
def profile(self, funcname):
if not self.profile_func:
self.profile_func = {}
self.profile_func[funcname] = 1
def trace_dispatch(self, frame, event, arg):
if event == 'call':
funcname = codehack.getcodename(frame.f_code)
if self.profile_func and not self.profiling:
if self.profile_func.has_key(funcname):
return
self.profiling = 1
t = os.times()
t = t[0] + t[1]
lineno = codehack.getlineno(frame.f_code)
filename = frame.f_code.co_filename
key = filename + ':' + `lineno` + '(' + funcname + ')'
self.call_level = depth(frame)
self.cur_frame = frame
pframe = frame.f_back
if self.debug:
s0 = 'call: ' + key + ' depth: ' + `self.call_level` + ' time: ' + `t`
if pframe:
pkey = pframe.f_code.co_filename + ':' + \
`codehack.getlineno(pframe.f_code)` \
+ '(' + \
codehack.getcodename(pframe.f_code) \
+ ')'
if self.debug:
s1 = 'parent: ' + pkey
if pframe.f_locals.has_key('__start_time'):
st = pframe.f_locals['__start_time']
nc, tt, ct, callers, callees = \
self.timings[pkey]
if self.debug:
s1 = s1+' before: st='+`st`+' nc='+`nc`+' tt='+`tt`+' ct='+`ct`
if callers.has_key(key):
callers[key] = callers[key] + 1
else:
callers[key] = 1
if self.debug:
s1 = s1+' after: st='+`st`+' nc='+`nc`+' tt='+`tt+(t-st)`+' ct='+`ct`
self.timings[pkey] = nc, tt + (t - st), ct, callers, callees
if self.timings.has_key(key):
nc, tt, ct, callers, callees = self.timings[key]
else:
nc, tt, ct, callers, callees = 0, 0, 0, {}, {}
if self.debug:
s0 = s0+' before: nc='+`nc`+' tt='+`tt`+' ct='+`ct`
s0 = s0+' after: nc='+`nc+1`+' tt='+`tt`+' ct='+`ct`
if pframe:
if callees.has_key(pkey):
callees[pkey] = callees[pkey] + 1
else:
callees[pkey] = 1
self.timings[key] = nc + 1, tt, ct, callers, callees
frame.f_locals['__start_time'] = t
if self.debug:
print s0
print s1
return
if event == 'return':
if self.profile_func:
if not self.profiling:
return
if self.profile_func.has_key( \
codehack.getcodename(frame.f_code)):
self.profiling = 0
self.call_level = depth(frame)
self.cur_frame = frame
pframe = frame.f_back
if self.debug:
s0 = 'return: '
else:
s0 = None
self.handle_return(pframe, frame, s0)
return
if event == 'exception':
if self.profile_func and not self.profiling:
return
call_level = depth(frame)
if call_level < self.call_level:
if call_level <> self.call_level - 1:
print 'heh!',call_level,self.call_level
if self.debug:
s0 = 'exception: '
else:
s0 = None
self.handle_return(self.cur_frame, frame, s0)
self.call_level = call_level
self.cur_frame = frame
return
print 'profile.Profile.dispatch: unknown debugging event:',
print `event`
return
def handle_return(self, pframe, frame, s0):
t = os.times()
t = t[0] + t[1]
funcname = codehack.getcodename(frame.f_code)
lineno = codehack.getlineno(frame.f_code)
filename = frame.f_code.co_filename
key = filename + ':' + `lineno` + '(' + funcname + ')'
if self.debug:
s0 = s0 + key + ' depth: ' + `self.call_level` + ' time: ' + `t`
if pframe:
funcname = codehack.getcodename(frame.f_code)
lineno = codehack.getlineno(frame.f_code)
filename = frame.f_code.co_filename
pkey = filename + ':' + `lineno` + '(' + funcname + ')'
if self.debug:
s1 = 'parent: '+pkey
if pframe.f_locals.has_key('__start_time') and \
self.timings.has_key(pkey):
st = pframe.f_locals['__start_time']
nc, tt, ct, callers, callees = \
self.timings[pkey]
if self.debug:
s1 = s1+' before: st='+`st`+' nc='+`nc`+' tt='+`tt`+' ct='+`ct`
s1 = s1+' after: st='+`t`+' nc='+`nc`+' tt='+`tt`+' ct='+`ct+(t-st)`
self.timings[pkey] = \
nc, tt, ct + (t - st), callers, callees
pframe.f_locals['__start_time'] = t
if self.timings.has_key(key):
nc, tt, ct, callers, callees = self.timings[key]
else:
nc, tt, ct, callers, callees = 0, 0, 0, {}, {}
if frame.f_locals.has_key('__start_time'):
st = frame.f_locals['__start_time']
else:
st = t
if self.debug:
s0 = s0+' before: st='+`st`+' nc='+`nc`+' tt='+`tt`+' ct='+`ct`
s0 = s0+' after: nc='+`nc`+' tt='+`tt+(t-st)`+' ct='+`ct+(t-st)`
print s0
print s1
self.timings[key] = \
nc, tt + (t - st), ct + (t - st), callers, callees
def print_stats(self):
# Print in reverse order by ct
print_title()
list = []
for key in self.timings.keys():
nc, tt, ct, callers, callees = self.timings[key]
if nc == 0:
continue
list.append(ct, tt, nc, key)
list.sort()
list.reverse()
for ct, tt, nc, key in list:
print_line(nc, tt, ct, os.path.basename(key))
def dump_stats(self, file):
f = open(file, 'w')
marshal.dump(self.timings, f)
f.close()
# The following two methods can be called by clients to use
# a profiler to profile a statement, given as a string.
def run(self, cmd):
import __main__
dict = __main__.__dict__
self.runctx(cmd, dict, dict)
def runctx(self, cmd, globals, locals):
sys.setprofile(self.trace_dispatch)
try:
exec(cmd + '\n', globals, locals)
finally:
sys.setprofile(None)
# This method is more useful to profile a single function call.
def runcall(self, func, *args):
sys.setprofile(self.trace_dispatch)
try:
apply(func, args)
finally:
sys.setprofile(None)
def depth(frame):
d = 0
while frame:
d = d + 1
frame = frame.f_back
return d
class Stats():
def init(self, file):
f = open(file, 'r')
self.stats = marshal.load(f)
f.close()
self.stats_list = None
return self
def print_stats(self):
print_title()
if self.stats_list:
for i in range(len(self.stats_list)):
nc, tt, ct, callers, callees, key = \
self.stats_list[i]
print_line(nc, tt, ct, key)
else:
for key in self.stats.keys():
nc, tt, ct, callers, callees = self.stats[key]
print_line(nc, tt, ct, key)
def print_callers(self):
if self.stats_list:
for i in range(len(self.stats_list)):
nc, tt, ct, callers, callees, key = \
self.stats_list[i]
print key,
for func in callers.keys():
print func+'('+`callers[func]`+')',
print
else:
for key in self.stats.keys():
nc, tt, ct, callers, callees = self.stats[key]
print key,
for func in callers.keys():
print func+'('+`callers[func]`+')',
print
def print_callees(self):
if self.stats_list:
for i in range(len(self.stats_list)):
nc, tt, ct, callers, callees, key = \
self.stats_list[i]
print key,
for func in callees.keys():
print func+'('+`callees[func]`+')',
print
else:
for key in self.stats.keys():
nc, tt, ct, callers, callees = self.stats[key]
print key,
for func in callees.keys():
print func+'('+`callees[func]`+')',
print
def sort_stats(self, field):
stats_list = []
for key in self.stats.keys():
t = self.stats[key]
nt = ()
for i in range(len(t)):
if i == field:
nt = (t[i],) + nt[:]
else:
nt = nt[:] + (t[i],)
if field == -1:
nt = (key,) + nt
else:
nt = nt + (key,)
stats_list.append(nt)
stats_list.sort()
self.stats_list = []
for i in range(len(stats_list)):
t = stats_list[i]
if field == -1:
nt = t[1:] + t[0:1]
else:
nt = t[1:]
nt = nt[:field] + t[0:1] + nt[field:]
self.stats_list.append(nt)
def reverse_order(self):
self.stats_list.reverse()
def strip_dirs(self):
newstats = {}
for key in self.stats.keys():
nc, tt, ct, callers, callees = self.stats[key]
newkey = os.path.basename(key)
newcallers = {}
for c in callers.keys():
newcallers[os.path.basename(c)] = callers[c]
newcallees = {}
for c in callees.keys():
newcallees[os.path.basename(c)] = callees[c]
newstats[newkey] = nc, tt, ct, newcallers, newcallees
self.stats = newstats
self.stats_list = None
def print_title():
print string.rjust('ncalls', 8),
print string.rjust('tottime', 8),
print string.rjust('percall', 8),
print string.rjust('cumtime', 8),
print string.rjust('percall', 8),
print 'filename:lineno(function)'
def print_line(nc, tt, ct, key):
print string.rjust(`nc`, 8),
print f8(tt),
if nc == 0:
print ' '*8,
else:
print f8(tt/nc),
print f8(ct),
if nc == 0:
print ' '*8,
else:
print f8(ct/nc),
print key
def f8(x):
return string.rjust(fpformat.fix(x, 3), 8)
# simplified user interface
def run(statement, *args):
prof = Profile().init()
try:
prof.run(statement)
except SystemExit:
pass
if len(args) == 0:
prof.print_stats()
else:
prof.dump_stats(args[0])
# test command with debugging
def debug():
prof = Profile().init()
prof.debug = 1
try:
prof.run('import x; x.main()')
except SystemExit:
pass
prof.print_stats()
# test command
def test():
run('import x; x.main()')