coro.print_profile

Source Code for Module coro.print_profile

1 # Copyright (c) 2002-2011 IronPort Systems and Cisco Systems 2 # 3 # Permission is hereby granted, free of charge, to any person obtaining a copy 4 # of this software and associated documentation files (the "Software"), to deal 5 # in the Software without restriction, including without limitation the rights 6 # to use, copy, modify, merge, publish, distribute, sublicense, and/or sell 7 # copies of the Software, and to permit persons to whom the Software is 8 # furnished to do so, subject to the following conditions: 9 # 10 # The above copyright notice and this permission notice shall be included in 11 # all copies or substantial portions of the Software. 12 # 13 # THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR 14 # IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, 15 # FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE 16 # AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER 17 # LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, 18 # OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE 19 # SOFTWARE. 20 21 # $Header: /cvsroot/ap/shrapnel/coro/print_profile.py,v 1.1 2006/11/30 21:58:41 ehuss Exp $ 22 23 """Display profile data as HTML. 24 25 TODO 26 ==== 27 - The javascript sorting code has a weird behavior. If you click on a column 28 to sort it, then click on a different column, the click on the previous 29 column, the sort order changes. I would prefer it it just went with the 30 previous sort order. However, fixing it is not obvious to me. 31 32 """ 33 34 35 36 import urllib 37 import cgi 38 import sys 39 import coro.profiler 40 import cPickle 41 import time 42 43 PER_COLUMNS = ('ticks', 'utime', 'stime') 44 45 # from http://kryogenix.org/code/browser/sorttable/ 46 # Note: I changed the default sort direction to 'down' 47 sortable_js = """addEvent(window, "load", sortables_init); 48 49 var SORT_COLUMN_INDEX; 50 51 function sortables_init() { 52 // Find all tables with class sortable and make them sortable 53 if (!document.getElementsByTagName) return; 54 tbls = document.getElementsByTagName("table"); 55 for (ti=0;ti<tbls.length;ti++) { 56 thisTbl = tbls[ti]; 57 if (((' '+thisTbl.className+' ').indexOf("sortable") != -1) && (thisTbl.id)) { 58 //initTable(thisTbl.id); 59 ts_makeSortable(thisTbl); 60 } 61 } 62 } 63 64 function ts_makeSortable(table) { 65 if (table.rows && table.rows.length > 0) { 66 var firstRow = table.rows[0]; 67 } 68 if (!firstRow) return; 69 70 // We have a first row: assume it's the header, and make its contents clickable links 71 for (var i=0;i<firstRow.cells.length;i++) { 72 var cell = firstRow.cells[i]; 73 var txt = ts_getInnerText(cell); 74 cell.innerHTML = '<a href="#" class="sortheader" '+ 75 'onclick="ts_resortTable(this, '+i+');return false;">' + 76 txt+'<span class="sortarrow">   </span></a>'; 77 } 78 } 79 80 function ts_getInnerText(el) { 81 if (typeof el == "string") return el; 82 if (typeof el == "undefined") { return el }; 83 if (el.innerText) return el.innerText; //Not needed but it is faster 84 var str = ""; 85 86 var cs = el.childNodes; 87 var l = cs.length; 88 for (var i = 0; i < l; i++) { 89 switch (cs[i].nodeType) { 90 case 1: //ELEMENT_NODE 91 str += ts_getInnerText(cs[i]); 92 break; 93 case 3: //TEXT_NODE 94 str += cs[i].nodeValue; 95 break; 96 } 97 } 98 return str; 99 } 100 101 function ts_resortTable(lnk,clid) { 102 // get the span 103 var span; 104 for (var ci=0;ci<lnk.childNodes.length;ci++) { 105 if (lnk.childNodes[ci].tagName && lnk.childNodes[ci].tagName.toLowerCase() == 'span') span = lnk.childNodes[ci]; 106 } 107 var spantext = ts_getInnerText(span); 108 var td = lnk.parentNode; 109 var column = clid || td.cellIndex; 110 var table = getParent(td,'TABLE'); 111 112 // Work out a type for the column 113 if (table.rows.length <= 1) return; 114 var itm = ts_getInnerText(table.rows[1].cells[column]); 115 //sortfn = ts_sort_caseinsensitive; 116 //if (itm.match(/^\d\d[\/-]\d\d[\/-]\d\d\d\d$/)) sortfn = ts_sort_date; 117 //if (itm.match(/^\d\d[\/-]\d\d[\/-]\d\d$/)) sortfn = ts_sort_date; 118 //if (itm.match(/^[\ufffd$]/)) sortfn = ts_sort_currency; 119 //if (itm.match(/^[\d\.]+$/)) sortfn = ts_sort_numeric; 120 sortfn = ts_sort_numeric; 121 SORT_COLUMN_INDEX = column; 122 var firstRow = new Array(); 123 var newRows = new Array(); 124 for (i=0;i<table.rows[0].length;i++) { firstRow[i] = table.rows[0][i]; } 125 for (j=1;j<table.rows.length;j++) { newRows[j-1] = table.rows[j]; } 126 127 newRows.sort(sortfn); 128 129 if (span.getAttribute("sortdir") == 'up') { 130 ARROW = '  ↓'; 131 span.setAttribute('sortdir','down'); 132 } else { 133 ARROW = '  ↑'; 134 newRows.reverse(); 135 span.setAttribute('sortdir','up'); 136 } 137 138 // We appendChild rows that already exist to the tbody, so it moves them rather than creating new ones 139 // don't do sortbottom rows 140 for (i=0;i<newRows.length;i++) { if (!newRows[i].className || (newRows[i].className && (newRows[i].className.indexOf('sortbottom') == -1))) table.tBodies[0].appendChild(newRows[i]);} 141 // do sortbottom rows only 142 for (i=0;i<newRows.length;i++) { if (newRows[i].className && (newRows[i].className.indexOf('sortbottom') != -1)) table.tBodies[0].appendChild(newRows[i]);} 143 144 // Delete any other arrows there may be showing 145 var allspans = document.getElementsByTagName("span"); 146 for (var ci=0;ci<allspans.length;ci++) { 147 if (allspans[ci].className == 'sortarrow') { 148 if (getParent(allspans[ci],"table") == getParent(lnk,"table")) { // in the same table as us? 149 allspans[ci].innerHTML = '   '; 150 } 151 } 152 } 153 154 span.innerHTML = ARROW; 155 } 156 157 function getParent(el, pTagName) { 158 if (el == null) return null; 159 else if (el.nodeType == 1 && el.tagName.toLowerCase() == pTagName.toLowerCase()) // Gecko bug, supposed to be uppercase 160 return el; 161 else 162 return getParent(el.parentNode, pTagName); 163 } 164 function ts_sort_date(a,b) { 165 // y2k notes: two digit years less than 50 are treated as 20XX, greater than 50 are treated as 19XX 166 aa = ts_getInnerText(a.cells[SORT_COLUMN_INDEX]); 167 bb = ts_getInnerText(b.cells[SORT_COLUMN_INDEX]); 168 if (aa.length == 10) { 169 dt1 = aa.substr(6,4)+aa.substr(3,2)+aa.substr(0,2); 170 } else { 171 yr = aa.substr(6,2); 172 if (parseInt(yr) < 50) { yr = '20'+yr; } else { yr = '19'+yr; } 173 dt1 = yr+aa.substr(3,2)+aa.substr(0,2); 174 } 175 if (bb.length == 10) { 176 dt2 = bb.substr(6,4)+bb.substr(3,2)+bb.substr(0,2); 177 } else { 178 yr = bb.substr(6,2); 179 if (parseInt(yr) < 50) { yr = '20'+yr; } else { yr = '19'+yr; } 180 dt2 = yr+bb.substr(3,2)+bb.substr(0,2); 181 } 182 if (dt1==dt2) return 0; 183 if (dt1<dt2) return -1; 184 return 1; 185 } 186 187 function ts_sort_currency(a,b) { 188 aa = ts_getInnerText(a.cells[SORT_COLUMN_INDEX]).replace(/[^0-9.]/g,''); 189 bb = ts_getInnerText(b.cells[SORT_COLUMN_INDEX]).replace(/[^0-9.]/g,''); 190 return parseFloat(aa) - parseFloat(bb); 191 } 192 193 function ts_sort_numeric(a,b) { 194 aa = parseFloat(ts_getInnerText(a.cells[SORT_COLUMN_INDEX])); 195 if (isNaN(aa)) aa = 0; 196 bb = parseFloat(ts_getInnerText(b.cells[SORT_COLUMN_INDEX])); 197 if (isNaN(bb)) bb = 0; 198 return aa-bb; 199 } 200 201 function ts_sort_caseinsensitive(a,b) { 202 aa = ts_getInnerText(a.cells[SORT_COLUMN_INDEX]).toLowerCase(); 203 bb = ts_getInnerText(b.cells[SORT_COLUMN_INDEX]).toLowerCase(); 204 if (aa==bb) return 0; 205 if (aa<bb) return -1; 206 return 1; 207 } 208 209 function ts_sort_default(a,b) { 210 aa = ts_getInnerText(a.cells[SORT_COLUMN_INDEX]); 211 bb = ts_getInnerText(b.cells[SORT_COLUMN_INDEX]); 212 if (aa==bb) return 0; 213 if (aa<bb) return -1; 214 return 1; 215 } 216 217 218 function addEvent(elm, evType, fn, useCapture) 219 // addEvent and removeEvent 220 // cross-browser event handling for IE5+, NS6 and Mozilla 221 // By Scott Andrew 222 { 223 if (elm.addEventListener){ 224 elm.addEventListener(evType, fn, useCapture); 225 return true; 226 } else if (elm.attachEvent){ 227 var r = elm.attachEvent("on"+evType, fn); 228 return r; 229 } else { 230 alert("Handler could not be removed"); 231 } 232 } 233 """ 234

235 -def _mapfuns(d1, d2):

236 """ 237 Given two dicts, d1 (k1 -> v1) and d2 (k2 -> v2), returns a dict which has 238 the mapping (k1 -> k2) such that _name(k1) == _name(k2). 239 """ 240 def _name(fn): 241 """ 242 Strips the line number at the end if any. 243 Eg. 'foo.py:23' -> 'foo.py', 'foo:bar.py' -> 'foo:bar.py' etc. 244 """ 245 parts = fn.rsplit(':', 1) 246 try: 247 int(parts[1]) 248 return parts[0] 249 except Exception: 250 return fn

251 252 m1 = [(_name(f), f) for f in d1] 253 m2 = dict([(_name(f), f) for f in d2]) 254 return dict([(v, m2[k]) for k,v in m1 if k in m2]) 255 256

257 -class profile_data:

258 259 """ 260 261 profile_data = {function_string: data_tuple} 262 263 data_tuple[0] is always calls 264 265 call_data = {caller_string: [(callee_string, call_count),...]) 266 } 267 268 """ 269

270 - def __init__(self, filename):

271 self._load(filename)

272

273 - def _load(self, filename):

274 f = open(filename) 275 header = f.read(len(coro.profiler.MAGIC)) 276 if header != coro.profiler.MAGIC: 277 err('Header not valid.') 278 self.bench_type, self.headings, self.time = cPickle.load(f) 279 self.profile_data = cPickle.load(f) 280 self.call_data = cPickle.load(f)

281

282 - def process(self, other_profile):

283 self._print_header() 284 self._print_timings(False, other_profile) 285 print '<hr>' 286 self._print_timings(True, other_profile) 287 self._print_call_graph() 288 self._print_footer()

289

290 - def _print_timings(self, aggregate, other_profile):

291 if aggregate: 292 print '<h2>Aggregate Timings</h2>' 293 else: 294 print '<h2>Non-Aggregate Timings</h2>' 295 296 # Find any columns that have all zeros and skip them. 297 has_nonzero = {} 298 # Also determine the sum for the column. 299 column_sums = [0]*len(self.headings) 300 empty_cols = [0]*len(self.headings) 301 302 for heading in self.headings: 303 has_nonzero[heading] = False 304 for function_string, (calls, data_tuple, aggregate_data_tuple) in self.profile_data.iteritems(): 305 if function_string != '<wait>': 306 for i, heading in enumerate(self.headings): 307 if aggregate: 308 data_item = aggregate_data_tuple[i] 309 else: 310 data_item = data_tuple[i] 311 if data_item: 312 has_nonzero[heading] = True 313 column_sums[i] += data_item 314 skip_headings = [] 315 for heading, nonzero in has_nonzero.items(): 316 if not nonzero: 317 skip_headings.append(heading) 318 319 print '<table id="t1" class="sortable" border=1 cellpadding=2 cellspacing=0>' 320 print ' <tr>' 321 print ' <th>calls</th>' 322 for heading in self.headings: 323 if heading not in skip_headings: 324 print ' <th>%s</th>' % (heading,) 325 if heading in PER_COLUMNS: 326 print ' <th>%s/call</th>' % (heading,) 327 print ' <th>Function</th>' 328 print ' </tr>' 329 330 m = _mapfuns(self.profile_data, other_profile) 331 for function_string, (calls, data_tuple, aggregate_data_tuple) in self.profile_data.iteritems(): 332 try: 333 calls2, data_tuple2, aggregate_data_tuple2 = other_profile[m[function_string]] 334 except KeyError: 335 calls2, data_tuple2, aggregate_data_tuple2 = 0,empty_cols, empty_cols 336 print ' <tr align=right>' 337 print ' <td>%s</td>' % (calls-calls2,) 338 for i, heading in enumerate(self.headings): 339 if heading not in skip_headings: 340 if aggregate: 341 data_item = aggregate_data_tuple[i]-aggregate_data_tuple2[i] 342 else: 343 data_item = data_tuple[i]-data_tuple2[i] 344 if isinstance(data_item, float): 345 value = '%.6f' % (data_item,) 346 else: 347 value = data_item 348 if data_item and function_string != '<wait>': 349 pct = ' (%.2f%%)' % ((float(data_item)/column_sums[i])*100,) 350 else: 351 pct = '' 352 print ' <td>%s%s</td>' % (value, pct) 353 if heading in PER_COLUMNS: 354 if calls == 0: 355 per = data_item 356 else: 357 if isinstance(data_item, float): 358 per = '%.6f' % (data_item/calls,) 359 else: 360 per = data_item/calls 361 print ' <td>%s</td>' % (per,) 362 print ' <td align=left><a name="tt_%s"></a><a href="#cg_%s">%s</a></td>' % ( 363 urllib.quote_plus(function_string), 364 urllib.quote_plus(function_string), 365 cgi.escape(function_string, quote=True) 366 ) 367 print ' </tr>' 368 print '</table>' 369 print '<p><tt>/call</tt> columns represent the time spent in that function per call <b>on average</b>.' 370 print '<p>Columns with all zeros are not displayed.'

371

372 - def _print_call_graph(self):

373 # self.call_data is caller->callee, make a reverse graph of callee->caller 374 rg = {} 375 for caller_string, callees in self.call_data.iteritems(): 376 for callee_string, call_count in callees: 377 if rg.has_key(callee_string): 378 rg[callee_string].append((caller_string, call_count)) 379 else: 380 rg[callee_string] = [(caller_string, call_count)] 381 382 functions = self.profile_data.items() 383 functions.sort() 384 385 for function_string, (calls, data_tuple, aggregate_data_tuple) in functions: 386 print '<hr>' 387 print '<tt><a name="cg_%s">%s</a> -- ' % ( 388 urllib.quote_plus(function_string), 389 cgi.escape(function_string, quote=True) 390 ) 391 for (data_item, heading) in zip(data_tuple, self.headings): 392 if data_item != 0: 393 print '%s=%s' % (heading, data_item) 394 print '</tt>' 395 print '<pre>' 396 # Print callers. 397 if rg.has_key(function_string): 398 l = [] 399 for caller, count in rg[function_string]: 400 l.append((caller, count)) 401 l.sort(lambda a,b: cmp(a[1], b[1])) 402 for caller, count in l: 403 print '%10i/%-10i (%04.1f%%) <a href="#tt_%s">%s</a>' % ( 404 count, 405 calls, 406 (float(count)/calls) * 100, 407 urllib.quote_plus(caller), 408 cgi.escape(caller, quote=True) 409 ) 410 411 print '%15i <b>%s</b>' % (calls, 412 function_string 413 ) 414 415 # Print callees. 416 callees2 = [] 417 callees = self.call_data.get(function_string, ()) 418 for callee_string, call_count in callees: 419 callee_calls = self.profile_data.get(callee_string, [1])[0] 420 callees2.append((callee_string, call_count, callee_calls)) 421 callees2.sort(lambda a,b: cmp(a[1], b[1])) 422 for callee_string, call_count, callee_calls in callees2: 423 print '%10i/%-10i (%04.1f%%) <a href="#tt_%s">%s</a>' % ( 424 call_count, 425 callee_calls, 426 (float(call_count)/callee_calls) * 100, 427 urllib.quote_plus(callee_string), 428 cgi.escape(callee_string, quote=True) 429 ) 430 print '</pre>' 431 432 print '<hr>' 433 print 'Description of output:' 434 print '<pre>' 435 print 'filename:funcname:lineno -- prof_data' 436 print 437 print ' caller_x/caller_y (%) caller' 438 print ' total_calls <b>function</b>' 439 print ' callee_x/callee_y (%) callee' 440 print 441 print 'caller_x is the number of times caller made a call to this function.' 442 print 'caller_y is the total number of calls to the function from all callers combined.' 443 print 444 print 'callee_x is the total number of times the function called this callee.' 445 print 'callee_y is the total number of calls to this callee from all functions in the program.' 446 print 447 print 'Profile data values of 0 are not displayed.'

448 449

450 - def _print_header(self):

451 print '<html><head><title>Shrapnel Profile</title></head><body bgcolor="#ffffff">' 452 print '<script type="text/javascript">' 455 print '</script>' 456 print '<h1>Shrapnel Profile Results</h1>' 457 print '<hr>'

458

459 - def _print_footer(self):

460 print '<hr>' 461 print 'Profile data collected at %s<br>' % (time.ctime(self.time),) 462 print 'Output generated at %s<br>' % (time.ctime(),) 463 print '</body></html>'

464

465 -def err(msg):

466 sys.stderr.write(msg + '\n') 467 sys.exit(1)

468

469 -def usage():

470 print 'Usage: print_profile.py profile_filename [other_profile]' 471 print 472 print ' print_profile.py filename -> Convert Profile data to HTML' 473 print ' print_profile.py filename1, filename2 -> Compare timings between profile results in file1 and file2' 474 print 475 print 'Output HTML is sent to stdout'

476

477 -def main(baseline, otherfile=None):

478 data = profile_data(baseline) 479 other_profile = {} 480 if otherfile: 481 data2 = profile_data(otherfile) 482 if data.bench_type != data2.bench_type: 483 print 'Cannot Compare. Bench types are different.' 484 return 485 other_profile = data2.profile_data 486 data.process(other_profile)

487 488 if __name__ == '__main__': 489 if len(sys.argv) not in (2, 3): 490 usage() 491 sys.exit(1) 492 493 baseline = sys.argv[1] 494 otherfile = sys.argv[2] if len(sys.argv) == 3 else None 495 main(baseline, otherfile) 496