1 """Class for printing reports on profiled python code.""" 2 3 # Written by James Roskind 4 # Based on prior profile module by Sjoerd Mullender... 5 # which was hacked somewhat by: Guido van Rossum 6 7 # Copyright Disney Enterprises, Inc. All Rights Reserved. 8 # Licensed to PSF under a Contributor Agreement 9 # 10 # Licensed under the Apache License, Version 2.0 (the "License"); 11 # you may not use this file except in compliance with the License. 12 # You may obtain a copy of the License at 13 # 14 # http://www.apache.org/licenses/LICENSE-2.0 15 # 16 # Unless required by applicable law or agreed to in writing, software 17 # distributed under the License is distributed on an "AS IS" BASIS, 18 # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, 19 # either express or implied. See the License for the specific language 20 # governing permissions and limitations under the License. 21 22 23 import sys 24 import os 25 import time 26 import marshal 27 import re 28 from functools import cmp_to_key 29 30 __all__ = ["Stats"] 31 32 class Stats: 33 """This class is used for creating reports from data generated by the 34 Profile class. It is a "friend" of that class, and imports data either 35 by direct access to members of Profile class, or by reading in a dictionary 36 that was emitted (via marshal) from the Profile class. 37 38 The big change from the previous Profiler (in terms of raw functionality) 39 is that an "add()" method has been provided to combine Stats from 40 several distinct profile runs. Both the constructor and the add() 41 method now take arbitrarily many file names as arguments. 42 43 All the print methods now take an argument that indicates how many lines 44 to print. If the arg is a floating point number between 0 and 1.0, then 45 it is taken as a decimal percentage of the available lines to be printed 46 (e.g., .1 means print 10% of all available lines). If it is an integer, 47 it is taken to mean the number of lines of data that you wish to have 48 printed. 49 50 The sort_stats() method now processes some additional options (i.e., in 51 addition to the old -1, 0, 1, or 2 that are respectively interpreted as 52 'stdname', 'calls', 'time', and 'cumulative'). It takes an arbitrary number 53 of quoted strings to select the sort order. 54 55 For example sort_stats('time', 'name') sorts on the major key of 'internal 56 function time', and on the minor key of 'the name of the function'. Look at 57 the two tables in sort_stats() and get_sort_arg_defs(self) for more 58 examples. 59 60 All methods return self, so you can string together commands like: 61 Stats('foo', 'goo').strip_dirs().sort_stats('calls').\ 62 print_stats(5).print_callers(5) 63 """ 64 65 def __init__(self, *args, stream=None): 66 self.stream = stream or sys.stdout 67 if not len(args): 68 arg = None 69 else: 70 arg = args[0] 71 args = args[1:] 72 self.init(arg) 73 self.add(*args) 74 75 def init(self, arg): 76 self.all_callees = None # calc only if needed 77 self.files = [] 78 self.fcn_list = None 79 self.total_tt = 0 80 self.total_calls = 0 81 self.prim_calls = 0 82 self.max_name_len = 0 83 self.top_level = set() 84 self.stats = {} 85 self.sort_arg_dict = {} 86 self.load_stats(arg) 87 try: 88 self.get_top_level_stats() 89 except Exception: 90 print("Invalid timing data %s" % 91 (self.files[-1] if self.files else ''), file=self.stream) 92 raise 93 94 def load_stats(self, arg): 95 if arg is None: 96 self.stats = {} 97 return 98 elif isinstance(arg, str): 99 with open(arg, 'rb') as f: 100 self.stats = marshal.load(f) 101 try: 102 file_stats = os.stat(arg) 103 arg = time.ctime(file_stats.st_mtime) + " " + arg 104 except: # in case this is not unix 105 pass 106 self.files = [arg] 107 elif hasattr(arg, 'create_stats'): 108 arg.create_stats() 109 self.stats = arg.stats 110 arg.stats = {} 111 if not self.stats: 112 raise TypeError("Cannot create or construct a %r object from %r" 113 % (self.__class__, arg)) 114 return 115 116 def get_top_level_stats(self): 117 for func, (cc, nc, tt, ct, callers) in self.stats.items(): 118 self.total_calls += nc 119 self.prim_calls += cc 120 self.total_tt += tt 121 if ("jprofile", 0, "profiler") in callers: 122 self.top_level.add(func) 123 if len(func_std_string(func)) > self.max_name_len: 124 self.max_name_len = len(func_std_string(func)) 125 126 def add(self, *arg_list): 127 if not arg_list: 128 return self 129 for item in reversed(arg_list): 130 if type(self) != type(item): 131 item = Stats(item) 132 self.files += item.files 133 self.total_calls += item.total_calls 134 self.prim_calls += item.prim_calls 135 self.total_tt += item.total_tt 136 for func in item.top_level: 137 self.top_level.add(func) 138 139 if self.max_name_len < item.max_name_len: 140 self.max_name_len = item.max_name_len 141 142 self.fcn_list = None 143 144 for func, stat in item.stats.items(): 145 if func in self.stats: 146 old_func_stat = self.stats[func] 147 else: 148 old_func_stat = (0, 0, 0, 0, {},) 149 self.stats[func] = add_func_stats(old_func_stat, stat) 150 return self 151 152 def dump_stats(self, filename): 153 """Write the profile data to a file we know how to load back.""" 154 with open(filename, 'wb') as f: 155 marshal.dump(self.stats, f) 156 157 # list the tuple indices and directions for sorting, 158 # along with some printable description 159 sort_arg_dict_default = { 160 "calls" : (((1,-1), ), "call count"), 161 "ncalls" : (((1,-1), ), "call count"), 162 "cumtime" : (((3,-1), ), "cumulative time"), 163 "cumulative": (((3,-1), ), "cumulative time"), 164 "file" : (((4, 1), ), "file name"), 165 "filename" : (((4, 1), ), "file name"), 166 "line" : (((5, 1), ), "line number"), 167 "module" : (((4, 1), ), "file name"), 168 "name" : (((6, 1), ), "function name"), 169 "nfl" : (((6, 1),(4, 1),(5, 1),), "name/file/line"), 170 "pcalls" : (((0,-1), ), "primitive call count"), 171 "stdname" : (((7, 1), ), "standard name"), 172 "time" : (((2,-1), ), "internal time"), 173 "tottime" : (((2,-1), ), "internal time"), 174 } 175 176 def get_sort_arg_defs(self): 177 """Expand all abbreviations that are unique.""" 178 if not self.sort_arg_dict: 179 self.sort_arg_dict = dict = {} 180 bad_list = {} 181 for word, tup in self.sort_arg_dict_default.items(): 182 fragment = word 183 while fragment: 184 if not fragment: 185 break 186 if fragment in dict: 187 bad_list[fragment] = 0 188 break 189 dict[fragment] = tup 190 fragment = fragment[:-1] 191 for word in bad_list: 192 del dict[word] 193 return self.sort_arg_dict 194 195 def sort_stats(self, *field): 196 if not field: 197 self.fcn_list = 0 198 return self 199 if len(field) == 1 and isinstance(field[0], int): 200 # Be compatible with old profiler 201 field = [ {-1: "stdname", 202 0: "calls", 203 1: "time", 204 2: "cumulative"}[field[0]] ] 205 206 sort_arg_defs = self.get_sort_arg_defs() 207 sort_tuple = () 208 self.sort_type = "" 209 connector = "" 210 for word in field: 211 sort_tuple = sort_tuple + sort_arg_defs[word][0] 212 self.sort_type += connector + sort_arg_defs[word][1] 213 connector = ", " 214 215 stats_list = [] 216 for func, (cc, nc, tt, ct, callers) in self.stats.items(): 217 stats_list.append((cc, nc, tt, ct) + func + 218 (func_std_string(func), func)) 219 220 stats_list.sort(key=cmp_to_key(TupleComp(sort_tuple).compare)) 221 222 self.fcn_list = fcn_list = [] 223 for tuple in stats_list: 224 fcn_list.append(tuple[-1]) 225 return self 226 227 def reverse_order(self): 228 if self.fcn_list: 229 self.fcn_list.reverse() 230 return self 231 232 def strip_dirs(self): 233 oldstats = self.stats 234 self.stats = newstats = {} 235 max_name_len = 0 236 for func, (cc, nc, tt, ct, callers) in oldstats.items(): 237 newfunc = func_strip_path(func) 238 if len(func_std_string(newfunc)) > max_name_len: 239 max_name_len = len(func_std_string(newfunc)) 240 newcallers = {} 241 for func2, caller in callers.items(): 242 newcallers[func_strip_path(func2)] = caller 243 244 if newfunc in newstats: 245 newstats[newfunc] = add_func_stats( 246 newstats[newfunc], 247 (cc, nc, tt, ct, newcallers)) 248 else: 249 newstats[newfunc] = (cc, nc, tt, ct, newcallers) 250 old_top = self.top_level 251 self.top_level = new_top = set() 252 for func in old_top: 253 new_top.add(func_strip_path(func)) 254 255 self.max_name_len = max_name_len 256 257 self.fcn_list = None 258 self.all_callees = None 259 return self 260 261 def calc_callees(self): 262 if self.all_callees: 263 return 264 self.all_callees = all_callees = {} 265 for func, (cc, nc, tt, ct, callers) in self.stats.items(): 266 if not func in all_callees: 267 all_callees[func] = {} 268 for func2, caller in callers.items(): 269 if not func2 in all_callees: 270 all_callees[func2] = {} 271 all_callees[func2][func] = caller 272 return 273 274 #****************************************************************** 275 # The following functions support actual printing of reports 276 #****************************************************************** 277 278 # Optional "amount" is either a line count, or a percentage of lines. 279 280 def eval_print_amount(self, sel, list, msg): 281 new_list = list 282 if isinstance(sel, str): 283 try: 284 rex = re.compile(sel) 285 except re.error: 286 msg += " <Invalid regular expression %r>\n" % sel 287 return new_list, msg 288 new_list = [] 289 for func in list: 290 if rex.search(func_std_string(func)): 291 new_list.append(func) 292 else: 293 count = len(list) 294 if isinstance(sel, float) and 0.0 <= sel < 1.0: 295 count = int(count * sel + .5) 296 new_list = list[:count] 297 elif isinstance(sel, int) and 0 <= sel < count: 298 count = sel 299 new_list = list[:count] 300 if len(list) != len(new_list): 301 msg += " List reduced from %r to %r due to restriction <%r>\n" % ( 302 len(list), len(new_list), sel) 303 304 return new_list, msg 305 306 def get_print_list(self, sel_list): 307 width = self.max_name_len 308 if self.fcn_list: 309 stat_list = self.fcn_list[:] 310 msg = " Ordered by: " + self.sort_type + '\n' 311 else: 312 stat_list = list(self.stats.keys()) 313 msg = " Random listing order was used\n" 314 315 for selection in sel_list: 316 stat_list, msg = self.eval_print_amount(selection, stat_list, msg) 317 318 count = len(stat_list) 319 320 if not stat_list: 321 return 0, stat_list 322 print(msg, file=self.stream) 323 if count < len(self.stats): 324 width = 0 325 for func in stat_list: 326 if len(func_std_string(func)) > width: 327 width = len(func_std_string(func)) 328 return width+2, stat_list 329 330 def print_stats(self, *amount): 331 for filename in self.files: 332 print(filename, file=self.stream) 333 if self.files: 334 print(file=self.stream) 335 indent = ' ' * 8 336 for func in self.top_level: 337 print(indent, func_get_function_name(func), file=self.stream) 338 339 print(indent, self.total_calls, "function calls", end=' ', file=self.stream) 340 if self.total_calls != self.prim_calls: 341 print("(%d primitive calls)" % self.prim_calls, end=' ', file=self.stream) 342 print("in %.3f seconds" % self.total_tt, file=self.stream) 343 print(file=self.stream) 344 width, list = self.get_print_list(amount) 345 if list: 346 self.print_title() 347 for func in list: 348 self.print_line(func) 349 print(file=self.stream) 350 print(file=self.stream) 351 return self 352 353 def print_callees(self, *amount): 354 width, list = self.get_print_list(amount) 355 if list: 356 self.calc_callees() 357 358 self.print_call_heading(width, "called...") 359 for func in list: 360 if func in self.all_callees: 361 self.print_call_line(width, func, self.all_callees[func]) 362 else: 363 self.print_call_line(width, func, {}) 364 print(file=self.stream) 365 print(file=self.stream) 366 return self 367 368 def print_callers(self, *amount): 369 width, list = self.get_print_list(amount) 370 if list: 371 self.print_call_heading(width, "was called by...") 372 for func in list: 373 cc, nc, tt, ct, callers = self.stats[func] 374 self.print_call_line(width, func, callers, "<-") 375 print(file=self.stream) 376 print(file=self.stream) 377 return self 378 379 def print_call_heading(self, name_size, column_title): 380 print("Function ".ljust(name_size) + column_title, file=self.stream) 381 # print sub-header only if we have new-style callers 382 subheader = False 383 for cc, nc, tt, ct, callers in self.stats.values(): 384 if callers: 385 value = next(iter(callers.values())) 386 subheader = isinstance(value, tuple) 387 break 388 if subheader: 389 print(" "*name_size + " ncalls tottime cumtime", file=self.stream) 390 391 def print_call_line(self, name_size, source, call_dict, arrow="->"): 392 print(func_std_string(source).ljust(name_size) + arrow, end=' ', file=self.stream) 393 if not call_dict: 394 print(file=self.stream) 395 return 396 clist = sorted(call_dict.keys()) 397 indent = "" 398 for func in clist: 399 name = func_std_string(func) 400 value = call_dict[func] 401 if isinstance(value, tuple): 402 nc, cc, tt, ct = value 403 if nc != cc: 404 substats = '%d/%d' % (nc, cc) 405 else: 406 substats = '%d' % (nc,) 407 substats = '%s %s %s %s' % (substats.rjust(7+2*len(indent)), 408 f8(tt), f8(ct), name) 409 left_width = name_size + 1 410 else: 411 substats = '%s(%r) %s' % (name, value, f8(self.stats[func][3])) 412 left_width = name_size + 3 413 print(indent*left_width + substats, file=self.stream) 414 indent = " " 415 416 def print_title(self): 417 print(' ncalls tottime percall cumtime percall', end=' ', file=self.stream) 418 print('filename:lineno(function)', file=self.stream) 419 420 def print_line(self, func): # hack: should print percentages 421 cc, nc, tt, ct, callers = self.stats[func] 422 c = str(nc) 423 if nc != cc: 424 c = c + '/' + str(cc) 425 print(c.rjust(9), end=' ', file=self.stream) 426 print(f8(tt), end=' ', file=self.stream) 427 if nc == 0: 428 print(' '*8, end=' ', file=self.stream) 429 else: 430 print(f8(tt/nc), end=' ', file=self.stream) 431 print(f8(ct), end=' ', file=self.stream) 432 if cc == 0: 433 print(' '*8, end=' ', file=self.stream) 434 else: 435 print(f8(ct/cc), end=' ', file=self.stream) 436 print(func_std_string(func), file=self.stream) 437 438 class TupleComp: 439 """This class provides a generic function for comparing any two tuples. 440 Each instance records a list of tuple-indices (from most significant 441 to least significant), and sort direction (ascending or decending) for 442 each tuple-index. The compare functions can then be used as the function 443 argument to the system sort() function when a list of tuples need to be 444 sorted in the instances order.""" 445 446 def __init__(self, comp_select_list): 447 self.comp_select_list = comp_select_list 448 449 def compare (self, left, right): 450 for index, direction in self.comp_select_list: 451 l = left[index] 452 r = right[index] 453 if l < r: 454 return -direction 455 if l > r: 456 return direction 457 return 0 458 459 460 #************************************************************************** 461 # func_name is a triple (file:string, line:int, name:string) 462 463 def func_strip_path(func_name): 464 filename, line, name = func_name 465 return os.path.basename(filename), line, name 466 467 def func_get_function_name(func): 468 return func[2] 469 470 def func_std_string(func_name): # match what old profile produced 471 if func_name[:2] == ('~', 0): 472 # special case for built-in functions 473 name = func_name[2] 474 if name.startswith('<') and name.endswith('>'): 475 return '{%s}' % name[1:-1] 476 else: 477 return name 478 else: 479 return "%s:%d(%s)" % func_name 480 481 #************************************************************************** 482 # The following functions combine statists for pairs functions. 483 # The bulk of the processing involves correctly handling "call" lists, 484 # such as callers and callees. 485 #************************************************************************** 486 487 def add_func_stats(target, source): 488 """Add together all the stats for two profile entries.""" 489 cc, nc, tt, ct, callers = source 490 t_cc, t_nc, t_tt, t_ct, t_callers = target 491 return (cc+t_cc, nc+t_nc, tt+t_tt, ct+t_ct, 492 add_callers(t_callers, callers)) 493 494 def add_callers(target, source): 495 """Combine two caller lists in a single list.""" 496 new_callers = {} 497 for func, caller in target.items(): 498 new_callers[func] = caller 499 for func, caller in source.items(): 500 if func in new_callers: 501 if isinstance(caller, tuple): 502 # format used by cProfile 503 new_callers[func] = tuple([i[0] + i[1] for i in 504 zip(caller, new_callers[func])]) 505 else: 506 # format used by profile 507 new_callers[func] += caller 508 else: 509 new_callers[func] = caller 510 return new_callers 511 512 def count_calls(callers): 513 """Sum the caller statistics to get total number of calls received.""" 514 nc = 0 515 for calls in callers.values(): 516 nc += calls 517 return nc 518 519 #************************************************************************** 520 # The following functions support printing of reports 521 #************************************************************************** 522 523 def f8(x): 524 return "%8.3f" % x 525 526 #************************************************************************** 527 # Statistics browser added by ESR, April 2001 528 #************************************************************************** 529 530 if __name__ == '__main__': 531 import cmd 532 try: 533 import readline 534 except ImportError: 535 pass 536 537 class ProfileBrowser(cmd.Cmd): 538 def __init__(self, profile=None): 539 cmd.Cmd.__init__(self) 540 self.prompt = "% " 541 self.stats = None 542 self.stream = sys.stdout 543 if profile is not None: 544 self.do_read(profile) 545 546 def generic(self, fn, line): 547 args = line.split() 548 processed = [] 549 for term in args: 550 try: 551 processed.append(int(term)) 552 continue 553 except ValueError: 554 pass 555 try: 556 frac = float(term) 557 if frac > 1 or frac < 0: 558 print("Fraction argument must be in [0, 1]", file=self.stream) 559 continue 560 processed.append(frac) 561 continue 562 except ValueError: 563 pass 564 processed.append(term) 565 if self.stats: 566 getattr(self.stats, fn)(*processed) 567 else: 568 print("No statistics object is loaded.", file=self.stream) 569 return 0 570 def generic_help(self): 571 print("Arguments may be:", file=self.stream) 572 print("* An integer maximum number of entries to print.", file=self.stream) 573 print("* A decimal fractional number between 0 and 1, controlling", file=self.stream) 574 print(" what fraction of selected entries to print.", file=self.stream) 575 print("* A regular expression; only entries with function names", file=self.stream) 576 print(" that match it are printed.", file=self.stream) 577 578 def do_add(self, line): 579 if self.stats: 580 try: 581 self.stats.add(line) 582 except IOError as e: 583 print("Failed to load statistics for %s: %s" % (line, e), file=self.stream) 584 else: 585 print("No statistics object is loaded.", file=self.stream) 586 return 0 587 def help_add(self): 588 print("Add profile info from given file to current statistics object.", file=self.stream) 589 590 def do_callees(self, line): 591 return self.generic('print_callees', line) 592 def help_callees(self): 593 print("Print callees statistics from the current stat object.", file=self.stream) 594 self.generic_help() 595 596 def do_callers(self, line): 597 return self.generic('print_callers', line) 598 def help_callers(self): 599 print("Print callers statistics from the current stat object.", file=self.stream) 600 self.generic_help() 601 602 def do_EOF(self, line): 603 print("", file=self.stream) 604 return 1 605 def help_EOF(self): 606 print("Leave the profile brower.", file=self.stream) 607 608 def do_quit(self, line): 609 return 1 610 def help_quit(self): 611 print("Leave the profile brower.", file=self.stream) 612 613 def do_read(self, line): 614 if line: 615 try: 616 self.stats = Stats(line) 617 except OSError as err: 618 print(err.args[1], file=self.stream) 619 return 620 except Exception as err: 621 print(err.__class__.__name__ + ':', err, file=self.stream) 622 return 623 self.prompt = line + "% " 624 elif len(self.prompt) > 2: 625 line = self.prompt[:-2] 626 self.do_read(line) 627 else: 628 print("No statistics object is current -- cannot reload.", file=self.stream) 629 return 0 630 def help_read(self): 631 print("Read in profile data from a specified file.", file=self.stream) 632 print("Without argument, reload the current file.", file=self.stream) 633 634 def do_reverse(self, line): 635 if self.stats: 636 self.stats.reverse_order() 637 else: 638 print("No statistics object is loaded.", file=self.stream) 639 return 0 640 def help_reverse(self): 641 print("Reverse the sort order of the profiling report.", file=self.stream) 642 643 def do_sort(self, line): 644 if not self.stats: 645 print("No statistics object is loaded.", file=self.stream) 646 return 647 abbrevs = self.stats.get_sort_arg_defs() 648 if line and all((x in abbrevs) for x in line.split()): 649 self.stats.sort_stats(*line.split()) 650 else: 651 print("Valid sort keys (unique prefixes are accepted):", file=self.stream) 652 for (key, value) in Stats.sort_arg_dict_default.items(): 653 print("%s -- %s" % (key, value[1]), file=self.stream) 654 return 0 655 def help_sort(self): 656 print("Sort profile data according to specified keys.", file=self.stream) 657 print("(Typing `sort' without arguments lists valid keys.)", file=self.stream) 658 def complete_sort(self, text, *args): 659 return [a for a in Stats.sort_arg_dict_default if a.startswith(text)] 660 661 def do_stats(self, line): 662 return self.generic('print_stats', line) 663 def help_stats(self): 664 print("Print statistics from the current stat object.", file=self.stream) 665 self.generic_help() 666 667 def do_strip(self, line): 668 if self.stats: 669 self.stats.strip_dirs() 670 else: 671 print("No statistics object is loaded.", file=self.stream) 672 def help_strip(self): 673 print("Strip leading path information from filenames in the report.", file=self.stream) 674 675 def help_help(self): 676 print("Show help for a given command.", file=self.stream) 677 678 def postcmd(self, stop, line): 679 if stop: 680 return stop 681 return None 682 683 if len(sys.argv) > 1: 684 initprofile = sys.argv[1] 685 else: 686 initprofile = None 687 try: 688 browser = ProfileBrowser(initprofile) 689 for profile in sys.argv[2:]: 690 browser.do_add(profile) 691 print("Welcome to the profile statistics browser.", file=browser.stream) 692 browser.cmdloop() 693 print("Goodbye.", file=browser.stream) 694 except KeyboardInterrupt: 695 pass 696 697 # That's all, folks. 698