| # |
| # Class for profiling python code. |
| # Author: Sjoerd Mullender |
| # |
| # See the accompanying document profile.doc for more information. |
| |
| import sys |
| import codehack |
| import posix |
| |
| 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 = posix.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:', `event` |
| return |
| |
| def handle_return(self, pframe, frame, s0): |
| t = posix.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): |
| import string |
| s = string.rjust('# calls', 8) |
| s = s + ' ' + string.rjust('tot time', 8) |
| s = s + ' ' + string.rjust('per call', 8) |
| s = s + ' ' + string.rjust('cum time', 8) |
| s = s + ' ' + string.rjust('per call', 8) |
| print s + ' filename(function)' |
| for key in self.timings.keys(): |
| nc, tt, ct, callers, callees = self.timings[key] |
| if nc == 0: |
| continue |
| s = string.rjust(`nc`, 8) |
| s = s + ' ' + string.rjust(`tt`, 8) |
| s = s + ' ' + string.rjust(`tt/nc`, 8) |
| s = s + ' ' + string.rjust(`ct`, 8) |
| s = s + ' ' + string.rjust(`ct/nc`, 8) |
| print s + ' ' + key |
| |
| def dump_stats(self, file): |
| import marshal |
| f = open(file, 'w') |
| marshal.dump(self.timings, f) |
| f.close() |
| |
| # The following two functions can be called by clients to use |
| # a debugger to debug 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): |
| ## self.reset() |
| sys.setprofile(self.trace_dispatch) |
| try: |
| ## try: |
| exec(cmd + '\n', globals, locals) |
| ## except ProfQuit: |
| ## pass |
| finally: |
| ## self.quitting = 1 |
| sys.setprofile(None) |
| # XXX What to do if the command finishes normally? |
| |
| def depth(frame): |
| d = 0 |
| while frame: |
| d = d + 1 |
| frame = frame.f_back |
| return d |
| |
| 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]) |
| |
| def cv_float(val, width): |
| import string |
| s = `val` |
| try: |
| e = string.index(s, 'e') |
| exp = s[e+1:] |
| s = s[:e] |
| width = width - len(exp) - 1 |
| except string.index_error: |
| exp = '' |
| try: |
| d = string.index(s, '.') |
| frac = s[d+1:] |
| s = s[:d] |
| width = width - len(s) - 1 |
| except string.index_error: |
| if exp <> '': |
| return s + 'e' + exp |
| else: |
| return s |
| if width < 0: |
| width = 0 |
| while width < len(frac): |
| c = frac[width] |
| frac = frac[:width] |
| if ord(c) >= ord('5'): |
| carry = 1 |
| for i in range(width-1, -1, -1): |
| if frac[i] == '9': |
| frac = frac[:i] |
| # keep if trailing zeroes are wanted |
| # + '0' + frac[i+1:width] |
| else: |
| frac = frac[:i] + chr(ord(frac[i])+1) + frac[i+1:width] |
| carry = 0 |
| break |
| if carry: |
| for i in range(len(s)-1, -1, -1): |
| if s[i] == '9': |
| s = s[:i] + '0' + s[i+1:] |
| if i == 0: |
| # gets one wider, so |
| # should shorten |
| # fraction by one |
| s = '1' + s |
| if width > 0: |
| width = width - 1 |
| else: |
| s = s[:i] + chr(ord(s[i])+1) + s[i+1:] |
| break |
| # delete trailing zeroes |
| for i in range(len(frac)-1, -1, -1): |
| if frac[i] == '0': |
| frac = frac[:i] |
| else: |
| break |
| # build up the number |
| if width > 0 and len(frac) > 0: |
| s = s + '.' + frac[:width] |
| if exp <> '': |
| s = s + 'e' + exp |
| return s |
| |
| def print_line(nc, tt, ct, callers, callees, key): |
| import string |
| s = string.rjust(cv_float(nc,8), 8) |
| s = s + ' ' + string.rjust(cv_float(tt,8), 8) |
| if nc == 0: |
| s = s + ' '*9 |
| else: |
| s = s + ' ' + string.rjust(cv_float(tt/nc,8), 8) |
| s = s + ' ' + string.rjust(cv_float(ct,8), 8) |
| if nc == 0: |
| s = s + ' '*9 |
| else: |
| s = s + ' ' + string.rjust(cv_float(ct/nc,8), 8) |
| print s + ' ' + key |
| |
| class Stats(): |
| def init(self, file): |
| import marshal |
| f = open(file, 'r') |
| self.stats = marshal.load(f) |
| f.close() |
| self.stats_list = None |
| return self |
| |
| def print_stats(self): |
| import string |
| s = string.rjust('# calls', 8) |
| s = s + ' ' + string.rjust('tot time', 8) |
| s = s + ' ' + string.rjust('per call', 8) |
| s = s + ' ' + string.rjust('cum time', 8) |
| s = s + ' ' + string.rjust('per call', 8) |
| print s + ' filename(function)' |
| 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, callers, callees, key) |
| else: |
| for key in self.stats.keys(): |
| nc, tt, ct, callers, callees = self.stats[key] |
| print_line(nc, tt, ct, callers, callees, 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 strip_dirs(self): |
| import os |
| 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 |
| |
| # test command |
| def debug(): |
| prof = Profile().init() |
| prof.debug = 1 |
| try: |
| prof.run('import x; x.main()') |
| except SystemExit: |
| pass |
| prof.print_stats() |
| |
| def test(): |
| run('import x; x.main()') |