Lib/profile.py

   1 #
   2 # Class for profiling python code.
   3 # Author: Sjoerd Mullender
   4 # Hacked somewhat by: Guido van Rossum
   5 #
   6 # See the accompanying document profile.doc for more information.
   7
   8 import sys
   9 import codehack
  10 import os
  11 import string
  12 import fpformat
  13 import marshal
  14
  15 class Profile:
  16
  17         def __init__(self):
  18                 self.timings = {}
  19                 self.debug = None
  20                 self.call_level = 0
  21                 self.profile_func = None
  22                 self.profiling = 0
  23
  24         def profile(self, funcname):
  25                 if not self.profile_func:
  26                         self.profile_func = {}
  27                 self.profile_func[funcname] = 1
  28
  29         def trace_dispatch(self, frame, event, arg):
  30                 if event == 'call':
  31                         funcname = codehack.getcodename(frame.f_code)
  32                         if self.profile_func and not self.profiling:
  33                                 if self.profile_func.has_key(funcname):
  34                                         return
  35                                 self.profiling = 1
  36                         t = os.times()
  37                         t = t[0] + t[1]
  38                         if frame.f_locals.has_key('__key'):
  39                                 key = frame.f_locals['__key']
  40                         else:
  41                                 lineno = codehack.getlineno(frame.f_code)
  42                                 filename = frame.f_code.co_filename
  43                                 key = filename + ':' + `lineno` + '(' + funcname + ')'
  44                                 frame.f_locals['__key'] = key
  45                         self.call_level = depth(frame)
  46                         self.cur_frame = frame
  47                         pframe = frame.f_back
  48                         if self.debug:
  49                                 s0 = 'call: ' + key + ' depth: ' + `self.call_level` + ' time: ' + `t`
  50                         if pframe:
  51                                 if pframe.f_locals.has_key('__key'):
  52                                         pkey = pframe.f_locals['__key']
  53                                 else:
  54                                         pkey = pframe.f_code.co_filename + \
  55                                                   ':' + \
  56                                                   `codehack.getlineno(pframe.f_code)` \
  57                                                   + '(' + \
  58                                                   codehack.getcodename(pframe.f_code) \
  59                                                   + ')'
  60                                         pframe.f_locals['__key'] = pkey
  61                                 if self.debug:
  62                                         s1 = 'parent: ' + pkey
  63                                 if pframe.f_locals.has_key('__start_time'):
  64                                         st = pframe.f_locals['__start_time']
  65                                         nc, tt, ct, callers, callees = \
  66                                                 self.timings[pkey]
  67                                         if self.debug:
  68                                                 s1 = s1+' before: st='+`st`+' nc='+`nc`+' tt='+`tt`+' ct='+`ct`
  69                                         if callers.has_key(key):
  70                                                 callers[key] = callers[key] + 1
  71                                         else:
  72                                                 callers[key] = 1
  73                                         if self.debug:
  74                                                 s1 = s1+' after: st='+`st`+' nc='+`nc`+' tt='+`tt+(t-st)`+' ct='+`ct`
  75                                         self.timings[pkey] = nc, tt + (t - st), ct, callers, callees
  76                         if self.timings.has_key(key):
  77                                 nc, tt, ct, callers, callees = self.timings[key]
  78                         else:
  79                                 nc, tt, ct, callers, callees = 0, 0, 0, {}, {}
  80                         if self.debug:
  81                                 s0 = s0+' before: nc='+`nc`+' tt='+`tt`+' ct='+`ct`
  82                                 s0 = s0+' after: nc='+`nc+1`+' tt='+`tt`+' ct='+`ct`
  83                         if pframe:
  84                                 if callees.has_key(pkey):
  85                                         callees[pkey] = callees[pkey] + 1
  86                                 else:
  87                                         callees[pkey] = 1
  88                         self.timings[key] = nc + 1, tt, ct, callers, callees
  89                         frame.f_locals['__start_time'] = t
  90                         if self.debug:
  91                                 print s0
  92                                 print s1
  93                         return
  94                 if event == 'return':
  95                         if self.profile_func:
  96                                 if not self.profiling:
  97                                         return
  98                                 if self.profile_func.has_key( \
  99                                         codehack.getcodename(frame.f_code)):
 100                                         self.profiling = 0
 101                         self.call_level = depth(frame)
 102                         self.cur_frame = frame
 103                         pframe = frame.f_back
 104                         if self.debug:
 105                                 s0 = 'return: '
 106                         else:
 107                                 s0 = None
 108                         self.handle_return(pframe, frame, s0)
 109                         return
 110                 if event == 'exception':
 111                         if self.profile_func and not self.profiling:
 112                                 return
 113                         call_level = depth(frame)
 114                         if call_level < self.call_level:
 115                                 if call_level <> self.call_level - 1:
 116                                         print 'heh!',call_level,self.call_level
 117                                 if self.debug:
 118                                         s0 = 'exception: '
 119                                 else:
 120                                         s0 = None
 121                                 self.handle_return(self.cur_frame, frame, s0)
 122                         self.call_level = call_level
 123                         self.cur_frame = frame
 124                         return
 125                 print 'profile.Profile.dispatch: unknown debugging event:',
 126                 print `event`
 127                 return
 128
 129         def handle_return(self, pframe, frame, s0):
 130                 t = os.times()
 131                 t = t[0] + t[1]
 132                 if frame.f_locals.has_key('__key'):
 133                         key = frame.f_locals['__key']
 134                 else:
 135                         funcname = codehack.getcodename(frame.f_code)
 136                         lineno = codehack.getlineno(frame.f_code)
 137                         filename = frame.f_code.co_filename
 138                         key = filename + ':' + `lineno` + '(' + funcname + ')'
 139                         frame.f_locals['__key'] = key
 140                 if self.debug:
 141                         s0 = s0 + key + ' depth: ' + `self.call_level` + ' time: ' + `t`
 142                 if pframe:
 143                         if pframe.f_locals.has_key('__key'):
 144                                 pkey = pframe.f_locals['__key']
 145                         else:
 146                                 funcname = codehack.getcodename(frame.f_code)
 147                                 lineno = codehack.getlineno(frame.f_code)
 148                                 filename = frame.f_code.co_filename
 149                                 pkey = filename + ':' + `lineno` + '(' + funcname + ')'
 150                                 pframe.f_locals['__key'] = pkey
 151                         if self.debug:
 152                                 s1 = 'parent: '+pkey
 153                         if pframe.f_locals.has_key('__start_time') and \
 154                                   self.timings.has_key(pkey):
 155                                 st = pframe.f_locals['__start_time']
 156                                 nc, tt, ct, callers, callees = \
 157                                         self.timings[pkey]
 158                                 if self.debug:
 159                                         s1 = s1+' before: st='+`st`+' nc='+`nc`+' tt='+`tt`+' ct='+`ct`
 160                                         s1 = s1+' after: st='+`t`+' nc='+`nc`+' tt='+`tt`+' ct='+`ct+(t-st)`
 161                                 self.timings[pkey] = \
 162                                         nc, tt, ct + (t - st), callers, callees
 163                                 pframe.f_locals['__start_time'] = t
 164                 if self.timings.has_key(key):
 165                         nc, tt, ct, callers, callees = self.timings[key]
 166                 else:
 167                         nc, tt, ct, callers, callees = 0, 0, 0, {}, {}
 168                 if frame.f_locals.has_key('__start_time'):
 169                         st = frame.f_locals['__start_time']
 170                 else:
 171                         st = t
 172                 if self.debug:
 173                         s0 = s0+' before: st='+`st`+' nc='+`nc`+' tt='+`tt`+' ct='+`ct`
 174                         s0 = s0+' after: nc='+`nc`+' tt='+`tt+(t-st)`+' ct='+`ct+(t-st)`
 175                         print s0
 176                         print s1
 177                 self.timings[key] = \
 178                         nc, tt + (t - st), ct + (t - st), callers, callees
 179
 180         def print_stats(self):
 181                 # Print in reverse order by ct
 182                 print_title()
 183                 list = []
 184                 for key in self.timings.keys():
 185                         nc, tt, ct, callers, callees = self.timings[key]
 186                         if nc == 0:
 187                                 continue
 188                         list.append(ct, tt, nc, key)
 189                 list.sort()
 190                 list.reverse()
 191                 for ct, tt, nc, key in list:
 192                         print_line(nc, tt, ct, os.path.basename(key))
 193
 194         def dump_stats(self, file):
 195                 f = open(file, 'w')
 196                 marshal.dump(self.timings, f)
 197                 f.close()
 198
 199         # The following two methods can be called by clients to use
 200         # a profiler to profile a statement, given as a string.
 201
 202         def run(self, cmd):
 203                 import __main__
 204                 dict = __main__.__dict__
 205                 self.runctx(cmd, dict, dict)
 206
 207         def runctx(self, cmd, globals, locals):
 208                 sys.setprofile(self.trace_dispatch)
 209                 try:
 210                         exec(cmd + '\n', globals, locals)
 211                 finally:
 212                         sys.setprofile(None)
 213
 214         # This method is more useful to profile a single function call.
 215
 216         def runcall(self, func, *args):
 217                 sys.setprofile(self.trace_dispatch)
 218                 try:
 219                         apply(func, args)
 220                 finally:
 221                         sys.setprofile(None)
 222
 223
 224 def depth(frame):
 225         d = 0
 226         while frame:
 227                 d = d + 1
 228                 frame = frame.f_back
 229         return d
 230
 231 class Stats:
 232         def __init__(self, file):
 233                 f = open(file, 'r')
 234                 self.stats = marshal.load(f)
 235                 f.close()
 236                 self.stats_list = None
 237
 238         def print_stats(self):
 239                 print_title()
 240                 if self.stats_list:
 241                         for i in range(len(self.stats_list)):
 242                                 nc, tt, ct, callers, callees, key = \
 243                                         self.stats_list[i]
 244                                 print_line(nc, tt, ct, key)
 245                 else:
 246                         for key in self.stats.keys():
 247                                 nc, tt, ct, callers, callees = self.stats[key]
 248                                 print_line(nc, tt, ct, key)
 249
 250         def print_callers(self):
 251                 if self.stats_list:
 252                         for i in range(len(self.stats_list)):
 253                                 nc, tt, ct, callers, callees, key = \
 254                                         self.stats_list[i]
 255                                 print key,
 256                                 for func in callers.keys():
 257                                         print func+'('+`callers[func]`+')',
 258                                 print
 259                 else:
 260                         for key in self.stats.keys():
 261                                 nc, tt, ct, callers, callees = self.stats[key]
 262                                 print key,
 263                                 for func in callers.keys():
 264                                         print func+'('+`callers[func]`+')',
 265                                 print
 266
 267         def print_callees(self):
 268                 if self.stats_list:
 269                         for i in range(len(self.stats_list)):
 270                                 nc, tt, ct, callers, callees, key = \
 271                                         self.stats_list[i]
 272                                 print key,
 273                                 for func in callees.keys():
 274                                         print func+'('+`callees[func]`+')',
 275                                 print
 276                 else:
 277                         for key in self.stats.keys():
 278                                 nc, tt, ct, callers, callees = self.stats[key]
 279                                 print key,
 280                                 for func in callees.keys():
 281                                         print func+'('+`callees[func]`+')',
 282                                 print
 283
 284         def sort_stats(self, field):
 285                 stats_list = []
 286                 for key in self.stats.keys():
 287                         t = self.stats[key]
 288                         nt = ()
 289                         for i in range(len(t)):
 290                                 if i == field:
 291                                         nt = (t[i],) + nt[:]
 292                                 else:
 293                                         nt = nt[:] + (t[i],)
 294                         if field == -1:
 295                                 nt = (key,) + nt
 296                         else:
 297                                 nt = nt + (key,)
 298                         stats_list.append(nt)
 299                 stats_list.sort()
 300                 self.stats_list = []
 301                 for i in range(len(stats_list)):
 302                         t = stats_list[i]
 303                         if field == -1:
 304                                 nt = t[1:] + t[0:1]
 305                         else:
 306                                 nt = t[1:]
 307                                 nt = nt[:field] + t[0:1] + nt[field:]
 308                         self.stats_list.append(nt)
 309
 310         def reverse_order(self):
 311                 self.stats_list.reverse()
 312
 313         def strip_dirs(self):
 314                 newstats = {}
 315                 for key in self.stats.keys():
 316                         nc, tt, ct, callers, callees = self.stats[key]
 317                         newkey = os.path.basename(key)
 318                         newcallers = {}
 319                         for c in callers.keys():
 320                                 newcallers[os.path.basename(c)] = callers[c]
 321                         newcallees = {}
 322                         for c in callees.keys():
 323                                 newcallees[os.path.basename(c)] = callees[c]
 324                         newstats[newkey] = nc, tt, ct, newcallers, newcallees
 325                 self.stats = newstats
 326                 self.stats_list = None
 327
 328 def print_title():
 329         print string.rjust('ncalls', 8),
 330         print string.rjust('tottime', 8),
 331         print string.rjust('percall', 8),
 332         print string.rjust('cumtime', 8),
 333         print string.rjust('percall', 8),
 334         print 'filename:lineno(function)'
 335
 336 def print_line(nc, tt, ct, key):
 337         print string.rjust(`nc`, 8),
 338         print f8(tt),
 339         if nc == 0:
 340                 print ' '*8,
 341         else:
 342                 print f8(tt/nc),
 343         print f8(ct),
 344         if nc == 0:
 345                 print ' '*8,
 346         else:
 347                 print f8(ct/nc),
 348         print key
 349
 350 def f8(x):
 351         return string.rjust(fpformat.fix(x, 3), 8)
 352
 353 # simplified user interface
 354 def run(statement, *args):
 355         prof = Profile()
 356         try:
 357                 prof.run(statement)
 358         except SystemExit:
 359                 pass
 360         if len(args) == 0:
 361                 prof.print_stats()
 362         else:
 363                 prof.dump_stats(args[0])
 364
 365 # test command with debugging
 366 def debug():
 367         prof = Profile()
 368         prof.debug = 1
 369         try:
 370                 prof.run('import x; x.main()')
 371         except SystemExit:
 372                 pass
 373         prof.print_stats()
 374
 375 # test command
 376 def test():
 377         run('import x; x.main()')
 378
 379 # print help
 380 def help():
 381         for dirname in sys.path:
 382                 fullname = os.path.join(dirname, 'profile.doc')
 383                 if os.path.exists(fullname):
 384                         sts = os.system('${PAGER-more} '+fullname)
 385                         if sts: print '*** Pager exit status:', sts
 386                         break
 387         else:
 388                 print 'Sorry, can\'t find the help file "profile.doc"',
 389                 print 'along the Python search path'