2 # SPDX-License-Identifier: GPL-2.0-only
4 # Tool for analyzing boot timing
5 # Copyright (c) 2013, Intel Corporation.
11 # This tool is designed to assist kernel and OS developers in optimizing
12 # their linux stack's boot time. It creates an html representation of
13 # the kernel boot timeline up to the start of the init process.
16 # ----------------- LIBRARIES --------------------
25 from datetime import datetime, timedelta
26 from subprocess import call, Popen, PIPE
27 import sleepgraph as aslib
33 # ----------------- CLASSES --------------------
37 # A global, single-instance container used to
38 # store system values and test parameters
39 class SystemValues(aslib.SystemValues):
42 hostname = 'localhost'
47 htmlfile = 'bootgraph.html'
55 graph_filter = 'do_one_initcall'
63 self.hostname = platform.node()
64 self.testtime = datetime.now().strftime('%Y-%m-%d_%H:%M:%S')
65 if os.path.exists('/proc/version'):
66 fp = open('/proc/version', 'r')
67 val = fp.read().strip()
69 self.kernel = self.kernelVersion(val)
71 self.kernel = 'unknown'
72 self.testdir = datetime.now().strftime('boot-%y%m%d-%H%M%S')
73 def kernelVersion(self, msg):
75 def checkFtraceKernelVersion(self):
76 val = tuple(map(int, self.kernel.split('-')[0].split('.')))
80 def kernelParams(self):
81 cmdline = 'initcall_debug log_buf_len=32M'
84 bs = min(self.memtotal / 2, 2*1024*1024) / self.cpucount
87 cmdline += ' trace_buf_size=%dK trace_clock=global '\
88 'trace_options=nooverwrite,funcgraph-abstime,funcgraph-cpu,'\
89 'funcgraph-duration,funcgraph-proc,funcgraph-tail,'\
90 'nofuncgraph-overhead,context-info,graph-time '\
91 'ftrace=function_graph '\
92 'ftrace_graph_max_depth=%d '\
93 'ftrace_graph_filter=%s' % \
94 (bs, self.max_graph_depth, self.graph_filter)
96 def setGraphFilter(self, val):
97 master = self.getBootFtraceFilterFunctions()
99 for i in val.split(','):
102 doError('badly formatted filter function string')
103 if '[' in func or ']' in func:
104 doError('loadable module functions not allowed - "%s"' % func)
106 doError('spaces found in filter functions - "%s"' % func)
107 if func not in master:
108 doError('function "%s" not available for ftrace' % func)
114 doError('badly formatted filter function string')
115 self.graph_filter = fs
116 def getBootFtraceFilterFunctions(self):
118 fp = open(self.tpath+'available_filter_functions')
119 fulllist = fp.read().split('\n')
123 if not i or ' ' in i or '[' in i or ']' in i:
127 def myCronJob(self, line):
128 if '@reboot' not in line:
130 if 'bootgraph' in line or 'analyze_boot.py' in line or '-cronjob' in line:
133 def cronjobCmdString(self):
134 cmdline = '%s -cronjob' % os.path.abspath(sys.argv[0])
135 args = iter(sys.argv[1:])
137 if arg in ['-h', '-v', '-cronjob', '-reboot', '-verbose']:
139 elif arg in ['-o', '-dmesg', '-ftrace', '-func']:
142 elif arg == '-result':
143 cmdline += ' %s "%s"' % (arg, os.path.abspath(args.next()))
145 elif arg == '-cgskip':
146 file = self.configFile(args.next())
147 cmdline += ' %s "%s"' % (arg, os.path.abspath(file))
150 if self.graph_filter != 'do_one_initcall':
151 cmdline += ' -func "%s"' % self.graph_filter
152 cmdline += ' -o "%s"' % os.path.abspath(self.testdir)
154 def manualRebootRequired(self):
155 cmdline = self.kernelParams()
156 pprint('To generate a new timeline manually, follow these steps:\n\n'\
157 '1. Add the CMDLINE string to your kernel command line.\n'\
158 '2. Reboot the system.\n'\
159 '3. After reboot, re-run this tool with the same arguments but no command (w/o -reboot or -manual).\n\n'\
160 'CMDLINE="%s"' % cmdline)
164 for cmd in ['update-grub', 'grub-mkconfig', 'grub2-mkconfig']:
167 blcmd = self.getExec(cmd)
169 doError('[GRUB] missing update command')
170 if not os.path.exists('/etc/default/grub'):
171 doError('[GRUB] missing /etc/default/grub')
173 cfg = '/boot/grub2/grub.cfg'
175 cfg = '/boot/grub/grub.cfg'
176 if not os.path.exists(cfg):
177 doError('[GRUB] missing %s' % cfg)
178 if 'update-grub' in blcmd:
179 self.blexec = [blcmd]
181 self.blexec = [blcmd, '-o', cfg]
182 def getBootLoader(self):
183 if self.bootloader == 'grub':
186 doError('unknown boot loader: %s' % self.bootloader)
187 def writeDatafileHeader(self, filename):
188 self.kparams = open('/proc/cmdline', 'r').read().strip()
189 fp = open(filename, 'w')
190 fp.write(self.teststamp+'\n')
191 fp.write(self.sysstamp+'\n')
192 fp.write('# command | %s\n' % self.cmdline)
193 fp.write('# kparams | %s\n' % self.kparams)
196 sysvals = SystemValues()
200 # The primary container for test data.
201 class Data(aslib.Data):
202 dmesg = {} # root data structure
203 start = 0.0 # test start
205 dmesgtext = [] # dmesg text file in memory
212 phases = ['kernel', 'user']
213 do_one_initcall = False
214 def __init__(self, num):
215 self.testnumber = num
219 'kernel': {'list': dict(), 'start': -1.0, 'end': -1.0, 'row': 0,
220 'order': 0, 'color': 'linear-gradient(to bottom, #fff, #bcf)'},
221 'user': {'list': dict(), 'start': -1.0, 'end': -1.0, 'row': 0,
222 'order': 1, 'color': '#fff'}
224 def deviceTopology(self):
226 def newAction(self, phase, name, pid, start, end, ret, ulen):
227 # new device callback for a specific phase
228 self.html_device_id += 1
229 devid = '%s%d' % (self.idstr, self.html_device_id)
230 list = self.dmesg[phase]['list']
232 if(start >= 0 and end >= 0):
237 name = '%s[%d]' % (origname, i)
239 list[name] = {'name': name, 'start': start, 'end': end,
240 'pid': pid, 'length': length, 'row': 0, 'id': devid,
241 'ret': ret, 'ulen': ulen }
243 def deviceMatch(self, pid, cg):
244 if cg.end - cg.start == 0:
246 for p in data.phases:
247 list = self.dmesg[p]['list']
250 if pid != dev['pid']:
252 if cg.name == 'do_one_initcall':
253 if(cg.start <= dev['start'] and cg.end >= dev['end'] and dev['length'] > 0):
255 self.do_one_initcall = True
258 if(cg.start > dev['start'] and cg.end < dev['end']):
259 if 'ftraces' not in dev:
261 dev['ftraces'].append(cg)
264 def printDetails(self):
265 sysvals.vprint('Timeline Details:')
266 sysvals.vprint(' Host: %s' % sysvals.hostname)
267 sysvals.vprint(' Kernel: %s' % sysvals.kernel)
268 sysvals.vprint(' Test time: %s' % sysvals.testtime)
269 sysvals.vprint(' Boot time: %s' % self.boottime)
270 for phase in self.phases:
271 dc = len(self.dmesg[phase]['list'])
272 sysvals.vprint('%9s mode: %.3f - %.3f (%d initcalls)' % (phase,
273 self.dmesg[phase]['start']*1000,
274 self.dmesg[phase]['end']*1000, dc))
276 # ----------------- FUNCTIONS --------------------
278 # Function: parseKernelLog
280 # parse a kernel log for boot data
281 def parseKernelLog():
282 sysvals.vprint('Analyzing the dmesg data (%s)...' % \
283 os.path.basename(sysvals.dmesgfile))
286 data.dmesg['kernel']['start'] = data.start = ktime = 0.0
288 'time': datetime.now().strftime('%B %d %Y, %I:%M:%S %p'),
289 'host': sysvals.hostname,
290 'mode': 'boot', 'kernel': ''}
292 tp = aslib.TestProps()
294 if(sysvals.dmesgfile):
295 lf = open(sysvals.dmesgfile, 'r')
297 lf = Popen('dmesg', stdout=PIPE).stdout
299 line = line.replace('\r\n', '')
300 # grab the stamp and sysinfo
301 if re.match(tp.stampfmt, line):
304 elif re.match(tp.sysinfofmt, line):
307 elif re.match(tp.cmdlinefmt, line):
310 elif re.match(tp.kparamsfmt, line):
316 m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line)
319 ktime = float(m.group('ktime'))
323 data.dmesgtext.append(line)
324 if(ktime == 0.0 and re.match('^Linux version .*', msg)):
325 if(not sysvals.stamp['kernel']):
326 sysvals.stamp['kernel'] = sysvals.kernelVersion(msg)
328 m = re.match('.* setting system clock to (?P<t>.*) UTC.*', msg)
330 bt = datetime.strptime(m.group('t'), '%Y-%m-%d %H:%M:%S')
331 bt = bt - timedelta(seconds=int(ktime))
332 data.boottime = bt.strftime('%Y-%m-%d_%H:%M:%S')
333 sysvals.stamp['time'] = bt.strftime('%B %d %Y, %I:%M:%S %p')
335 m = re.match('^calling *(?P<f>.*)\+.* @ (?P<p>[0-9]*)', msg)
338 pid = int(m.group('p'))
339 devtemp[func] = (ktime, pid)
341 m = re.match('^initcall *(?P<f>.*)\+.* returned (?P<r>.*) after (?P<t>.*) usecs', msg)
345 f, r, t = m.group('f', 'r', 't')
347 start, pid = devtemp[f]
348 data.newAction(phase, f, pid, start, ktime, int(r), int(t))
351 if(re.match('^Freeing unused kernel memory.*', msg)):
352 data.tUserMode = ktime
353 data.dmesg['kernel']['end'] = ktime
354 data.dmesg['user']['start'] = ktime
359 tp.parseStamp(data, sysvals)
360 data.dmesg['user']['end'] = data.end
364 # Function: parseTraceLog
366 # Check if trace is available and copy to a temp file
367 def parseTraceLog(data):
368 sysvals.vprint('Analyzing the ftrace data (%s)...' % \
369 os.path.basename(sysvals.ftracefile))
370 # if available, calculate cgfilter allowable ranges
372 if len(sysvals.cgfilter) > 0:
373 for p in data.phases:
374 list = data.dmesg[p]['list']
375 for i in sysvals.cgfilter:
377 cgfilter.append([list[i]['start']-0.0001,
378 list[i]['end']+0.0001])
379 # parse the trace log
381 tp = aslib.TestProps()
382 tp.setTracerType('function_graph')
383 tf = open(sysvals.ftracefile, 'r')
387 m = re.match(tp.ftrace_line_fmt, line.strip())
390 m_time, m_proc, m_pid, m_msg, m_dur = \
391 m.group('time', 'proc', 'pid', 'msg', 'dur')
393 if len(cgfilter) > 0:
396 if t >= r[0] and t < r[1]:
403 if(m_time and m_pid and m_msg):
404 t = aslib.FTraceLine(m_time, m_msg, m_dur)
408 if t.fevent or t.fkprobe:
411 if(key not in ftemp):
413 ftemp[key].append(aslib.FTraceCallGraph(pid, sysvals))
417 ftemp[key].append(aslib.FTraceCallGraph(pid, sysvals))
419 ftemp[key][-1].addLine(t)
423 # add the callgraph data to the device hierarchy
426 for cg in ftemp[key]:
427 if len(cg.list) < 1 or cg.invalid or (cg.end - cg.start == 0):
429 if(not cg.postProcess()):
430 pprint('Sanity check failed for %s-%d' % (proc, pid))
432 # match cg data to devices
433 devname = data.deviceMatch(pid, cg)
438 sysvals.vprint('%s callgraph found for %s %s-%d [%f - %f]' %\
439 (kind, cg.name, proc, pid, cg.start, cg.end))
440 elif len(cg.list) > 1000000:
441 pprint('WARNING: the callgraph found for %s is massive! (%d lines)' %\
442 (devname, len(cg.list)))
444 # Function: retrieveLogs
446 # Create copies of dmesg and/or ftrace for later processing
448 # check ftrace is configured first
449 if sysvals.useftrace:
450 tracer = sysvals.fgetVal('current_tracer').strip()
451 if tracer != 'function_graph':
452 doError('ftrace not configured for a boot callgraph')
453 # create the folder and get dmesg
454 sysvals.systemInfo(aslib.dmidecode(sysvals.mempath))
455 sysvals.initTestOutput('boot')
456 sysvals.writeDatafileHeader(sysvals.dmesgfile)
457 call('dmesg >> '+sysvals.dmesgfile, shell=True)
458 if not sysvals.useftrace:
461 sysvals.writeDatafileHeader(sysvals.ftracefile)
462 call('cat '+sysvals.tpath+'trace >> '+sysvals.ftracefile, shell=True)
464 # Function: colorForName
466 # Generate a repeatable color from a list for a given name
467 def colorForName(name):
484 total += ord(name[i])
486 return list[total % count]
488 def cgOverview(cg, minlen):
492 if l.fcall and l.depth == 1:
493 if l.length >= minlen:
495 if l.name not in stats:
496 stats[l.name] = [0, 0.0]
497 stats[l.name][0] += (l.length * 1000.0)
498 stats[l.name][1] += 1
499 return (large, stats)
501 # Function: createBootGraph
503 # Create the output html file from the resident test data
505 # testruns: array of Data objects from parseKernelLog or parseTraceLog
507 # True if the html file was created, false if it failed
508 def createBootGraph(data):
509 # html function templates
510 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'
511 html_timetotal = '<table class="time1">\n<tr>'\
512 '<td class="blue">Init process starts @ <b>{0} ms</b></td>'\
513 '<td class="blue">Last initcall ends @ <b>{1} ms</b></td>'\
517 devtl = aslib.Timeline(100, 20)
519 # write the test title and general info header
520 devtl.createHeader(sysvals, sysvals.stamp)
522 # Generate the header for this timeline
527 pprint('ERROR: No timeline data')
529 user_mode = '%.0f'%(data.tUserMode*1000)
530 last_init = '%.0f'%(tTotal*1000)
531 devtl.html += html_timetotal.format(user_mode, last_init)
533 # determine the maximum number of rows we need to draw
535 for p in data.phases:
536 list = data.dmesg[p]['list']
538 d = aslib.DevItem(0, p, list[devname])
540 devtl.getPhaseRows(devlist, 0, 'start')
541 devtl.calcTotalRows()
543 # draw the timeline background
544 devtl.createZoomBox()
545 devtl.html += devtl.html_tblock.format('boot', '0', '100', devtl.scaleH)
546 for p in data.phases:
547 phase = data.dmesg[p]
548 length = phase['end']-phase['start']
549 left = '%.3f' % (((phase['start']-t0)*100.0)/tTotal)
550 width = '%.3f' % ((length*100.0)/tTotal)
551 devtl.html += devtl.html_phase.format(left, width, \
552 '%.3f'%devtl.scaleH, '%.3f'%devtl.bodyH, \
555 # draw the device timeline
558 for phase in data.phases:
559 list = data.dmesg[phase]['list']
560 for devname in sorted(list):
561 cls, color = colorForName(devname)
563 info = '@|%.3f|%.3f|%.3f|%d' % (dev['start']*1000.0, dev['end']*1000.0,
564 dev['ulen']/1000.0, dev['ret'])
565 devstats[dev['id']] = {'info':info}
567 height = devtl.phaseRowHeight(0, phase, dev['row'])
568 top = '%.6f' % ((dev['row']*height) + devtl.scaleH)
569 left = '%.6f' % (((dev['start']-t0)*100)/tTotal)
570 width = '%.6f' % (((dev['end']-dev['start'])*100)/tTotal)
571 length = ' (%0.3f ms) ' % ((dev['end']-dev['start'])*1000)
572 devtl.html += devtl.html_device.format(dev['id'],
573 devname+length+phase+'_mode', left, top, '%.3f'%height,
574 width, devname, ' '+cls, '')
575 rowtop = devtl.phaseRowTop(0, phase, dev['row'])
576 height = '%.6f' % (devtl.rowH / 2)
577 top = '%.6f' % (rowtop + devtl.scaleH + (devtl.rowH / 2))
578 if data.do_one_initcall:
579 if('ftrace' not in dev):
582 large, stats = cgOverview(cg, 0.001)
583 devstats[dev['id']]['fstat'] = stats
585 left = '%f' % (((l.time-t0)*100)/tTotal)
586 width = '%f' % (l.length*100/tTotal)
587 title = '%s (%0.3fms)' % (l.name, l.length * 1000.0)
588 devtl.html += html_srccall.format(l.name, left,
589 top, height, width, title, 'x%d'%num)
592 if('ftraces' not in dev):
594 for cg in dev['ftraces']:
595 left = '%f' % (((cg.start-t0)*100)/tTotal)
596 width = '%f' % ((cg.end-cg.start)*100/tTotal)
597 cglen = (cg.end - cg.start) * 1000.0
598 title = '%s (%0.3fms)' % (cg.name, cglen)
600 devtl.html += html_srccall.format(cg.name, left,
601 top, height, width, title, dev['id']+cg.id)
604 # draw the time scale, try to make the number of labels readable
605 devtl.createTimeScale(t0, tMax, tTotal, 'boot')
606 devtl.html += '</div>\n'
608 # timeline is finished
609 devtl.html += '</div>\n</div>\n'
611 # draw a legend which describes the phases by color
612 devtl.html += '<div class="legend">\n'
615 for phase in data.phases:
616 order = '%.2f' % ((data.dmesg[phase]['order'] * pdelta) + pmargin)
617 devtl.html += devtl.html_legend.format(order, \
618 data.dmesg[phase]['color'], phase+'_mode', phase[0])
619 devtl.html += '</div>\n'
621 hf = open(sysvals.htmlfile, 'w')
625 .c1 {background:rgba(209,0,0,0.4);}\n\
626 .c2 {background:rgba(255,102,34,0.4);}\n\
627 .c3 {background:rgba(255,218,33,0.4);}\n\
628 .c4 {background:rgba(51,221,0,0.4);}\n\
629 .c5 {background:rgba(17,51,204,0.4);}\n\
630 .c6 {background:rgba(34,0,102,0.4);}\n\
631 .c7 {background:rgba(51,0,68,0.4);}\n\
632 .c8 {background:rgba(204,255,204,0.4);}\n\
633 .c9 {background:rgba(169,208,245,0.4);}\n\
634 .c10 {background:rgba(255,255,204,0.4);}\n\
635 .vt {transform:rotate(-60deg);transform-origin:0 0;}\n\
636 table.fstat {table-layout:fixed;padding:150px 15px 0 0;font-size:10px;column-width:30px;}\n\
637 .fstat th {width:55px;}\n\
638 .fstat td {text-align:left;width:35px;}\n\
639 .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\
640 .srccall:hover {color:white;font-weight:bold;border:1px solid white;}\n'
641 aslib.addCSS(hf, sysvals, 1, False, extra)
643 # write the device timeline
646 # add boot specific html
647 statinfo = 'var devstats = {\n'
648 for n in sorted(devstats):
649 statinfo += '\t"%s": [\n\t\t"%s",\n' % (n, devstats[n]['info'])
650 if 'fstat' in devstats[n]:
651 funcs = devstats[n]['fstat']
652 for f in sorted(funcs, key=funcs.get, reverse=True):
653 if funcs[f][0] < 0.01 and len(funcs) > 10:
655 statinfo += '\t\t"%f|%s|%d",\n' % (funcs[f][0], f, funcs[f][1])
659 '<div id="devicedetailtitle"></div>\n'\
660 '<div id="devicedetail" style="display:none;">\n'\
661 '<div id="devicedetail0">\n'
662 for p in data.phases:
663 phase = data.dmesg[p]
664 html += devtl.html_phaselet.format(p+'_mode', '0', '100', phase['color'])
665 html += '</div>\n</div>\n'\
666 '<script type="text/javascript">\n'+statinfo+\
670 # add the callgraph html
671 if(sysvals.usecallgraph):
672 aslib.addCallgraphs(sysvals, hf, data)
674 # add the test log as a hidden div
675 if sysvals.testlog and sysvals.logmsg:
676 hf.write('<div id="testlog" style="display:none;">\n'+sysvals.logmsg+'</div>\n')
677 # add the dmesg log as a hidden div
679 hf.write('<div id="dmesglog" style="display:none;">\n')
680 for line in data.dmesgtext:
681 line = line.replace('<', '<').replace('>', '>')
685 # write the footer and close
686 aslib.addScriptCode(hf, [data])
687 hf.write('</body>\n</html>\n')
691 # Function: updateCron
693 # (restore=False) Set the tool to run automatically on reboot
694 # (restore=True) Restore the original crontab
695 def updateCron(restore=False):
697 sysvals.rootUser(True)
698 crondir = '/var/spool/cron/crontabs/'
699 if not os.path.exists(crondir):
700 crondir = '/var/spool/cron/'
701 if not os.path.exists(crondir):
702 doError('%s not found' % crondir)
703 cronfile = crondir+'root'
704 backfile = crondir+'root-analyze_boot-backup'
705 cmd = sysvals.getExec('crontab')
707 doError('crontab not found')
708 # on restore: move the backup cron back into place
710 if os.path.exists(backfile):
711 shutil.move(backfile, cronfile)
712 call([cmd, cronfile])
714 # backup current cron and install new one with reboot
715 if os.path.exists(cronfile):
716 shutil.move(cronfile, backfile)
718 fp = open(backfile, 'w')
722 fp = open(backfile, 'r')
723 op = open(cronfile, 'w')
725 if not sysvals.myCronJob(line):
729 op.write('@reboot python %s\n' % sysvals.cronjobCmdString())
731 res = call([cmd, cronfile])
733 pprint('Exception: %s' % str(e))
734 shutil.move(backfile, cronfile)
737 doError('crontab failed')
739 # Function: updateGrub
741 # update grub.cfg for all kernels with our parameters
742 def updateGrub(restore=False):
743 # call update-grub on restore
746 call(sysvals.blexec, stderr=PIPE, stdout=PIPE,
747 env={'PATH': '.:/sbin:/usr/sbin:/usr/bin:/sbin:/bin'})
749 pprint('Exception: %s\n' % str(e))
751 # extract the option and create a grub config without it
752 sysvals.rootUser(True)
753 tgtopt = 'GRUB_CMDLINE_LINUX_DEFAULT'
755 grubfile = '/etc/default/grub'
756 tempfile = '/etc/default/grub.analyze_boot'
757 shutil.move(grubfile, tempfile)
760 fp = open(tempfile, 'r')
761 op = open(grubfile, 'w')
765 if len(line) == 0 or line[0] == '#':
767 opt = line.split('=')[0].strip()
769 cmdline = line.split('=', 1)[1].strip('\\')
773 cmdline += line.strip('\\')
777 op.write('%s\n' % line)
779 # if the target option value is in quotes, strip them
781 val = cmdline.strip()
782 if val and (val[0] == '\'' or val[0] == '"'):
786 # append our cmd line options
789 cmdline += sysvals.kernelParams()
790 # write out the updated target option
791 op.write('\n%s=%s%s%s\n' % (tgtopt, sp, cmdline, sp))
793 res = call(sysvals.blexec)
796 pprint('Exception: %s' % str(e))
799 shutil.move(tempfile, grubfile)
801 doError('update grub failed')
803 # Function: updateKernelParams
805 # update boot conf for all kernels with our parameters
806 def updateKernelParams(restore=False):
807 # find the boot loader
808 sysvals.getBootLoader()
809 if sysvals.bootloader == 'grub':
812 # Function: doError Description:
813 # generic error function for catastrphic failures
815 # msg: the error message to print
816 # help: True if printHelp should be called after, False otherwise
817 def doError(msg, help=False):
820 pprint('ERROR: %s\n' % msg)
821 sysvals.outputResult({'error':msg})
824 # Function: printHelp
826 # print out the help text
829 'Usage: bootgraph <options> <command>\n'\
832 ' This tool reads in a dmesg log of linux kernel boot and\n'\
833 ' creates an html representation of the boot timeline up to\n'\
834 ' the start of the init process.\n'\
836 ' If no specific command is given the tool reads the current dmesg\n'\
837 ' and/or ftrace log and creates a timeline\n'\
839 ' Generates output files in subdirectory: boot-yymmdd-HHMMSS\n'\
840 ' HTML output: <hostname>_boot.html\n'\
841 ' raw dmesg output: <hostname>_boot_dmesg.txt\n'\
842 ' raw ftrace output: <hostname>_boot_ftrace.txt\n'\
845 ' -h Print this help text\n'\
846 ' -v Print the current tool version\n'\
847 ' -verbose Print extra information during execution and analysis\n'\
848 ' -addlogs Add the dmesg log to the html output\n'\
849 ' -result fn Export a results table to a text file for parsing.\n'\
850 ' -o name Overrides the output subdirectory name when running a new test\n'\
851 ' default: boot-{date}-{time}\n'\
853 ' -fstat Use ftrace to add function detail and statistics (default: disabled)\n'\
854 ' -f/-callgraph Add callgraph detail, can be very large (default: disabled)\n'\
855 ' -maxdepth N limit the callgraph data to N call levels (default: 2)\n'\
856 ' -mincg ms Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)\n'\
857 ' -timeprec N Number of significant digits in timestamps (0:S, 3:ms, [6:us])\n'\
858 ' -expandcg pre-expand the callgraph data in the html output (default: disabled)\n'\
859 ' -func list Limit ftrace to comma-delimited list of functions (default: do_one_initcall)\n'\
860 ' -cgfilter S Filter the callgraph output in the timeline\n'\
861 ' -cgskip file Callgraph functions to skip, off to disable (default: cgskip.txt)\n'\
862 ' -bl name Use the following boot loader for kernel params (default: grub)\n'\
863 ' -reboot Reboot the machine automatically and generate a new timeline\n'\
864 ' -manual Show the steps to generate a new timeline manually (used with -reboot)\n'\
867 ' -flistall Print all functions capable of being captured in ftrace\n'\
868 ' -sysinfo Print out system info extracted from BIOS\n'\
870 ' -dmesg file Create HTML output using dmesg input (used with -ftrace)\n'\
871 ' -ftrace file Create HTML output using ftrace input (used with -dmesg)\n'\
872 '' % (sysvals.title, sysvals.version))
875 # ----------------- MAIN --------------------
876 # exec start (skipped if script is loaded as library)
877 if __name__ == '__main__':
878 # loop through the command line arguments
881 switchoff = ['disable', 'off', 'false', '0']
882 simplecmds = ['-sysinfo', '-kpupdate', '-flistall', '-checkbl']
885 cgskip = sysvals.configFile('cgskip.txt')
886 args = iter(sys.argv[1:])
893 pprint("Version %s" % sysvals.version)
895 elif(arg == '-verbose'):
896 sysvals.verbose = True
897 elif(arg in simplecmds):
899 elif(arg == '-fstat'):
900 sysvals.useftrace = True
901 elif(arg == '-callgraph' or arg == '-f'):
902 sysvals.useftrace = True
903 sysvals.usecallgraph = True
904 elif(arg == '-cgdump'):
905 sysvals.cgdump = True
906 elif(arg == '-mincg'):
907 sysvals.mincglen = aslib.getArgFloat('-mincg', args, 0.0, 10000.0)
908 elif(arg == '-cgfilter'):
912 doError('No callgraph functions supplied', True)
913 sysvals.setCallgraphFilter(val)
914 elif(arg == '-cgskip'):
918 doError('No file supplied', True)
919 if val.lower() in switchoff:
922 cgskip = sysvals.configFile(val)
924 doError('%s does not exist' % cgskip)
929 doError('No boot loader name supplied', True)
930 if val.lower() not in ['grub']:
931 doError('Unknown boot loader: %s' % val, True)
932 sysvals.bootloader = val.lower()
933 elif(arg == '-timeprec'):
934 sysvals.setPrecision(aslib.getArgInt('-timeprec', args, 0, 6))
935 elif(arg == '-maxdepth'):
937 sysvals.max_graph_depth = aslib.getArgInt('-maxdepth', args, 0, 1000)
938 elif(arg == '-func'):
942 doError('No filter functions supplied', True)
943 sysvals.useftrace = True
944 sysvals.usecallgraph = True
945 sysvals.rootCheck(True)
946 sysvals.setGraphFilter(val)
947 elif(arg == '-ftrace'):
951 doError('No ftrace file supplied', True)
952 if(os.path.exists(val) == False):
953 doError('%s does not exist' % val)
955 sysvals.ftracefile = val
956 elif(arg == '-addlogs'):
957 sysvals.dmesglog = True
958 elif(arg == '-expandcg'):
960 elif(arg == '-dmesg'):
964 doError('No dmesg file supplied', True)
965 if(os.path.exists(val) == False):
966 doError('%s does not exist' % val)
968 sysvals.dmesgfile = val
973 doError('No subdirectory name supplied', True)
974 sysvals.testdir = sysvals.setOutputFolder(val)
975 elif(arg == '-result'):
979 doError('No result file supplied', True)
981 elif(arg == '-reboot'):
982 sysvals.reboot = True
983 elif(arg == '-manual'):
984 sysvals.reboot = True
985 sysvals.manual = True
986 # remaining options are only for cron job use
987 elif(arg == '-cronjob'):
988 sysvals.iscronjob = True
990 doError('Invalid argument: '+arg, True)
992 # compatibility errors and access checks
993 if(sysvals.iscronjob and (sysvals.reboot or \
994 sysvals.dmesgfile or sysvals.ftracefile or cmd)):
995 doError('-cronjob is meant for batch purposes only')
996 if(sysvals.reboot and (sysvals.dmesgfile or sysvals.ftracefile)):
997 doError('-reboot and -dmesg/-ftrace are incompatible')
998 if cmd or sysvals.reboot or sysvals.iscronjob or testrun:
999 sysvals.rootCheck(True)
1000 if (testrun and sysvals.useftrace) or cmd == 'flistall':
1001 if not sysvals.verifyFtrace():
1002 doError('Ftrace is not properly enabled')
1004 # run utility commands
1007 if cmd == 'kpupdate':
1008 updateKernelParams()
1009 elif cmd == 'flistall':
1010 for f in sysvals.getBootFtraceFilterFunctions():
1012 elif cmd == 'checkbl':
1013 sysvals.getBootLoader()
1014 pprint('Boot Loader: %s\n%s' % (sysvals.bootloader, sysvals.blexec))
1015 elif(cmd == 'sysinfo'):
1016 sysvals.printSystemInfo(True)
1019 # reboot: update grub, setup a cronjob, and reboot
1021 if (sysvals.useftrace or sysvals.usecallgraph) and \
1022 not sysvals.checkFtraceKernelVersion():
1023 doError('Ftrace functionality requires kernel v4.10 or newer')
1024 if not sysvals.manual:
1025 updateKernelParams()
1029 sysvals.manualRebootRequired()
1032 if sysvals.usecallgraph and cgskip:
1033 sysvals.vprint('Using cgskip file: %s' % cgskip)
1034 sysvals.setCallgraphBlacklist(cgskip)
1036 # cronjob: remove the cronjob, grub changes, and disable ftrace
1037 if sysvals.iscronjob:
1039 updateKernelParams(True)
1041 sysvals.fsetVal('0', 'tracing_on')
1045 # testrun: generate copies of the logs
1049 sysvals.setOutputFile()
1051 # process the log data
1052 if sysvals.dmesgfile:
1054 sysvals.max_graph_depth = 0
1055 data = parseKernelLog()
1057 doError('No initcall data found in %s' % sysvals.dmesgfile)
1058 if sysvals.useftrace and sysvals.ftracefile:
1064 doError('dmesg file required')
1066 sysvals.vprint('Creating the html timeline (%s)...' % sysvals.htmlfile)
1067 sysvals.vprint('Command:\n %s' % sysvals.cmdline)
1068 sysvals.vprint('Kernel parameters:\n %s' % sysvals.kparams)
1070 createBootGraph(data)
1072 # if running as root, change output dir owner to sudo_user
1073 if testrun and os.path.isdir(sysvals.testdir) and \
1074 os.getuid() == 0 and 'SUDO_USER' in os.environ:
1075 cmd = 'chown -R {0}:{0} {1} > /dev/null 2>&1'
1076 call(cmd.format(os.environ['SUDO_USER'], sysvals.testdir), shell=True)
1078 sysvals.stamp['boot'] = (data.tUserMode - data.start) * 1000
1079 sysvals.stamp['lastinit'] = data.end * 1000
1080 sysvals.outputResult(sysvals.stamp)