# # 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()')