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)