Linux kernel mirror (for testing) git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
kernel os linux

tools: power: pm-graph: AnalyzeBoot v2.0

First release into the kernel tools source
- pulls in analyze_suspend.py as as library, same html formatting
- supplants scripts/bootgraph.pl, outputs HTML instead of SVG
- enables automatic reboot and collection for easy timeline capture
- enables ftrace callgraph collection from early boot

Signed-off-by: Todd Brandt <todd.e.brandt@linux.intel.com>
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>

authored by

Todd E Brandt and committed by
Rafael J. Wysocki
c4980cee bc167c7d

+824
+824
tools/power/pm-graph/analyze_boot.py
··· 1 + #!/usr/bin/python 2 + # 3 + # Tool for analyzing boot timing 4 + # Copyright (c) 2013, Intel Corporation. 5 + # 6 + # This program is free software; you can redistribute it and/or modify it 7 + # under the terms and conditions of the GNU General Public License, 8 + # version 2, as published by the Free Software Foundation. 9 + # 10 + # This program is distributed in the hope it will be useful, but WITHOUT 11 + # ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or 12 + # FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for 13 + # more details. 14 + # 15 + # Authors: 16 + # Todd Brandt <todd.e.brandt@linux.intel.com> 17 + # 18 + # Description: 19 + # This tool is designed to assist kernel and OS developers in optimizing 20 + # their linux stack's boot time. It creates an html representation of 21 + # the kernel boot timeline up to the start of the init process. 22 + # 23 + 24 + # ----------------- LIBRARIES -------------------- 25 + 26 + import sys 27 + import time 28 + import os 29 + import string 30 + import re 31 + import platform 32 + import shutil 33 + from datetime import datetime, timedelta 34 + from subprocess import call, Popen, PIPE 35 + import analyze_suspend as aslib 36 + 37 + # ----------------- CLASSES -------------------- 38 + 39 + # Class: SystemValues 40 + # Description: 41 + # A global, single-instance container used to 42 + # store system values and test parameters 43 + class SystemValues(aslib.SystemValues): 44 + title = 'BootGraph' 45 + version = 2.0 46 + hostname = 'localhost' 47 + testtime = '' 48 + kernel = '' 49 + dmesgfile = '' 50 + ftracefile = '' 51 + htmlfile = 'bootgraph.html' 52 + outfile = '' 53 + phoronix = False 54 + addlogs = False 55 + useftrace = False 56 + usedevsrc = True 57 + suspendmode = 'boot' 58 + max_graph_depth = 2 59 + graph_filter = 'do_one_initcall' 60 + reboot = False 61 + manual = False 62 + iscronjob = False 63 + timeformat = '%.6f' 64 + def __init__(self): 65 + if('LOG_FILE' in os.environ and 'TEST_RESULTS_IDENTIFIER' in os.environ): 66 + self.phoronix = True 67 + self.addlogs = True 68 + self.outfile = os.environ['LOG_FILE'] 69 + self.htmlfile = os.environ['LOG_FILE'] 70 + self.hostname = platform.node() 71 + self.testtime = datetime.now().strftime('%Y-%m-%d_%H:%M:%S') 72 + if os.path.exists('/proc/version'): 73 + fp = open('/proc/version', 'r') 74 + val = fp.read().strip() 75 + fp.close() 76 + self.kernel = self.kernelVersion(val) 77 + else: 78 + self.kernel = 'unknown' 79 + def kernelVersion(self, msg): 80 + return msg.split()[2] 81 + def kernelParams(self): 82 + cmdline = 'initcall_debug log_buf_len=32M' 83 + if self.useftrace: 84 + cmdline += ' trace_buf_size=128M trace_clock=global '\ 85 + 'trace_options=nooverwrite,funcgraph-abstime,funcgraph-cpu,'\ 86 + 'funcgraph-duration,funcgraph-proc,funcgraph-tail,'\ 87 + 'nofuncgraph-overhead,context-info,graph-time '\ 88 + 'ftrace=function_graph '\ 89 + 'ftrace_graph_max_depth=%d '\ 90 + 'ftrace_graph_filter=%s' % \ 91 + (self.max_graph_depth, self.graph_filter) 92 + return cmdline 93 + def setGraphFilter(self, val): 94 + fp = open(self.tpath+'available_filter_functions') 95 + master = fp.read().split('\n') 96 + fp.close() 97 + for i in val.split(','): 98 + func = i.strip() 99 + if func not in master: 100 + doError('function "%s" not available for ftrace' % func) 101 + self.graph_filter = val 102 + def cronjobCmdString(self): 103 + cmdline = '%s -cronjob' % os.path.abspath(sys.argv[0]) 104 + args = iter(sys.argv[1:]) 105 + for arg in args: 106 + if arg in ['-h', '-v', '-cronjob', '-reboot']: 107 + continue 108 + elif arg in ['-o', '-dmesg', '-ftrace', '-filter']: 109 + args.next() 110 + continue 111 + cmdline += ' '+arg 112 + if self.graph_filter != 'do_one_initcall': 113 + cmdline += ' -filter "%s"' % self.graph_filter 114 + cmdline += ' -o "%s"' % os.path.abspath(self.htmlfile) 115 + return cmdline 116 + def manualRebootRequired(self): 117 + cmdline = self.kernelParams() 118 + print 'To generate a new timeline manually, follow these steps:\n' 119 + print '1. Add the CMDLINE string to your kernel command line.' 120 + print '2. Reboot the system.' 121 + print '3. After reboot, re-run this tool with the same arguments but no command (w/o -reboot or -manual).\n' 122 + print 'CMDLINE="%s"' % cmdline 123 + sys.exit() 124 + 125 + sysvals = SystemValues() 126 + 127 + # Class: Data 128 + # Description: 129 + # The primary container for test data. 130 + class Data(aslib.Data): 131 + dmesg = {} # root data structure 132 + start = 0.0 # test start 133 + end = 0.0 # test end 134 + dmesgtext = [] # dmesg text file in memory 135 + testnumber = 0 136 + idstr = '' 137 + html_device_id = 0 138 + valid = False 139 + initstart = 0.0 140 + boottime = '' 141 + phases = ['boot'] 142 + do_one_initcall = False 143 + def __init__(self, num): 144 + self.testnumber = num 145 + self.idstr = 'a' 146 + self.dmesgtext = [] 147 + self.dmesg = { 148 + 'boot': {'list': dict(), 'start': -1.0, 'end': -1.0, 'row': 0, 'color': '#dddddd'} 149 + } 150 + def deviceTopology(self): 151 + return '' 152 + def newAction(self, phase, name, start, end, ret, ulen): 153 + # new device callback for a specific phase 154 + self.html_device_id += 1 155 + devid = '%s%d' % (self.idstr, self.html_device_id) 156 + list = self.dmesg[phase]['list'] 157 + length = -1.0 158 + if(start >= 0 and end >= 0): 159 + length = end - start 160 + i = 2 161 + origname = name 162 + while(name in list): 163 + name = '%s[%d]' % (origname, i) 164 + i += 1 165 + list[name] = {'name': name, 'start': start, 'end': end, 166 + 'pid': 0, 'length': length, 'row': 0, 'id': devid, 167 + 'ret': ret, 'ulen': ulen } 168 + return name 169 + def deviceMatch(self, cg): 170 + if cg.end - cg.start == 0: 171 + return True 172 + list = self.dmesg['boot']['list'] 173 + for devname in list: 174 + dev = list[devname] 175 + if cg.name == 'do_one_initcall': 176 + if(cg.start <= dev['start'] and cg.end >= dev['end'] and dev['length'] > 0): 177 + dev['ftrace'] = cg 178 + self.do_one_initcall = True 179 + return True 180 + else: 181 + if(cg.start > dev['start'] and cg.end < dev['end']): 182 + if 'ftraces' not in dev: 183 + dev['ftraces'] = [] 184 + dev['ftraces'].append(cg) 185 + return True 186 + return False 187 + 188 + # ----------------- FUNCTIONS -------------------- 189 + 190 + # Function: loadKernelLog 191 + # Description: 192 + # Load a raw kernel log from dmesg 193 + def loadKernelLog(): 194 + data = Data(0) 195 + data.dmesg['boot']['start'] = data.start = ktime = 0.0 196 + sysvals.stamp = { 197 + 'time': datetime.now().strftime('%B %d %Y, %I:%M:%S %p'), 198 + 'host': sysvals.hostname, 199 + 'mode': 'boot', 'kernel': ''} 200 + 201 + devtemp = dict() 202 + if(sysvals.dmesgfile): 203 + lf = open(sysvals.dmesgfile, 'r') 204 + else: 205 + lf = Popen('dmesg', stdout=PIPE).stdout 206 + for line in lf: 207 + line = line.replace('\r\n', '') 208 + idx = line.find('[') 209 + if idx > 1: 210 + line = line[idx:] 211 + m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line) 212 + if(not m): 213 + continue 214 + ktime = float(m.group('ktime')) 215 + if(ktime > 120): 216 + break 217 + msg = m.group('msg') 218 + data.end = data.initstart = ktime 219 + data.dmesgtext.append(line) 220 + if(ktime == 0.0 and re.match('^Linux version .*', msg)): 221 + if(not sysvals.stamp['kernel']): 222 + sysvals.stamp['kernel'] = sysvals.kernelVersion(msg) 223 + continue 224 + m = re.match('.* setting system clock to (?P<t>.*) UTC.*', msg) 225 + if(m): 226 + bt = datetime.strptime(m.group('t'), '%Y-%m-%d %H:%M:%S') 227 + bt = bt - timedelta(seconds=int(ktime)) 228 + data.boottime = bt.strftime('%Y-%m-%d_%H:%M:%S') 229 + sysvals.stamp['time'] = bt.strftime('%B %d %Y, %I:%M:%S %p') 230 + continue 231 + m = re.match('^calling *(?P<f>.*)\+.*', msg) 232 + if(m): 233 + devtemp[m.group('f')] = ktime 234 + continue 235 + m = re.match('^initcall *(?P<f>.*)\+.* returned (?P<r>.*) after (?P<t>.*) usecs', msg) 236 + if(m): 237 + data.valid = True 238 + f, r, t = m.group('f', 'r', 't') 239 + if(f in devtemp): 240 + data.newAction('boot', f, devtemp[f], ktime, int(r), int(t)) 241 + data.end = ktime 242 + del devtemp[f] 243 + continue 244 + if(re.match('^Freeing unused kernel memory.*', msg)): 245 + break 246 + 247 + data.dmesg['boot']['end'] = data.end 248 + lf.close() 249 + return data 250 + 251 + # Function: loadTraceLog 252 + # Description: 253 + # Check if trace is available and copy to a temp file 254 + def loadTraceLog(data): 255 + # load the data to a temp file if none given 256 + if not sysvals.ftracefile: 257 + lib = aslib.sysvals 258 + aslib.rootCheck(True) 259 + if not lib.verifyFtrace(): 260 + doError('ftrace not available') 261 + if lib.fgetVal('current_tracer').strip() != 'function_graph': 262 + doError('ftrace not configured for a boot callgraph') 263 + sysvals.ftracefile = '/tmp/boot_ftrace.%s.txt' % os.getpid() 264 + call('cat '+lib.tpath+'trace > '+sysvals.ftracefile, shell=True) 265 + if not sysvals.ftracefile: 266 + doError('No trace data available') 267 + 268 + # parse the trace log 269 + ftemp = dict() 270 + tp = aslib.TestProps() 271 + tp.setTracerType('function_graph') 272 + tf = open(sysvals.ftracefile, 'r') 273 + for line in tf: 274 + if line[0] == '#': 275 + continue 276 + m = re.match(tp.ftrace_line_fmt, line.strip()) 277 + if(not m): 278 + continue 279 + m_time, m_proc, m_pid, m_msg, m_dur = \ 280 + m.group('time', 'proc', 'pid', 'msg', 'dur') 281 + if float(m_time) > data.end: 282 + break 283 + if(m_time and m_pid and m_msg): 284 + t = aslib.FTraceLine(m_time, m_msg, m_dur) 285 + pid = int(m_pid) 286 + else: 287 + continue 288 + if t.fevent or t.fkprobe: 289 + continue 290 + key = (m_proc, pid) 291 + if(key not in ftemp): 292 + ftemp[key] = [] 293 + ftemp[key].append(aslib.FTraceCallGraph(pid)) 294 + cg = ftemp[key][-1] 295 + if(cg.addLine(t)): 296 + ftemp[key].append(aslib.FTraceCallGraph(pid)) 297 + tf.close() 298 + 299 + # add the callgraph data to the device hierarchy 300 + for key in ftemp: 301 + proc, pid = key 302 + for cg in ftemp[key]: 303 + if len(cg.list) < 1 or cg.invalid: 304 + continue 305 + if(not cg.postProcess()): 306 + print('Sanity check failed for %s-%d' % (proc, pid)) 307 + continue 308 + # match cg data to devices 309 + if not data.deviceMatch(cg): 310 + print ' BAD: %s %s-%d [%f - %f]' % (cg.name, proc, pid, cg.start, cg.end) 311 + 312 + # Function: colorForName 313 + # Description: 314 + # Generate a repeatable color from a list for a given name 315 + def colorForName(name): 316 + list = [ 317 + ('c1', '#ec9999'), 318 + ('c2', '#ffc1a6'), 319 + ('c3', '#fff0a6'), 320 + ('c4', '#adf199'), 321 + ('c5', '#9fadea'), 322 + ('c6', '#a699c1'), 323 + ('c7', '#ad99b4'), 324 + ('c8', '#eaffea'), 325 + ('c9', '#dcecfb'), 326 + ('c10', '#ffffea') 327 + ] 328 + i = 0 329 + total = 0 330 + count = len(list) 331 + while i < len(name): 332 + total += ord(name[i]) 333 + i += 1 334 + return list[total % count] 335 + 336 + def cgOverview(cg, minlen): 337 + stats = dict() 338 + large = [] 339 + for l in cg.list: 340 + if l.fcall and l.depth == 1: 341 + if l.length >= minlen: 342 + large.append(l) 343 + if l.name not in stats: 344 + stats[l.name] = [0, 0.0] 345 + stats[l.name][0] += (l.length * 1000.0) 346 + stats[l.name][1] += 1 347 + return (large, stats) 348 + 349 + # Function: createBootGraph 350 + # Description: 351 + # Create the output html file from the resident test data 352 + # Arguments: 353 + # testruns: array of Data objects from parseKernelLog or parseTraceLog 354 + # Output: 355 + # True if the html file was created, false if it failed 356 + def createBootGraph(data, embedded): 357 + # html function templates 358 + html_srccall = '<div id={6} title="{5}" class="srccall" style="left:{1}%;top:{2}px;height:{3}px;width:{4}%;line-height:{3}px;">{0}</div>\n' 359 + html_timetotal = '<table class="time1">\n<tr>'\ 360 + '<td class="blue">Time from Kernel Boot to start of User Mode: <b>{0} ms</b></td>'\ 361 + '</tr>\n</table>\n' 362 + 363 + # device timeline 364 + devtl = aslib.Timeline(100, 20) 365 + 366 + # write the test title and general info header 367 + devtl.createHeader(sysvals, 'noftrace') 368 + 369 + # Generate the header for this timeline 370 + t0 = data.start 371 + tMax = data.end 372 + tTotal = tMax - t0 373 + if(tTotal == 0): 374 + print('ERROR: No timeline data') 375 + return False 376 + boot_time = '%.0f'%(tTotal*1000) 377 + devtl.html += html_timetotal.format(boot_time) 378 + 379 + # determine the maximum number of rows we need to draw 380 + phase = 'boot' 381 + list = data.dmesg[phase]['list'] 382 + devlist = [] 383 + for devname in list: 384 + d = aslib.DevItem(0, phase, list[devname]) 385 + devlist.append(d) 386 + devtl.getPhaseRows(devlist) 387 + devtl.calcTotalRows() 388 + 389 + # draw the timeline background 390 + devtl.createZoomBox() 391 + boot = data.dmesg[phase] 392 + length = boot['end']-boot['start'] 393 + left = '%.3f' % (((boot['start']-t0)*100.0)/tTotal) 394 + width = '%.3f' % ((length*100.0)/tTotal) 395 + devtl.html += devtl.html_tblock.format(phase, left, width, devtl.scaleH) 396 + devtl.html += devtl.html_phase.format('0', '100', \ 397 + '%.3f'%devtl.scaleH, '%.3f'%devtl.bodyH, \ 398 + 'white', '') 399 + 400 + # draw the device timeline 401 + num = 0 402 + devstats = dict() 403 + for devname in sorted(list): 404 + cls, color = colorForName(devname) 405 + dev = list[devname] 406 + info = '@|%.3f|%.3f|%.3f|%d' % (dev['start']*1000.0, dev['end']*1000.0, 407 + dev['ulen']/1000.0, dev['ret']) 408 + devstats[dev['id']] = {'info':info} 409 + dev['color'] = color 410 + height = devtl.phaseRowHeight(0, phase, dev['row']) 411 + top = '%.6f' % ((dev['row']*height) + devtl.scaleH) 412 + left = '%.6f' % (((dev['start']-t0)*100)/tTotal) 413 + width = '%.6f' % (((dev['end']-dev['start'])*100)/tTotal) 414 + length = ' (%0.3f ms) ' % ((dev['end']-dev['start'])*1000) 415 + devtl.html += devtl.html_device.format(dev['id'], 416 + devname+length+'kernel_mode', left, top, '%.3f'%height, 417 + width, devname, ' '+cls, '') 418 + rowtop = devtl.phaseRowTop(0, phase, dev['row']) 419 + height = '%.6f' % (devtl.rowH / 2) 420 + top = '%.6f' % (rowtop + devtl.scaleH + (devtl.rowH / 2)) 421 + if data.do_one_initcall: 422 + if('ftrace' not in dev): 423 + continue 424 + cg = dev['ftrace'] 425 + large, stats = cgOverview(cg, 0.001) 426 + devstats[dev['id']]['fstat'] = stats 427 + for l in large: 428 + left = '%f' % (((l.time-t0)*100)/tTotal) 429 + width = '%f' % (l.length*100/tTotal) 430 + title = '%s (%0.3fms)' % (l.name, l.length * 1000.0) 431 + devtl.html += html_srccall.format(l.name, left, 432 + top, height, width, title, 'x%d'%num) 433 + num += 1 434 + continue 435 + if('ftraces' not in dev): 436 + continue 437 + for cg in dev['ftraces']: 438 + left = '%f' % (((cg.start-t0)*100)/tTotal) 439 + width = '%f' % ((cg.end-cg.start)*100/tTotal) 440 + cglen = (cg.end - cg.start) * 1000.0 441 + title = '%s (%0.3fms)' % (cg.name, cglen) 442 + cg.id = 'x%d' % num 443 + devtl.html += html_srccall.format(cg.name, left, 444 + top, height, width, title, dev['id']+cg.id) 445 + num += 1 446 + 447 + # draw the time scale, try to make the number of labels readable 448 + devtl.createTimeScale(t0, tMax, tTotal, phase) 449 + devtl.html += '</div>\n' 450 + 451 + # timeline is finished 452 + devtl.html += '</div>\n</div>\n' 453 + 454 + if(sysvals.outfile == sysvals.htmlfile): 455 + hf = open(sysvals.htmlfile, 'a') 456 + else: 457 + hf = open(sysvals.htmlfile, 'w') 458 + 459 + # add the css if this is not an embedded run 460 + extra = '\ 461 + .c1 {background:rgba(209,0,0,0.4);}\n\ 462 + .c2 {background:rgba(255,102,34,0.4);}\n\ 463 + .c3 {background:rgba(255,218,33,0.4);}\n\ 464 + .c4 {background:rgba(51,221,0,0.4);}\n\ 465 + .c5 {background:rgba(17,51,204,0.4);}\n\ 466 + .c6 {background:rgba(34,0,102,0.4);}\n\ 467 + .c7 {background:rgba(51,0,68,0.4);}\n\ 468 + .c8 {background:rgba(204,255,204,0.4);}\n\ 469 + .c9 {background:rgba(169,208,245,0.4);}\n\ 470 + .c10 {background:rgba(255,255,204,0.4);}\n\ 471 + .vt {transform:rotate(-60deg);transform-origin:0 0;}\n\ 472 + table.fstat {table-layout:fixed;padding:150px 15px 0 0;font-size:10px;column-width:30px;}\n\ 473 + .fstat th {width:55px;}\n\ 474 + .fstat td {text-align:left;width:35px;}\n\ 475 + .srccall {position:absolute;font-size:10px;z-index:7;overflow:hidden;color:black;text-align:center;white-space:nowrap;border-radius:5px;border:1px solid black;background:linear-gradient(to bottom right,#CCC,#969696);}\n\ 476 + .srccall:hover {color:white;font-weight:bold;border:1px solid white;}\n' 477 + if(not embedded): 478 + aslib.addCSS(hf, sysvals, 1, False, extra) 479 + 480 + # write the device timeline 481 + hf.write(devtl.html) 482 + 483 + # add boot specific html 484 + statinfo = 'var devstats = {\n' 485 + for n in sorted(devstats): 486 + statinfo += '\t"%s": [\n\t\t"%s",\n' % (n, devstats[n]['info']) 487 + if 'fstat' in devstats[n]: 488 + funcs = devstats[n]['fstat'] 489 + for f in sorted(funcs, key=funcs.get, reverse=True): 490 + if funcs[f][0] < 0.01 and len(funcs) > 10: 491 + break 492 + statinfo += '\t\t"%f|%s|%d",\n' % (funcs[f][0], f, funcs[f][1]) 493 + statinfo += '\t],\n' 494 + statinfo += '};\n' 495 + html = \ 496 + '<div id="devicedetailtitle"></div>\n'\ 497 + '<div id="devicedetail" style="display:none;">\n'\ 498 + '<div id="devicedetail0">\n'\ 499 + '<div id="kernel_mode" class="phaselet" style="left:0%;width:100%;background:#DDDDDD"></div>\n'\ 500 + '</div>\n</div>\n'\ 501 + '<script type="text/javascript">\n'+statinfo+\ 502 + '</script>\n' 503 + hf.write(html) 504 + 505 + # add the callgraph html 506 + if(sysvals.usecallgraph): 507 + aslib.addCallgraphs(sysvals, hf, data) 508 + 509 + # add the dmesg log as a hidden div 510 + if sysvals.addlogs: 511 + hf.write('<div id="dmesglog" style="display:none;">\n') 512 + for line in data.dmesgtext: 513 + line = line.replace('<', '&lt').replace('>', '&gt') 514 + hf.write(line) 515 + hf.write('</div>\n') 516 + 517 + if(not embedded): 518 + # write the footer and close 519 + aslib.addScriptCode(hf, [data]) 520 + hf.write('</body>\n</html>\n') 521 + else: 522 + # embedded out will be loaded in a page, skip the js 523 + hf.write('<div id=bounds style=display:none>%f,%f</div>' % \ 524 + (data.start*1000, data.initstart*1000)) 525 + hf.close() 526 + return True 527 + 528 + # Function: updateCron 529 + # Description: 530 + # (restore=False) Set the tool to run automatically on reboot 531 + # (restore=True) Restore the original crontab 532 + def updateCron(restore=False): 533 + if not restore: 534 + sysvals.rootUser(True) 535 + crondir = '/var/spool/cron/crontabs/' 536 + cronfile = crondir+'root' 537 + backfile = crondir+'root-analyze_boot-backup' 538 + if not os.path.exists(crondir): 539 + doError('%s not found' % crondir) 540 + out = Popen(['which', 'crontab'], stdout=PIPE).stdout.read() 541 + if not out: 542 + doError('crontab not found') 543 + # on restore: move the backup cron back into place 544 + if restore: 545 + if os.path.exists(backfile): 546 + shutil.move(backfile, cronfile) 547 + return 548 + # backup current cron and install new one with reboot 549 + if os.path.exists(cronfile): 550 + shutil.move(cronfile, backfile) 551 + else: 552 + fp = open(backfile, 'w') 553 + fp.close() 554 + res = -1 555 + try: 556 + fp = open(backfile, 'r') 557 + op = open(cronfile, 'w') 558 + for line in fp: 559 + if '@reboot' not in line: 560 + op.write(line) 561 + continue 562 + fp.close() 563 + op.write('@reboot python %s\n' % sysvals.cronjobCmdString()) 564 + op.close() 565 + res = call('crontab %s' % cronfile, shell=True) 566 + except Exception, e: 567 + print 'Exception: %s' % str(e) 568 + shutil.move(backfile, cronfile) 569 + res = -1 570 + if res != 0: 571 + doError('crontab failed') 572 + 573 + # Function: updateGrub 574 + # Description: 575 + # update grub.cfg for all kernels with our parameters 576 + def updateGrub(restore=False): 577 + # call update-grub on restore 578 + if restore: 579 + try: 580 + call(['update-grub'], stderr=PIPE, stdout=PIPE, 581 + env={'PATH': '.:/sbin:/usr/sbin:/usr/bin:/sbin:/bin'}) 582 + except Exception, e: 583 + print 'Exception: %s\n' % str(e) 584 + return 585 + # verify we can do this 586 + sysvals.rootUser(True) 587 + grubfile = '/etc/default/grub' 588 + if not os.path.exists(grubfile): 589 + print 'ERROR: Unable to set the kernel parameters via grub.\n' 590 + sysvals.manualRebootRequired() 591 + out = Popen(['which', 'update-grub'], stdout=PIPE).stdout.read() 592 + if not out: 593 + print 'ERROR: Unable to set the kernel parameters via grub.\n' 594 + sysvals.manualRebootRequired() 595 + 596 + # extract the option and create a grub config without it 597 + tgtopt = 'GRUB_CMDLINE_LINUX_DEFAULT' 598 + cmdline = '' 599 + tempfile = '/etc/default/grub.analyze_boot' 600 + shutil.move(grubfile, tempfile) 601 + res = -1 602 + try: 603 + fp = open(tempfile, 'r') 604 + op = open(grubfile, 'w') 605 + cont = False 606 + for line in fp: 607 + line = line.strip() 608 + if len(line) == 0 or line[0] == '#': 609 + continue 610 + opt = line.split('=')[0].strip() 611 + if opt == tgtopt: 612 + cmdline = line.split('=', 1)[1].strip('\\') 613 + if line[-1] == '\\': 614 + cont = True 615 + elif cont: 616 + cmdline += line.strip('\\') 617 + if line[-1] != '\\': 618 + cont = False 619 + else: 620 + op.write('%s\n' % line) 621 + fp.close() 622 + # if the target option value is in quotes, strip them 623 + sp = '"' 624 + val = cmdline.strip() 625 + if val[0] == '\'' or val[0] == '"': 626 + sp = val[0] 627 + val = val.strip(sp) 628 + cmdline = val 629 + # append our cmd line options 630 + if len(cmdline) > 0: 631 + cmdline += ' ' 632 + cmdline += sysvals.kernelParams() 633 + # write out the updated target option 634 + op.write('\n%s=%s%s%s\n' % (tgtopt, sp, cmdline, sp)) 635 + op.close() 636 + res = call('update-grub') 637 + os.remove(grubfile) 638 + except Exception, e: 639 + print 'Exception: %s' % str(e) 640 + res = -1 641 + # cleanup 642 + shutil.move(tempfile, grubfile) 643 + if res != 0: 644 + doError('update-grub failed') 645 + 646 + # Function: doError 647 + # Description: 648 + # generic error function for catastrphic failures 649 + # Arguments: 650 + # msg: the error message to print 651 + # help: True if printHelp should be called after, False otherwise 652 + def doError(msg, help=False): 653 + if help == True: 654 + printHelp() 655 + print 'ERROR: %s\n' % msg 656 + sys.exit() 657 + 658 + # Function: printHelp 659 + # Description: 660 + # print out the help text 661 + def printHelp(): 662 + print('') 663 + print('%s v%.1f' % (sysvals.title, sysvals.version)) 664 + print('Usage: bootgraph <options> <command>') 665 + print('') 666 + print('Description:') 667 + print(' This tool reads in a dmesg log of linux kernel boot and') 668 + print(' creates an html representation of the boot timeline up to') 669 + print(' the start of the init process.') 670 + print('') 671 + print(' If no specific command is given the tool reads the current dmesg') 672 + print(' and/or ftrace log and outputs bootgraph.html') 673 + print('') 674 + print('Options:') 675 + print(' -h Print this help text') 676 + print(' -v Print the current tool version') 677 + print(' -addlogs Add the dmesg log to the html output') 678 + print(' -o file Html timeline name (default: bootgraph.html)') 679 + print(' [advanced]') 680 + print(' -f Use ftrace to add function detail (default: disabled)') 681 + print(' -callgraph Add callgraph detail, can be very large (default: disabled)') 682 + print(' -maxdepth N limit the callgraph data to N call levels (default: 2)') 683 + print(' -mincg ms Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)') 684 + print(' -timeprec N Number of significant digits in timestamps (0:S, 3:ms, [6:us])') 685 + print(' -expandcg pre-expand the callgraph data in the html output (default: disabled)') 686 + print(' -filter list Limit ftrace to comma-delimited list of functions (default: do_one_initcall)') 687 + print(' [commands]') 688 + print(' -reboot Reboot the machine automatically and generate a new timeline') 689 + print(' -manual Show the requirements to generate a new timeline manually') 690 + print(' -dmesg file Load a stored dmesg file (used with -ftrace)') 691 + print(' -ftrace file Load a stored ftrace file (used with -dmesg)') 692 + print(' -flistall Print all functions capable of being captured in ftrace') 693 + print('') 694 + return True 695 + 696 + # ----------------- MAIN -------------------- 697 + # exec start (skipped if script is loaded as library) 698 + if __name__ == '__main__': 699 + # loop through the command line arguments 700 + cmd = '' 701 + simplecmds = ['-updategrub', '-flistall'] 702 + args = iter(sys.argv[1:]) 703 + for arg in args: 704 + if(arg == '-h'): 705 + printHelp() 706 + sys.exit() 707 + elif(arg == '-v'): 708 + print("Version %.1f" % sysvals.version) 709 + sys.exit() 710 + elif(arg in simplecmds): 711 + cmd = arg[1:] 712 + elif(arg == '-f'): 713 + sysvals.useftrace = True 714 + elif(arg == '-callgraph'): 715 + sysvals.useftrace = True 716 + sysvals.usecallgraph = True 717 + elif(arg == '-mincg'): 718 + sysvals.mincglen = aslib.getArgFloat('-mincg', args, 0.0, 10000.0) 719 + elif(arg == '-timeprec'): 720 + sysvals.setPrecision(aslib.getArgInt('-timeprec', args, 0, 6)) 721 + elif(arg == '-maxdepth'): 722 + sysvals.max_graph_depth = aslib.getArgInt('-maxdepth', args, 0, 1000) 723 + elif(arg == '-filter'): 724 + try: 725 + val = args.next() 726 + except: 727 + doError('No filter functions supplied', True) 728 + aslib.rootCheck(True) 729 + sysvals.setGraphFilter(val) 730 + elif(arg == '-ftrace'): 731 + try: 732 + val = args.next() 733 + except: 734 + doError('No ftrace file supplied', True) 735 + if(os.path.exists(val) == False): 736 + doError('%s does not exist' % val) 737 + sysvals.ftracefile = val 738 + elif(arg == '-addlogs'): 739 + sysvals.addlogs = True 740 + elif(arg == '-expandcg'): 741 + sysvals.cgexp = True 742 + elif(arg == '-dmesg'): 743 + try: 744 + val = args.next() 745 + except: 746 + doError('No dmesg file supplied', True) 747 + if(os.path.exists(val) == False): 748 + doError('%s does not exist' % val) 749 + if(sysvals.htmlfile == val or sysvals.outfile == val): 750 + doError('Output filename collision') 751 + sysvals.dmesgfile = val 752 + elif(arg == '-o'): 753 + try: 754 + val = args.next() 755 + except: 756 + doError('No HTML filename supplied', True) 757 + if(sysvals.dmesgfile == val or sysvals.ftracefile == val): 758 + doError('Output filename collision') 759 + sysvals.htmlfile = val 760 + elif(arg == '-reboot'): 761 + if sysvals.iscronjob: 762 + doError('-reboot and -cronjob are incompatible') 763 + sysvals.reboot = True 764 + elif(arg == '-manual'): 765 + sysvals.reboot = True 766 + sysvals.manual = True 767 + # remaining options are only for cron job use 768 + elif(arg == '-cronjob'): 769 + sysvals.iscronjob = True 770 + if sysvals.reboot: 771 + doError('-reboot and -cronjob are incompatible') 772 + else: 773 + doError('Invalid argument: '+arg, True) 774 + 775 + if cmd != '': 776 + if cmd == 'updategrub': 777 + updateGrub() 778 + elif cmd == 'flistall': 779 + sysvals.getFtraceFilterFunctions(False) 780 + sys.exit() 781 + 782 + # update grub, setup a cronjob, and reboot 783 + if sysvals.reboot: 784 + if not sysvals.manual: 785 + updateGrub() 786 + updateCron() 787 + call('reboot') 788 + else: 789 + sysvals.manualRebootRequired() 790 + sys.exit() 791 + 792 + # disable the cronjob 793 + if sysvals.iscronjob: 794 + updateCron(True) 795 + updateGrub(True) 796 + 797 + data = loadKernelLog() 798 + if sysvals.useftrace: 799 + loadTraceLog(data) 800 + if sysvals.iscronjob: 801 + try: 802 + sysvals.fsetVal('0', 'tracing_on') 803 + except: 804 + pass 805 + 806 + if(sysvals.outfile and sysvals.phoronix): 807 + fp = open(sysvals.outfile, 'w') 808 + fp.write('pass %s initstart %.3f end %.3f boot %s\n' % 809 + (data.valid, data.initstart*1000, data.end*1000, data.boottime)) 810 + fp.close() 811 + if(not data.valid): 812 + if sysvals.dmesgfile: 813 + doError('No initcall data found in %s' % sysvals.dmesgfile) 814 + else: 815 + doError('No initcall data found, is initcall_debug enabled?') 816 + 817 + print(' Host: %s' % sysvals.hostname) 818 + print(' Test time: %s' % sysvals.testtime) 819 + print(' Boot time: %s' % data.boottime) 820 + print('Kernel Version: %s' % sysvals.kernel) 821 + print(' Kernel start: %.3f' % (data.start * 1000)) 822 + print(' init start: %.3f' % (data.initstart * 1000)) 823 + 824 + createBootGraph(data, sysvals.phoronix)