2 # SPDX-License-Identifier: GPL-2.0-only
4 # Tool for analyzing boot timing
5 # Copyright (c) 2013, Intel Corporation.
7 # This program is free software; you can redistribute it and/or modify it
8 # under the terms and conditions of the GNU General Public License,
9 # version 2, as published by the Free Software Foundation.
11 # This program is distributed in the hope it will be useful, but WITHOUT
12 # ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
13 # FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for
17 # Todd Brandt <todd.e.brandt@linux.intel.com>
20 # This tool is designed to assist kernel and OS developers in optimizing
21 # their linux stack's boot time. It creates an html representation of
22 # the kernel boot timeline up to the start of the init process.
25 # ----------------- LIBRARIES --------------------
34 from datetime import datetime, timedelta
35 from subprocess import call, Popen, PIPE
36 import sleepgraph as aslib
42 # ----------------- CLASSES --------------------
46 # A global, single-instance container used to
47 # store system values and test parameters
48 class SystemValues(aslib.SystemValues):
51 hostname = 'localhost'
56 htmlfile = 'bootgraph.html'
64 graph_filter = 'do_one_initcall'
72 self.kernel, self.hostname = 'unknown', platform.node()
73 self.testtime = datetime.now().strftime('%Y-%m-%d_%H:%M:%S')
74 if os.path.exists('/proc/version'):
75 fp = open('/proc/version', 'r')
76 self.kernel = self.kernelVersion(fp.read().strip())
78 self.testdir = datetime.now().strftime('boot-%y%m%d-%H%M%S')
79 def kernelVersion(self, msg):
80 m = re.match('^[Ll]inux *[Vv]ersion *(?P<v>\S*) .*', msg)
84 def checkFtraceKernelVersion(self):
85 m = re.match('^(?P<x>[0-9]*)\.(?P<y>[0-9]*)\.(?P<z>[0-9]*).*', self.kernel)
87 val = tuple(map(int, m.groups()))
91 def kernelParams(self):
92 cmdline = 'initcall_debug log_buf_len=32M'
95 bs = min(self.memtotal // 2, 2*1024*1024) // self.cpucount
98 cmdline += ' trace_buf_size=%dK trace_clock=global '\
99 'trace_options=nooverwrite,funcgraph-abstime,funcgraph-cpu,'\
100 'funcgraph-duration,funcgraph-proc,funcgraph-tail,'\
101 'nofuncgraph-overhead,context-info,graph-time '\
102 'ftrace=function_graph '\
103 'ftrace_graph_max_depth=%d '\
104 'ftrace_graph_filter=%s' % \
105 (bs, self.max_graph_depth, self.graph_filter)
107 def setGraphFilter(self, val):
108 master = self.getBootFtraceFilterFunctions()
110 for i in val.split(','):
113 doError('badly formatted filter function string')
114 if '[' in func or ']' in func:
115 doError('loadable module functions not allowed - "%s"' % func)
117 doError('spaces found in filter functions - "%s"' % func)
118 if func not in master:
119 doError('function "%s" not available for ftrace' % func)
125 doError('badly formatted filter function string')
126 self.graph_filter = fs
127 def getBootFtraceFilterFunctions(self):
129 fp = open(self.tpath+'available_filter_functions')
130 fulllist = fp.read().split('\n')
134 if not i or ' ' in i or '[' in i or ']' in i:
138 def myCronJob(self, line):
139 if '@reboot' not in line:
141 if 'bootgraph' in line or 'analyze_boot.py' in line or '-cronjob' in line:
144 def cronjobCmdString(self):
145 cmdline = '%s -cronjob' % os.path.abspath(sys.argv[0])
146 args = iter(sys.argv[1:])
148 if arg in ['-h', '-v', '-cronjob', '-reboot', '-verbose']:
150 elif arg in ['-o', '-dmesg', '-ftrace', '-func']:
153 elif arg == '-result':
154 cmdline += ' %s "%s"' % (arg, os.path.abspath(next(args)))
156 elif arg == '-cgskip':
157 file = self.configFile(next(args))
158 cmdline += ' %s "%s"' % (arg, os.path.abspath(file))
161 if self.graph_filter != 'do_one_initcall':
162 cmdline += ' -func "%s"' % self.graph_filter
163 cmdline += ' -o "%s"' % os.path.abspath(self.testdir)
165 def manualRebootRequired(self):
166 cmdline = self.kernelParams()
167 pprint('To generate a new timeline manually, follow these steps:\n\n'\
168 '1. Add the CMDLINE string to your kernel command line.\n'\
169 '2. Reboot the system.\n'\
170 '3. After reboot, re-run this tool with the same arguments but no command (w/o -reboot or -manual).\n\n'\
171 'CMDLINE="%s"' % cmdline)
175 for cmd in ['update-grub', 'grub-mkconfig', 'grub2-mkconfig']:
178 blcmd = self.getExec(cmd)
180 doError('[GRUB] missing update command')
181 if not os.path.exists('/etc/default/grub'):
182 doError('[GRUB] missing /etc/default/grub')
184 cfg = '/boot/grub2/grub.cfg'
186 cfg = '/boot/grub/grub.cfg'
187 if not os.path.exists(cfg):
188 doError('[GRUB] missing %s' % cfg)
189 if 'update-grub' in blcmd:
190 self.blexec = [blcmd]
192 self.blexec = [blcmd, '-o', cfg]
193 def getBootLoader(self):
194 if self.bootloader == 'grub':
197 doError('unknown boot loader: %s' % self.bootloader)
198 def writeDatafileHeader(self, filename):
199 self.kparams = open('/proc/cmdline', 'r').read().strip()
200 fp = open(filename, 'w')
201 fp.write(self.teststamp+'\n')
202 fp.write(self.sysstamp+'\n')
203 fp.write('# command | %s\n' % self.cmdline)
204 fp.write('# kparams | %s\n' % self.kparams)
207 sysvals = SystemValues()
211 # The primary container for test data.
212 class Data(aslib.Data):
213 dmesg = {} # root data structure
214 start = 0.0 # test start
216 dmesgtext = [] # dmesg text file in memory
223 phases = ['kernel', 'user']
224 do_one_initcall = False
225 def __init__(self, num):
226 self.testnumber = num
230 'kernel': {'list': dict(), 'start': -1.0, 'end': -1.0, 'row': 0,
231 'order': 0, 'color': 'linear-gradient(to bottom, #fff, #bcf)'},
232 'user': {'list': dict(), 'start': -1.0, 'end': -1.0, 'row': 0,
233 'order': 1, 'color': '#fff'}
235 def deviceTopology(self):
237 def newAction(self, phase, name, pid, start, end, ret, ulen):
238 # new device callback for a specific phase
239 self.html_device_id += 1
240 devid = '%s%d' % (self.idstr, self.html_device_id)
241 list = self.dmesg[phase]['list']
243 if(start >= 0 and end >= 0):
248 name = '%s[%d]' % (origname, i)
250 list[name] = {'name': name, 'start': start, 'end': end,
251 'pid': pid, 'length': length, 'row': 0, 'id': devid,
252 'ret': ret, 'ulen': ulen }
254 def deviceMatch(self, pid, cg):
255 if cg.end - cg.start == 0:
257 for p in data.phases:
258 list = self.dmesg[p]['list']
261 if pid != dev['pid']:
263 if cg.name == 'do_one_initcall':
264 if(cg.start <= dev['start'] and cg.end >= dev['end'] and dev['length'] > 0):
266 self.do_one_initcall = True
269 if(cg.start > dev['start'] and cg.end < dev['end']):
270 if 'ftraces' not in dev:
272 dev['ftraces'].append(cg)
275 def printDetails(self):
276 sysvals.vprint('Timeline Details:')
277 sysvals.vprint(' Host: %s' % sysvals.hostname)
278 sysvals.vprint(' Kernel: %s' % sysvals.kernel)
279 sysvals.vprint(' Test time: %s' % sysvals.testtime)
280 sysvals.vprint(' Boot time: %s' % self.boottime)
281 for phase in self.phases:
282 dc = len(self.dmesg[phase]['list'])
283 sysvals.vprint('%9s mode: %.3f - %.3f (%d initcalls)' % (phase,
284 self.dmesg[phase]['start']*1000,
285 self.dmesg[phase]['end']*1000, dc))
287 # ----------------- FUNCTIONS --------------------
289 # Function: parseKernelLog
291 # parse a kernel log for boot data
292 def parseKernelLog():
293 sysvals.vprint('Analyzing the dmesg data (%s)...' % \
294 os.path.basename(sysvals.dmesgfile))
297 data.dmesg['kernel']['start'] = data.start = ktime = 0.0
299 'time': datetime.now().strftime('%B %d %Y, %I:%M:%S %p'),
300 'host': sysvals.hostname,
301 'mode': 'boot', 'kernel': ''}
303 tp = aslib.TestProps()
305 if(sysvals.dmesgfile):
306 lf = open(sysvals.dmesgfile, 'rb')
308 lf = Popen('dmesg', stdout=PIPE).stdout
310 line = aslib.ascii(line).replace('\r\n', '')
311 # grab the stamp and sysinfo
312 if re.match(tp.stampfmt, line):
315 elif re.match(tp.sysinfofmt, line):
318 elif re.match(tp.cmdlinefmt, line):
321 elif re.match(tp.kparamsfmt, line):
327 m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line)
330 ktime = float(m.group('ktime'))
334 data.dmesgtext.append(line)
335 if(ktime == 0.0 and re.match('^Linux version .*', msg)):
336 if(not sysvals.stamp['kernel']):
337 sysvals.stamp['kernel'] = sysvals.kernelVersion(msg)
339 m = re.match('.* setting system clock to (?P<d>[0-9\-]*)[ A-Z](?P<t>[0-9:]*) UTC.*', msg)
341 bt = datetime.strptime(m.group('d')+' '+m.group('t'), '%Y-%m-%d %H:%M:%S')
342 bt = bt - timedelta(seconds=int(ktime))
343 data.boottime = bt.strftime('%Y-%m-%d_%H:%M:%S')
344 sysvals.stamp['time'] = bt.strftime('%B %d %Y, %I:%M:%S %p')
346 m = re.match('^calling *(?P<f>.*)\+.* @ (?P<p>[0-9]*)', msg)
349 pid = int(m.group('p'))
350 devtemp[func] = (ktime, pid)
352 m = re.match('^initcall *(?P<f>.*)\+.* returned (?P<r>.*) after (?P<t>.*) usecs', msg)
356 f, r, t = m.group('f', 'r', 't')
358 start, pid = devtemp[f]
359 data.newAction(phase, f, pid, start, ktime, int(r), int(t))
362 if(re.match('^Freeing unused kernel .*', msg)):
363 data.tUserMode = ktime
364 data.dmesg['kernel']['end'] = ktime
365 data.dmesg['user']['start'] = ktime
370 tp.parseStamp(data, sysvals)
371 data.dmesg['user']['end'] = data.end
375 # Function: parseTraceLog
377 # Check if trace is available and copy to a temp file
378 def parseTraceLog(data):
379 sysvals.vprint('Analyzing the ftrace data (%s)...' % \
380 os.path.basename(sysvals.ftracefile))
381 # if available, calculate cgfilter allowable ranges
383 if len(sysvals.cgfilter) > 0:
384 for p in data.phases:
385 list = data.dmesg[p]['list']
386 for i in sysvals.cgfilter:
388 cgfilter.append([list[i]['start']-0.0001,
389 list[i]['end']+0.0001])
390 # parse the trace log
392 tp = aslib.TestProps()
393 tp.setTracerType('function_graph')
394 tf = open(sysvals.ftracefile, 'r')
398 m = re.match(tp.ftrace_line_fmt, line.strip())
401 m_time, m_proc, m_pid, m_msg, m_dur = \
402 m.group('time', 'proc', 'pid', 'msg', 'dur')
404 if len(cgfilter) > 0:
407 if t >= r[0] and t < r[1]:
414 if(m_time and m_pid and m_msg):
415 t = aslib.FTraceLine(m_time, m_msg, m_dur)
419 if t.fevent or t.fkprobe:
422 if(key not in ftemp):
424 ftemp[key].append(aslib.FTraceCallGraph(pid, sysvals))
428 ftemp[key].append(aslib.FTraceCallGraph(pid, sysvals))
430 ftemp[key][-1].addLine(t)
434 # add the callgraph data to the device hierarchy
437 for cg in ftemp[key]:
438 if len(cg.list) < 1 or cg.invalid or (cg.end - cg.start == 0):
440 if(not cg.postProcess()):
441 pprint('Sanity check failed for %s-%d' % (proc, pid))
443 # match cg data to devices
444 devname = data.deviceMatch(pid, cg)
449 sysvals.vprint('%s callgraph found for %s %s-%d [%f - %f]' %\
450 (kind, cg.name, proc, pid, cg.start, cg.end))
451 elif len(cg.list) > 1000000:
452 pprint('WARNING: the callgraph found for %s is massive! (%d lines)' %\
453 (devname, len(cg.list)))
455 # Function: retrieveLogs
457 # Create copies of dmesg and/or ftrace for later processing
459 # check ftrace is configured first
460 if sysvals.useftrace:
461 tracer = sysvals.fgetVal('current_tracer').strip()
462 if tracer != 'function_graph':
463 doError('ftrace not configured for a boot callgraph')
464 # create the folder and get dmesg
465 sysvals.systemInfo(aslib.dmidecode(sysvals.mempath))
466 sysvals.initTestOutput('boot')
467 sysvals.writeDatafileHeader(sysvals.dmesgfile)
468 call('dmesg >> '+sysvals.dmesgfile, shell=True)
469 if not sysvals.useftrace:
472 sysvals.writeDatafileHeader(sysvals.ftracefile)
473 call('cat '+sysvals.tpath+'trace >> '+sysvals.ftracefile, shell=True)
475 # Function: colorForName
477 # Generate a repeatable color from a list for a given name
478 def colorForName(name):
495 total += ord(name[i])
497 return list[total % count]
499 def cgOverview(cg, minlen):
503 if l.fcall and l.depth == 1:
504 if l.length >= minlen:
506 if l.name not in stats:
507 stats[l.name] = [0, 0.0]
508 stats[l.name][0] += (l.length * 1000.0)
509 stats[l.name][1] += 1
510 return (large, stats)
512 # Function: createBootGraph
514 # Create the output html file from the resident test data
516 # testruns: array of Data objects from parseKernelLog or parseTraceLog
518 # True if the html file was created, false if it failed
519 def createBootGraph(data):
520 # html function templates
521 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'
522 html_timetotal = '<table class="time1">\n<tr>'\
523 '<td class="blue">Init process starts @ <b>{0} ms</b></td>'\
524 '<td class="blue">Last initcall ends @ <b>{1} ms</b></td>'\
528 devtl = aslib.Timeline(100, 20)
530 # write the test title and general info header
531 devtl.createHeader(sysvals, sysvals.stamp)
533 # Generate the header for this timeline
538 pprint('ERROR: No timeline data')
540 user_mode = '%.0f'%(data.tUserMode*1000)
541 last_init = '%.0f'%(tTotal*1000)
542 devtl.html += html_timetotal.format(user_mode, last_init)
544 # determine the maximum number of rows we need to draw
546 for p in data.phases:
547 list = data.dmesg[p]['list']
549 d = aslib.DevItem(0, p, list[devname])
551 devtl.getPhaseRows(devlist, 0, 'start')
552 devtl.calcTotalRows()
554 # draw the timeline background
555 devtl.createZoomBox()
556 devtl.html += devtl.html_tblock.format('boot', '0', '100', devtl.scaleH)
557 for p in data.phases:
558 phase = data.dmesg[p]
559 length = phase['end']-phase['start']
560 left = '%.3f' % (((phase['start']-t0)*100.0)/tTotal)
561 width = '%.3f' % ((length*100.0)/tTotal)
562 devtl.html += devtl.html_phase.format(left, width, \
563 '%.3f'%devtl.scaleH, '%.3f'%devtl.bodyH, \
566 # draw the device timeline
569 for phase in data.phases:
570 list = data.dmesg[phase]['list']
571 for devname in sorted(list):
572 cls, color = colorForName(devname)
574 info = '@|%.3f|%.3f|%.3f|%d' % (dev['start']*1000.0, dev['end']*1000.0,
575 dev['ulen']/1000.0, dev['ret'])
576 devstats[dev['id']] = {'info':info}
578 height = devtl.phaseRowHeight(0, phase, dev['row'])
579 top = '%.6f' % ((dev['row']*height) + devtl.scaleH)
580 left = '%.6f' % (((dev['start']-t0)*100)/tTotal)
581 width = '%.6f' % (((dev['end']-dev['start'])*100)/tTotal)
582 length = ' (%0.3f ms) ' % ((dev['end']-dev['start'])*1000)
583 devtl.html += devtl.html_device.format(dev['id'],
584 devname+length+phase+'_mode', left, top, '%.3f'%height,
585 width, devname, ' '+cls, '')
586 rowtop = devtl.phaseRowTop(0, phase, dev['row'])
587 height = '%.6f' % (devtl.rowH / 2)
588 top = '%.6f' % (rowtop + devtl.scaleH + (devtl.rowH / 2))
589 if data.do_one_initcall:
590 if('ftrace' not in dev):
593 large, stats = cgOverview(cg, 0.001)
594 devstats[dev['id']]['fstat'] = stats
596 left = '%f' % (((l.time-t0)*100)/tTotal)
597 width = '%f' % (l.length*100/tTotal)
598 title = '%s (%0.3fms)' % (l.name, l.length * 1000.0)
599 devtl.html += html_srccall.format(l.name, left,
600 top, height, width, title, 'x%d'%num)
603 if('ftraces' not in dev):
605 for cg in dev['ftraces']:
606 left = '%f' % (((cg.start-t0)*100)/tTotal)
607 width = '%f' % ((cg.end-cg.start)*100/tTotal)
608 cglen = (cg.end - cg.start) * 1000.0
609 title = '%s (%0.3fms)' % (cg.name, cglen)
611 devtl.html += html_srccall.format(cg.name, left,
612 top, height, width, title, dev['id']+cg.id)
615 # draw the time scale, try to make the number of labels readable
616 devtl.createTimeScale(t0, tMax, tTotal, 'boot')
617 devtl.html += '</div>\n'
619 # timeline is finished
620 devtl.html += '</div>\n</div>\n'
622 # draw a legend which describes the phases by color
623 devtl.html += '<div class="legend">\n'
626 for phase in data.phases:
627 order = '%.2f' % ((data.dmesg[phase]['order'] * pdelta) + pmargin)
628 devtl.html += devtl.html_legend.format(order, \
629 data.dmesg[phase]['color'], phase+'_mode', phase[0])
630 devtl.html += '</div>\n'
632 hf = open(sysvals.htmlfile, 'w')
636 .c1 {background:rgba(209,0,0,0.4);}\n\
637 .c2 {background:rgba(255,102,34,0.4);}\n\
638 .c3 {background:rgba(255,218,33,0.4);}\n\
639 .c4 {background:rgba(51,221,0,0.4);}\n\
640 .c5 {background:rgba(17,51,204,0.4);}\n\
641 .c6 {background:rgba(34,0,102,0.4);}\n\
642 .c7 {background:rgba(51,0,68,0.4);}\n\
643 .c8 {background:rgba(204,255,204,0.4);}\n\
644 .c9 {background:rgba(169,208,245,0.4);}\n\
645 .c10 {background:rgba(255,255,204,0.4);}\n\
646 .vt {transform:rotate(-60deg);transform-origin:0 0;}\n\
647 table.fstat {table-layout:fixed;padding:150px 15px 0 0;font-size:10px;column-width:30px;}\n\
648 .fstat th {width:55px;}\n\
649 .fstat td {text-align:left;width:35px;}\n\
650 .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\
651 .srccall:hover {color:white;font-weight:bold;border:1px solid white;}\n'
652 aslib.addCSS(hf, sysvals, 1, False, extra)
654 # write the device timeline
657 # add boot specific html
658 statinfo = 'var devstats = {\n'
659 for n in sorted(devstats):
660 statinfo += '\t"%s": [\n\t\t"%s",\n' % (n, devstats[n]['info'])
661 if 'fstat' in devstats[n]:
662 funcs = devstats[n]['fstat']
663 for f in sorted(funcs, key=lambda k:(funcs[k], k), reverse=True):
664 if funcs[f][0] < 0.01 and len(funcs) > 10:
666 statinfo += '\t\t"%f|%s|%d",\n' % (funcs[f][0], f, funcs[f][1])
670 '<div id="devicedetailtitle"></div>\n'\
671 '<div id="devicedetail" style="display:none;">\n'\
672 '<div id="devicedetail0">\n'
673 for p in data.phases:
674 phase = data.dmesg[p]
675 html += devtl.html_phaselet.format(p+'_mode', '0', '100', phase['color'])
676 html += '</div>\n</div>\n'\
677 '<script type="text/javascript">\n'+statinfo+\
681 # add the callgraph html
682 if(sysvals.usecallgraph):
683 aslib.addCallgraphs(sysvals, hf, data)
685 # add the test log as a hidden div
686 if sysvals.testlog and sysvals.logmsg:
687 hf.write('<div id="testlog" style="display:none;">\n'+sysvals.logmsg+'</div>\n')
688 # add the dmesg log as a hidden div
690 hf.write('<div id="dmesglog" style="display:none;">\n')
691 for line in data.dmesgtext:
692 line = line.replace('<', '<').replace('>', '>')
696 # write the footer and close
697 aslib.addScriptCode(hf, [data])
698 hf.write('</body>\n</html>\n')
702 # Function: updateCron
704 # (restore=False) Set the tool to run automatically on reboot
705 # (restore=True) Restore the original crontab
706 def updateCron(restore=False):
708 sysvals.rootUser(True)
709 crondir = '/var/spool/cron/crontabs/'
710 if not os.path.exists(crondir):
711 crondir = '/var/spool/cron/'
712 if not os.path.exists(crondir):
713 doError('%s not found' % crondir)
714 cronfile = crondir+'root'
715 backfile = crondir+'root-analyze_boot-backup'
716 cmd = sysvals.getExec('crontab')
718 doError('crontab not found')
719 # on restore: move the backup cron back into place
721 if os.path.exists(backfile):
722 shutil.move(backfile, cronfile)
723 call([cmd, cronfile])
725 # backup current cron and install new one with reboot
726 if os.path.exists(cronfile):
727 shutil.move(cronfile, backfile)
729 fp = open(backfile, 'w')
733 fp = open(backfile, 'r')
734 op = open(cronfile, 'w')
736 if not sysvals.myCronJob(line):
740 op.write('@reboot python %s\n' % sysvals.cronjobCmdString())
742 res = call([cmd, cronfile])
743 except Exception as e:
744 pprint('Exception: %s' % str(e))
745 shutil.move(backfile, cronfile)
748 doError('crontab failed')
750 # Function: updateGrub
752 # update grub.cfg for all kernels with our parameters
753 def updateGrub(restore=False):
754 # call update-grub on restore
757 call(sysvals.blexec, stderr=PIPE, stdout=PIPE,
758 env={'PATH': '.:/sbin:/usr/sbin:/usr/bin:/sbin:/bin'})
759 except Exception as e:
760 pprint('Exception: %s\n' % str(e))
762 # extract the option and create a grub config without it
763 sysvals.rootUser(True)
764 tgtopt = 'GRUB_CMDLINE_LINUX_DEFAULT'
766 grubfile = '/etc/default/grub'
767 tempfile = '/etc/default/grub.analyze_boot'
768 shutil.move(grubfile, tempfile)
771 fp = open(tempfile, 'r')
772 op = open(grubfile, 'w')
776 if len(line) == 0 or line[0] == '#':
778 opt = line.split('=')[0].strip()
780 cmdline = line.split('=', 1)[1].strip('\\')
784 cmdline += line.strip('\\')
788 op.write('%s\n' % line)
790 # if the target option value is in quotes, strip them
792 val = cmdline.strip()
793 if val and (val[0] == '\'' or val[0] == '"'):
797 # append our cmd line options
800 cmdline += sysvals.kernelParams()
801 # write out the updated target option
802 op.write('\n%s=%s%s%s\n' % (tgtopt, sp, cmdline, sp))
804 res = call(sysvals.blexec)
806 except Exception as e:
807 pprint('Exception: %s' % str(e))
810 shutil.move(tempfile, grubfile)
812 doError('update grub failed')
814 # Function: updateKernelParams
816 # update boot conf for all kernels with our parameters
817 def updateKernelParams(restore=False):
818 # find the boot loader
819 sysvals.getBootLoader()
820 if sysvals.bootloader == 'grub':
823 # Function: doError Description:
824 # generic error function for catastrphic failures
826 # msg: the error message to print
827 # help: True if printHelp should be called after, False otherwise
828 def doError(msg, help=False):
831 pprint('ERROR: %s\n' % msg)
832 sysvals.outputResult({'error':msg})
835 # Function: printHelp
837 # print out the help text
840 'Usage: bootgraph <options> <command>\n'\
843 ' This tool reads in a dmesg log of linux kernel boot and\n'\
844 ' creates an html representation of the boot timeline up to\n'\
845 ' the start of the init process.\n'\
847 ' If no specific command is given the tool reads the current dmesg\n'\
848 ' and/or ftrace log and creates a timeline\n'\
850 ' Generates output files in subdirectory: boot-yymmdd-HHMMSS\n'\
851 ' HTML output: <hostname>_boot.html\n'\
852 ' raw dmesg output: <hostname>_boot_dmesg.txt\n'\
853 ' raw ftrace output: <hostname>_boot_ftrace.txt\n'\
856 ' -h Print this help text\n'\
857 ' -v Print the current tool version\n'\
858 ' -verbose Print extra information during execution and analysis\n'\
859 ' -addlogs Add the dmesg log to the html output\n'\
860 ' -result fn Export a results table to a text file for parsing.\n'\
861 ' -o name Overrides the output subdirectory name when running a new test\n'\
862 ' default: boot-{date}-{time}\n'\
864 ' -fstat Use ftrace to add function detail and statistics (default: disabled)\n'\
865 ' -f/-callgraph Add callgraph detail, can be very large (default: disabled)\n'\
866 ' -maxdepth N limit the callgraph data to N call levels (default: 2)\n'\
867 ' -mincg ms Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)\n'\
868 ' -timeprec N Number of significant digits in timestamps (0:S, 3:ms, [6:us])\n'\
869 ' -expandcg pre-expand the callgraph data in the html output (default: disabled)\n'\
870 ' -func list Limit ftrace to comma-delimited list of functions (default: do_one_initcall)\n'\
871 ' -cgfilter S Filter the callgraph output in the timeline\n'\
872 ' -cgskip file Callgraph functions to skip, off to disable (default: cgskip.txt)\n'\
873 ' -bl name Use the following boot loader for kernel params (default: grub)\n'\
874 ' -reboot Reboot the machine automatically and generate a new timeline\n'\
875 ' -manual Show the steps to generate a new timeline manually (used with -reboot)\n'\
878 ' -flistall Print all functions capable of being captured in ftrace\n'\
879 ' -sysinfo Print out system info extracted from BIOS\n'\
880 ' -which exec Print an executable path, should function even without PATH\n'\
882 ' -dmesg file Create HTML output using dmesg input (used with -ftrace)\n'\
883 ' -ftrace file Create HTML output using ftrace input (used with -dmesg)\n'\
884 '' % (sysvals.title, sysvals.version))
887 # ----------------- MAIN --------------------
888 # exec start (skipped if script is loaded as library)
889 if __name__ == '__main__':
890 # loop through the command line arguments
893 switchoff = ['disable', 'off', 'false', '0']
894 simplecmds = ['-sysinfo', '-kpupdate', '-flistall', '-checkbl']
897 cgskip = sysvals.configFile('cgskip.txt')
898 args = iter(sys.argv[1:])
905 pprint("Version %s" % sysvals.version)
907 elif(arg == '-verbose'):
908 sysvals.verbose = True
909 elif(arg in simplecmds):
911 elif(arg == '-fstat'):
912 sysvals.useftrace = True
913 elif(arg == '-callgraph' or arg == '-f'):
914 sysvals.useftrace = True
915 sysvals.usecallgraph = True
916 elif(arg == '-cgdump'):
917 sysvals.cgdump = True
918 elif(arg == '-mincg'):
919 sysvals.mincglen = aslib.getArgFloat('-mincg', args, 0.0, 10000.0)
920 elif(arg == '-cgfilter'):
924 doError('No callgraph functions supplied', True)
925 sysvals.setCallgraphFilter(val)
926 elif(arg == '-cgskip'):
930 doError('No file supplied', True)
931 if val.lower() in switchoff:
934 cgskip = sysvals.configFile(val)
936 doError('%s does not exist' % cgskip)
941 doError('No boot loader name supplied', True)
942 if val.lower() not in ['grub']:
943 doError('Unknown boot loader: %s' % val, True)
944 sysvals.bootloader = val.lower()
945 elif(arg == '-timeprec'):
946 sysvals.setPrecision(aslib.getArgInt('-timeprec', args, 0, 6))
947 elif(arg == '-maxdepth'):
949 sysvals.max_graph_depth = aslib.getArgInt('-maxdepth', args, 0, 1000)
950 elif(arg == '-func'):
954 doError('No filter functions supplied', True)
955 sysvals.useftrace = True
956 sysvals.usecallgraph = True
957 sysvals.rootCheck(True)
958 sysvals.setGraphFilter(val)
959 elif(arg == '-ftrace'):
963 doError('No ftrace file supplied', True)
964 if(os.path.exists(val) == False):
965 doError('%s does not exist' % val)
967 sysvals.ftracefile = val
968 elif(arg == '-addlogs'):
969 sysvals.dmesglog = True
970 elif(arg == '-expandcg'):
972 elif(arg == '-dmesg'):
976 doError('No dmesg file supplied', True)
977 if(os.path.exists(val) == False):
978 doError('%s does not exist' % val)
980 sysvals.dmesgfile = val
985 doError('No subdirectory name supplied', True)
986 sysvals.testdir = sysvals.setOutputFolder(val)
987 elif(arg == '-result'):
991 doError('No result file supplied', True)
993 elif(arg == '-reboot'):
994 sysvals.reboot = True
995 elif(arg == '-manual'):
996 sysvals.reboot = True
997 sysvals.manual = True
998 # remaining options are only for cron job use
999 elif(arg == '-cronjob'):
1000 sysvals.iscronjob = True
1001 elif(arg == '-which'):
1005 doError('No executable supplied', True)
1006 out = sysvals.getExec(val)
1008 print('%s not found' % val)
1013 doError('Invalid argument: '+arg, True)
1015 # compatibility errors and access checks
1016 if(sysvals.iscronjob and (sysvals.reboot or \
1017 sysvals.dmesgfile or sysvals.ftracefile or cmd)):
1018 doError('-cronjob is meant for batch purposes only')
1019 if(sysvals.reboot and (sysvals.dmesgfile or sysvals.ftracefile)):
1020 doError('-reboot and -dmesg/-ftrace are incompatible')
1021 if cmd or sysvals.reboot or sysvals.iscronjob or testrun:
1022 sysvals.rootCheck(True)
1023 if (testrun and sysvals.useftrace) or cmd == 'flistall':
1024 if not sysvals.verifyFtrace():
1025 doError('Ftrace is not properly enabled')
1027 # run utility commands
1030 if cmd == 'kpupdate':
1031 updateKernelParams()
1032 elif cmd == 'flistall':
1033 for f in sysvals.getBootFtraceFilterFunctions():
1035 elif cmd == 'checkbl':
1036 sysvals.getBootLoader()
1037 pprint('Boot Loader: %s\n%s' % (sysvals.bootloader, sysvals.blexec))
1038 elif(cmd == 'sysinfo'):
1039 sysvals.printSystemInfo(True)
1042 # reboot: update grub, setup a cronjob, and reboot
1044 if (sysvals.useftrace or sysvals.usecallgraph) and \
1045 not sysvals.checkFtraceKernelVersion():
1046 doError('Ftrace functionality requires kernel v4.10 or newer')
1047 if not sysvals.manual:
1048 updateKernelParams()
1052 sysvals.manualRebootRequired()
1055 if sysvals.usecallgraph and cgskip:
1056 sysvals.vprint('Using cgskip file: %s' % cgskip)
1057 sysvals.setCallgraphBlacklist(cgskip)
1059 # cronjob: remove the cronjob, grub changes, and disable ftrace
1060 if sysvals.iscronjob:
1062 updateKernelParams(True)
1064 sysvals.fsetVal('0', 'tracing_on')
1068 # testrun: generate copies of the logs
1072 sysvals.setOutputFile()
1074 # process the log data
1075 if sysvals.dmesgfile:
1077 sysvals.max_graph_depth = 0
1078 data = parseKernelLog()
1080 doError('No initcall data found in %s' % sysvals.dmesgfile)
1081 if sysvals.useftrace and sysvals.ftracefile:
1087 doError('dmesg file required')
1089 sysvals.vprint('Creating the html timeline (%s)...' % sysvals.htmlfile)
1090 sysvals.vprint('Command:\n %s' % sysvals.cmdline)
1091 sysvals.vprint('Kernel parameters:\n %s' % sysvals.kparams)
1093 createBootGraph(data)
1095 # if running as root, change output dir owner to sudo_user
1096 if testrun and os.path.isdir(sysvals.testdir) and \
1097 os.getuid() == 0 and 'SUDO_USER' in os.environ:
1098 cmd = 'chown -R {0}:{0} {1} > /dev/null 2>&1'
1099 call(cmd.format(os.environ['SUDO_USER'], sysvals.testdir), shell=True)
1101 sysvals.stamp['boot'] = (data.tUserMode - data.start) * 1000
1102 sysvals.stamp['lastinit'] = data.end * 1000
1103 sysvals.outputResult(sysvals.stamp)