v4.19.13 snapshot.
diff --git a/tools/power/pm-graph/bootgraph.py b/tools/power/pm-graph/bootgraph.py
new file mode 100755
index 0000000..8ee626c
--- /dev/null
+++ b/tools/power/pm-graph/bootgraph.py
@@ -0,0 +1,1085 @@
+#!/usr/bin/python2
+#
+# Tool for analyzing boot timing
+# Copyright (c) 2013, Intel Corporation.
+#
+# This program is free software; you can redistribute it and/or modify it
+# under the terms and conditions of the GNU General Public License,
+# version 2, as published by the Free Software Foundation.
+#
+# This program is distributed in the hope it will be useful, but WITHOUT
+# ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+# FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for
+# more details.
+#
+# Authors:
+# Todd Brandt <todd.e.brandt@linux.intel.com>
+#
+# Description:
+# This tool is designed to assist kernel and OS developers in optimizing
+# their linux stack's boot time. It creates an html representation of
+# the kernel boot timeline up to the start of the init process.
+#
+
+# ----------------- LIBRARIES --------------------
+
+import sys
+import time
+import os
+import string
+import re
+import platform
+import shutil
+from datetime import datetime, timedelta
+from subprocess import call, Popen, PIPE
+import sleepgraph as aslib
+
+# ----------------- CLASSES --------------------
+
+# Class: SystemValues
+# Description:
+# A global, single-instance container used to
+# store system values and test parameters
+class SystemValues(aslib.SystemValues):
+ title = 'BootGraph'
+ version = '2.2'
+ hostname = 'localhost'
+ testtime = ''
+ kernel = ''
+ dmesgfile = ''
+ ftracefile = ''
+ htmlfile = 'bootgraph.html'
+ testdir = ''
+ kparams = ''
+ result = ''
+ useftrace = False
+ usecallgraph = False
+ suspendmode = 'boot'
+ max_graph_depth = 2
+ graph_filter = 'do_one_initcall'
+ reboot = False
+ manual = False
+ iscronjob = False
+ timeformat = '%.6f'
+ bootloader = 'grub'
+ blexec = []
+ def __init__(self):
+ self.hostname = platform.node()
+ self.testtime = datetime.now().strftime('%Y-%m-%d_%H:%M:%S')
+ if os.path.exists('/proc/version'):
+ fp = open('/proc/version', 'r')
+ val = fp.read().strip()
+ fp.close()
+ self.kernel = self.kernelVersion(val)
+ else:
+ self.kernel = 'unknown'
+ self.testdir = datetime.now().strftime('boot-%y%m%d-%H%M%S')
+ def kernelVersion(self, msg):
+ return msg.split()[2]
+ def checkFtraceKernelVersion(self):
+ val = tuple(map(int, self.kernel.split('-')[0].split('.')))
+ if val >= (4, 10, 0):
+ return True
+ return False
+ def kernelParams(self):
+ cmdline = 'initcall_debug log_buf_len=32M'
+ if self.useftrace:
+ if self.cpucount > 0:
+ bs = min(self.memtotal / 2, 2*1024*1024) / self.cpucount
+ else:
+ bs = 131072
+ cmdline += ' trace_buf_size=%dK trace_clock=global '\
+ 'trace_options=nooverwrite,funcgraph-abstime,funcgraph-cpu,'\
+ 'funcgraph-duration,funcgraph-proc,funcgraph-tail,'\
+ 'nofuncgraph-overhead,context-info,graph-time '\
+ 'ftrace=function_graph '\
+ 'ftrace_graph_max_depth=%d '\
+ 'ftrace_graph_filter=%s' % \
+ (bs, self.max_graph_depth, self.graph_filter)
+ return cmdline
+ def setGraphFilter(self, val):
+ master = self.getBootFtraceFilterFunctions()
+ fs = ''
+ for i in val.split(','):
+ func = i.strip()
+ if func == '':
+ doError('badly formatted filter function string')
+ if '[' in func or ']' in func:
+ doError('loadable module functions not allowed - "%s"' % func)
+ if ' ' in func:
+ doError('spaces found in filter functions - "%s"' % func)
+ if func not in master:
+ doError('function "%s" not available for ftrace' % func)
+ if not fs:
+ fs = func
+ else:
+ fs += ','+func
+ if not fs:
+ doError('badly formatted filter function string')
+ self.graph_filter = fs
+ def getBootFtraceFilterFunctions(self):
+ self.rootCheck(True)
+ fp = open(self.tpath+'available_filter_functions')
+ fulllist = fp.read().split('\n')
+ fp.close()
+ list = []
+ for i in fulllist:
+ if not i or ' ' in i or '[' in i or ']' in i:
+ continue
+ list.append(i)
+ return list
+ def myCronJob(self, line):
+ if '@reboot' not in line:
+ return False
+ if 'bootgraph' in line or 'analyze_boot.py' in line or '-cronjob' in line:
+ return True
+ return False
+ def cronjobCmdString(self):
+ cmdline = '%s -cronjob' % os.path.abspath(sys.argv[0])
+ args = iter(sys.argv[1:])
+ for arg in args:
+ if arg in ['-h', '-v', '-cronjob', '-reboot', '-verbose']:
+ continue
+ elif arg in ['-o', '-dmesg', '-ftrace', '-func']:
+ args.next()
+ continue
+ elif arg == '-result':
+ cmdline += ' %s "%s"' % (arg, os.path.abspath(args.next()))
+ continue
+ elif arg == '-cgskip':
+ file = self.configFile(args.next())
+ cmdline += ' %s "%s"' % (arg, os.path.abspath(file))
+ continue
+ cmdline += ' '+arg
+ if self.graph_filter != 'do_one_initcall':
+ cmdline += ' -func "%s"' % self.graph_filter
+ cmdline += ' -o "%s"' % os.path.abspath(self.testdir)
+ return cmdline
+ def manualRebootRequired(self):
+ cmdline = self.kernelParams()
+ print 'To generate a new timeline manually, follow these steps:\n'
+ print '1. Add the CMDLINE string to your kernel command line.'
+ print '2. Reboot the system.'
+ print '3. After reboot, re-run this tool with the same arguments but no command (w/o -reboot or -manual).\n'
+ print 'CMDLINE="%s"' % cmdline
+ sys.exit()
+ def blGrub(self):
+ blcmd = ''
+ for cmd in ['update-grub', 'grub-mkconfig', 'grub2-mkconfig']:
+ if blcmd:
+ break
+ blcmd = self.getExec(cmd)
+ if not blcmd:
+ doError('[GRUB] missing update command')
+ if not os.path.exists('/etc/default/grub'):
+ doError('[GRUB] missing /etc/default/grub')
+ if 'grub2' in blcmd:
+ cfg = '/boot/grub2/grub.cfg'
+ else:
+ cfg = '/boot/grub/grub.cfg'
+ if not os.path.exists(cfg):
+ doError('[GRUB] missing %s' % cfg)
+ if 'update-grub' in blcmd:
+ self.blexec = [blcmd]
+ else:
+ self.blexec = [blcmd, '-o', cfg]
+ def getBootLoader(self):
+ if self.bootloader == 'grub':
+ self.blGrub()
+ else:
+ doError('unknown boot loader: %s' % self.bootloader)
+ def writeDatafileHeader(self, filename):
+ self.kparams = open('/proc/cmdline', 'r').read().strip()
+ fp = open(filename, 'w')
+ fp.write(self.teststamp+'\n')
+ fp.write(self.sysstamp+'\n')
+ fp.write('# command | %s\n' % self.cmdline)
+ fp.write('# kparams | %s\n' % self.kparams)
+ fp.close()
+
+sysvals = SystemValues()
+
+# Class: Data
+# Description:
+# The primary container for test data.
+class Data(aslib.Data):
+ dmesg = {} # root data structure
+ start = 0.0 # test start
+ end = 0.0 # test end
+ dmesgtext = [] # dmesg text file in memory
+ testnumber = 0
+ idstr = ''
+ html_device_id = 0
+ valid = False
+ tUserMode = 0.0
+ boottime = ''
+ phases = ['kernel', 'user']
+ do_one_initcall = False
+ def __init__(self, num):
+ self.testnumber = num
+ self.idstr = 'a'
+ self.dmesgtext = []
+ self.dmesg = {
+ 'kernel': {'list': dict(), 'start': -1.0, 'end': -1.0, 'row': 0,
+ 'order': 0, 'color': 'linear-gradient(to bottom, #fff, #bcf)'},
+ 'user': {'list': dict(), 'start': -1.0, 'end': -1.0, 'row': 0,
+ 'order': 1, 'color': '#fff'}
+ }
+ def deviceTopology(self):
+ return ''
+ def newAction(self, phase, name, pid, start, end, ret, ulen):
+ # new device callback for a specific phase
+ self.html_device_id += 1
+ devid = '%s%d' % (self.idstr, self.html_device_id)
+ list = self.dmesg[phase]['list']
+ length = -1.0
+ if(start >= 0 and end >= 0):
+ length = end - start
+ i = 2
+ origname = name
+ while(name in list):
+ name = '%s[%d]' % (origname, i)
+ i += 1
+ list[name] = {'name': name, 'start': start, 'end': end,
+ 'pid': pid, 'length': length, 'row': 0, 'id': devid,
+ 'ret': ret, 'ulen': ulen }
+ return name
+ def deviceMatch(self, pid, cg):
+ if cg.end - cg.start == 0:
+ return ''
+ for p in data.phases:
+ list = self.dmesg[p]['list']
+ for devname in list:
+ dev = list[devname]
+ if pid != dev['pid']:
+ continue
+ if cg.name == 'do_one_initcall':
+ if(cg.start <= dev['start'] and cg.end >= dev['end'] and dev['length'] > 0):
+ dev['ftrace'] = cg
+ self.do_one_initcall = True
+ return devname
+ else:
+ if(cg.start > dev['start'] and cg.end < dev['end']):
+ if 'ftraces' not in dev:
+ dev['ftraces'] = []
+ dev['ftraces'].append(cg)
+ return devname
+ return ''
+ def printDetails(self):
+ sysvals.vprint('Timeline Details:')
+ sysvals.vprint(' Host: %s' % sysvals.hostname)
+ sysvals.vprint(' Kernel: %s' % sysvals.kernel)
+ sysvals.vprint(' Test time: %s' % sysvals.testtime)
+ sysvals.vprint(' Boot time: %s' % self.boottime)
+ for phase in self.phases:
+ dc = len(self.dmesg[phase]['list'])
+ sysvals.vprint('%9s mode: %.3f - %.3f (%d initcalls)' % (phase,
+ self.dmesg[phase]['start']*1000,
+ self.dmesg[phase]['end']*1000, dc))
+
+# ----------------- FUNCTIONS --------------------
+
+# Function: parseKernelLog
+# Description:
+# parse a kernel log for boot data
+def parseKernelLog():
+ sysvals.vprint('Analyzing the dmesg data (%s)...' % \
+ os.path.basename(sysvals.dmesgfile))
+ phase = 'kernel'
+ data = Data(0)
+ data.dmesg['kernel']['start'] = data.start = ktime = 0.0
+ sysvals.stamp = {
+ 'time': datetime.now().strftime('%B %d %Y, %I:%M:%S %p'),
+ 'host': sysvals.hostname,
+ 'mode': 'boot', 'kernel': ''}
+
+ tp = aslib.TestProps()
+ devtemp = dict()
+ if(sysvals.dmesgfile):
+ lf = open(sysvals.dmesgfile, 'r')
+ else:
+ lf = Popen('dmesg', stdout=PIPE).stdout
+ for line in lf:
+ line = line.replace('\r\n', '')
+ # grab the stamp and sysinfo
+ if re.match(tp.stampfmt, line):
+ tp.stamp = line
+ continue
+ elif re.match(tp.sysinfofmt, line):
+ tp.sysinfo = line
+ continue
+ elif re.match(tp.cmdlinefmt, line):
+ tp.cmdline = line
+ continue
+ elif re.match(tp.kparamsfmt, line):
+ tp.kparams = line
+ continue
+ idx = line.find('[')
+ if idx > 1:
+ line = line[idx:]
+ m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line)
+ if(not m):
+ continue
+ ktime = float(m.group('ktime'))
+ if(ktime > 120):
+ break
+ msg = m.group('msg')
+ data.dmesgtext.append(line)
+ if(ktime == 0.0 and re.match('^Linux version .*', msg)):
+ if(not sysvals.stamp['kernel']):
+ sysvals.stamp['kernel'] = sysvals.kernelVersion(msg)
+ continue
+ m = re.match('.* setting system clock to (?P<t>.*) UTC.*', msg)
+ if(m):
+ bt = datetime.strptime(m.group('t'), '%Y-%m-%d %H:%M:%S')
+ bt = bt - timedelta(seconds=int(ktime))
+ data.boottime = bt.strftime('%Y-%m-%d_%H:%M:%S')
+ sysvals.stamp['time'] = bt.strftime('%B %d %Y, %I:%M:%S %p')
+ continue
+ m = re.match('^calling *(?P<f>.*)\+.* @ (?P<p>[0-9]*)', msg)
+ if(m):
+ func = m.group('f')
+ pid = int(m.group('p'))
+ devtemp[func] = (ktime, pid)
+ continue
+ m = re.match('^initcall *(?P<f>.*)\+.* returned (?P<r>.*) after (?P<t>.*) usecs', msg)
+ if(m):
+ data.valid = True
+ data.end = ktime
+ f, r, t = m.group('f', 'r', 't')
+ if(f in devtemp):
+ start, pid = devtemp[f]
+ data.newAction(phase, f, pid, start, ktime, int(r), int(t))
+ del devtemp[f]
+ continue
+ if(re.match('^Freeing unused kernel memory.*', msg)):
+ data.tUserMode = ktime
+ data.dmesg['kernel']['end'] = ktime
+ data.dmesg['user']['start'] = ktime
+ phase = 'user'
+
+ if tp.stamp:
+ sysvals.stamp = 0
+ tp.parseStamp(data, sysvals)
+ data.dmesg['user']['end'] = data.end
+ lf.close()
+ return data
+
+# Function: parseTraceLog
+# Description:
+# Check if trace is available and copy to a temp file
+def parseTraceLog(data):
+ sysvals.vprint('Analyzing the ftrace data (%s)...' % \
+ os.path.basename(sysvals.ftracefile))
+ # if available, calculate cgfilter allowable ranges
+ cgfilter = []
+ if len(sysvals.cgfilter) > 0:
+ for p in data.phases:
+ list = data.dmesg[p]['list']
+ for i in sysvals.cgfilter:
+ if i in list:
+ cgfilter.append([list[i]['start']-0.0001,
+ list[i]['end']+0.0001])
+ # parse the trace log
+ ftemp = dict()
+ tp = aslib.TestProps()
+ tp.setTracerType('function_graph')
+ tf = open(sysvals.ftracefile, 'r')
+ for line in tf:
+ if line[0] == '#':
+ continue
+ m = re.match(tp.ftrace_line_fmt, line.strip())
+ if(not m):
+ continue
+ m_time, m_proc, m_pid, m_msg, m_dur = \
+ m.group('time', 'proc', 'pid', 'msg', 'dur')
+ t = float(m_time)
+ if len(cgfilter) > 0:
+ allow = False
+ for r in cgfilter:
+ if t >= r[0] and t < r[1]:
+ allow = True
+ break
+ if not allow:
+ continue
+ if t > data.end:
+ break
+ if(m_time and m_pid and m_msg):
+ t = aslib.FTraceLine(m_time, m_msg, m_dur)
+ pid = int(m_pid)
+ else:
+ continue
+ if t.fevent or t.fkprobe:
+ continue
+ key = (m_proc, pid)
+ if(key not in ftemp):
+ ftemp[key] = []
+ ftemp[key].append(aslib.FTraceCallGraph(pid, sysvals))
+ cg = ftemp[key][-1]
+ res = cg.addLine(t)
+ if(res != 0):
+ ftemp[key].append(aslib.FTraceCallGraph(pid, sysvals))
+ if(res == -1):
+ ftemp[key][-1].addLine(t)
+
+ tf.close()
+
+ # add the callgraph data to the device hierarchy
+ for key in ftemp:
+ proc, pid = key
+ for cg in ftemp[key]:
+ if len(cg.list) < 1 or cg.invalid or (cg.end - cg.start == 0):
+ continue
+ if(not cg.postProcess()):
+ print('Sanity check failed for %s-%d' % (proc, pid))
+ continue
+ # match cg data to devices
+ devname = data.deviceMatch(pid, cg)
+ if not devname:
+ kind = 'Orphan'
+ if cg.partial:
+ kind = 'Partial'
+ sysvals.vprint('%s callgraph found for %s %s-%d [%f - %f]' %\
+ (kind, cg.name, proc, pid, cg.start, cg.end))
+ elif len(cg.list) > 1000000:
+ print 'WARNING: the callgraph found for %s is massive! (%d lines)' %\
+ (devname, len(cg.list))
+
+# Function: retrieveLogs
+# Description:
+# Create copies of dmesg and/or ftrace for later processing
+def retrieveLogs():
+ # check ftrace is configured first
+ if sysvals.useftrace:
+ tracer = sysvals.fgetVal('current_tracer').strip()
+ if tracer != 'function_graph':
+ doError('ftrace not configured for a boot callgraph')
+ # create the folder and get dmesg
+ sysvals.systemInfo(aslib.dmidecode(sysvals.mempath))
+ sysvals.initTestOutput('boot')
+ sysvals.writeDatafileHeader(sysvals.dmesgfile)
+ call('dmesg >> '+sysvals.dmesgfile, shell=True)
+ if not sysvals.useftrace:
+ return
+ # get ftrace
+ sysvals.writeDatafileHeader(sysvals.ftracefile)
+ call('cat '+sysvals.tpath+'trace >> '+sysvals.ftracefile, shell=True)
+
+# Function: colorForName
+# Description:
+# Generate a repeatable color from a list for a given name
+def colorForName(name):
+ list = [
+ ('c1', '#ec9999'),
+ ('c2', '#ffc1a6'),
+ ('c3', '#fff0a6'),
+ ('c4', '#adf199'),
+ ('c5', '#9fadea'),
+ ('c6', '#a699c1'),
+ ('c7', '#ad99b4'),
+ ('c8', '#eaffea'),
+ ('c9', '#dcecfb'),
+ ('c10', '#ffffea')
+ ]
+ i = 0
+ total = 0
+ count = len(list)
+ while i < len(name):
+ total += ord(name[i])
+ i += 1
+ return list[total % count]
+
+def cgOverview(cg, minlen):
+ stats = dict()
+ large = []
+ for l in cg.list:
+ if l.fcall and l.depth == 1:
+ if l.length >= minlen:
+ large.append(l)
+ if l.name not in stats:
+ stats[l.name] = [0, 0.0]
+ stats[l.name][0] += (l.length * 1000.0)
+ stats[l.name][1] += 1
+ return (large, stats)
+
+# Function: createBootGraph
+# Description:
+# Create the output html file from the resident test data
+# Arguments:
+# testruns: array of Data objects from parseKernelLog or parseTraceLog
+# Output:
+# True if the html file was created, false if it failed
+def createBootGraph(data):
+ # html function templates
+ 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'
+ html_timetotal = '<table class="time1">\n<tr>'\
+ '<td class="blue">Init process starts @ <b>{0} ms</b></td>'\
+ '<td class="blue">Last initcall ends @ <b>{1} ms</b></td>'\
+ '</tr>\n</table>\n'
+
+ # device timeline
+ devtl = aslib.Timeline(100, 20)
+
+ # write the test title and general info header
+ devtl.createHeader(sysvals, sysvals.stamp)
+
+ # Generate the header for this timeline
+ t0 = data.start
+ tMax = data.end
+ tTotal = tMax - t0
+ if(tTotal == 0):
+ print('ERROR: No timeline data')
+ return False
+ user_mode = '%.0f'%(data.tUserMode*1000)
+ last_init = '%.0f'%(tTotal*1000)
+ devtl.html += html_timetotal.format(user_mode, last_init)
+
+ # determine the maximum number of rows we need to draw
+ devlist = []
+ for p in data.phases:
+ list = data.dmesg[p]['list']
+ for devname in list:
+ d = aslib.DevItem(0, p, list[devname])
+ devlist.append(d)
+ devtl.getPhaseRows(devlist, 0, 'start')
+ devtl.calcTotalRows()
+
+ # draw the timeline background
+ devtl.createZoomBox()
+ devtl.html += devtl.html_tblock.format('boot', '0', '100', devtl.scaleH)
+ for p in data.phases:
+ phase = data.dmesg[p]
+ length = phase['end']-phase['start']
+ left = '%.3f' % (((phase['start']-t0)*100.0)/tTotal)
+ width = '%.3f' % ((length*100.0)/tTotal)
+ devtl.html += devtl.html_phase.format(left, width, \
+ '%.3f'%devtl.scaleH, '%.3f'%devtl.bodyH, \
+ phase['color'], '')
+
+ # draw the device timeline
+ num = 0
+ devstats = dict()
+ for phase in data.phases:
+ list = data.dmesg[phase]['list']
+ for devname in sorted(list):
+ cls, color = colorForName(devname)
+ dev = list[devname]
+ info = '@|%.3f|%.3f|%.3f|%d' % (dev['start']*1000.0, dev['end']*1000.0,
+ dev['ulen']/1000.0, dev['ret'])
+ devstats[dev['id']] = {'info':info}
+ dev['color'] = color
+ height = devtl.phaseRowHeight(0, phase, dev['row'])
+ top = '%.6f' % ((dev['row']*height) + devtl.scaleH)
+ left = '%.6f' % (((dev['start']-t0)*100)/tTotal)
+ width = '%.6f' % (((dev['end']-dev['start'])*100)/tTotal)
+ length = ' (%0.3f ms) ' % ((dev['end']-dev['start'])*1000)
+ devtl.html += devtl.html_device.format(dev['id'],
+ devname+length+phase+'_mode', left, top, '%.3f'%height,
+ width, devname, ' '+cls, '')
+ rowtop = devtl.phaseRowTop(0, phase, dev['row'])
+ height = '%.6f' % (devtl.rowH / 2)
+ top = '%.6f' % (rowtop + devtl.scaleH + (devtl.rowH / 2))
+ if data.do_one_initcall:
+ if('ftrace' not in dev):
+ continue
+ cg = dev['ftrace']
+ large, stats = cgOverview(cg, 0.001)
+ devstats[dev['id']]['fstat'] = stats
+ for l in large:
+ left = '%f' % (((l.time-t0)*100)/tTotal)
+ width = '%f' % (l.length*100/tTotal)
+ title = '%s (%0.3fms)' % (l.name, l.length * 1000.0)
+ devtl.html += html_srccall.format(l.name, left,
+ top, height, width, title, 'x%d'%num)
+ num += 1
+ continue
+ if('ftraces' not in dev):
+ continue
+ for cg in dev['ftraces']:
+ left = '%f' % (((cg.start-t0)*100)/tTotal)
+ width = '%f' % ((cg.end-cg.start)*100/tTotal)
+ cglen = (cg.end - cg.start) * 1000.0
+ title = '%s (%0.3fms)' % (cg.name, cglen)
+ cg.id = 'x%d' % num
+ devtl.html += html_srccall.format(cg.name, left,
+ top, height, width, title, dev['id']+cg.id)
+ num += 1
+
+ # draw the time scale, try to make the number of labels readable
+ devtl.createTimeScale(t0, tMax, tTotal, 'boot')
+ devtl.html += '</div>\n'
+
+ # timeline is finished
+ devtl.html += '</div>\n</div>\n'
+
+ # draw a legend which describes the phases by color
+ devtl.html += '<div class="legend">\n'
+ pdelta = 20.0
+ pmargin = 36.0
+ for phase in data.phases:
+ order = '%.2f' % ((data.dmesg[phase]['order'] * pdelta) + pmargin)
+ devtl.html += devtl.html_legend.format(order, \
+ data.dmesg[phase]['color'], phase+'_mode', phase[0])
+ devtl.html += '</div>\n'
+
+ hf = open(sysvals.htmlfile, 'w')
+
+ # add the css
+ extra = '\
+ .c1 {background:rgba(209,0,0,0.4);}\n\
+ .c2 {background:rgba(255,102,34,0.4);}\n\
+ .c3 {background:rgba(255,218,33,0.4);}\n\
+ .c4 {background:rgba(51,221,0,0.4);}\n\
+ .c5 {background:rgba(17,51,204,0.4);}\n\
+ .c6 {background:rgba(34,0,102,0.4);}\n\
+ .c7 {background:rgba(51,0,68,0.4);}\n\
+ .c8 {background:rgba(204,255,204,0.4);}\n\
+ .c9 {background:rgba(169,208,245,0.4);}\n\
+ .c10 {background:rgba(255,255,204,0.4);}\n\
+ .vt {transform:rotate(-60deg);transform-origin:0 0;}\n\
+ table.fstat {table-layout:fixed;padding:150px 15px 0 0;font-size:10px;column-width:30px;}\n\
+ .fstat th {width:55px;}\n\
+ .fstat td {text-align:left;width:35px;}\n\
+ .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\
+ .srccall:hover {color:white;font-weight:bold;border:1px solid white;}\n'
+ aslib.addCSS(hf, sysvals, 1, False, extra)
+
+ # write the device timeline
+ hf.write(devtl.html)
+
+ # add boot specific html
+ statinfo = 'var devstats = {\n'
+ for n in sorted(devstats):
+ statinfo += '\t"%s": [\n\t\t"%s",\n' % (n, devstats[n]['info'])
+ if 'fstat' in devstats[n]:
+ funcs = devstats[n]['fstat']
+ for f in sorted(funcs, key=funcs.get, reverse=True):
+ if funcs[f][0] < 0.01 and len(funcs) > 10:
+ break
+ statinfo += '\t\t"%f|%s|%d",\n' % (funcs[f][0], f, funcs[f][1])
+ statinfo += '\t],\n'
+ statinfo += '};\n'
+ html = \
+ '<div id="devicedetailtitle"></div>\n'\
+ '<div id="devicedetail" style="display:none;">\n'\
+ '<div id="devicedetail0">\n'
+ for p in data.phases:
+ phase = data.dmesg[p]
+ html += devtl.html_phaselet.format(p+'_mode', '0', '100', phase['color'])
+ html += '</div>\n</div>\n'\
+ '<script type="text/javascript">\n'+statinfo+\
+ '</script>\n'
+ hf.write(html)
+
+ # add the callgraph html
+ if(sysvals.usecallgraph):
+ aslib.addCallgraphs(sysvals, hf, data)
+
+ # add the test log as a hidden div
+ if sysvals.testlog and sysvals.logmsg:
+ hf.write('<div id="testlog" style="display:none;">\n'+sysvals.logmsg+'</div>\n')
+ # add the dmesg log as a hidden div
+ if sysvals.dmesglog:
+ hf.write('<div id="dmesglog" style="display:none;">\n')
+ for line in data.dmesgtext:
+ line = line.replace('<', '<').replace('>', '>')
+ hf.write(line)
+ hf.write('</div>\n')
+
+ # write the footer and close
+ aslib.addScriptCode(hf, [data])
+ hf.write('</body>\n</html>\n')
+ hf.close()
+ return True
+
+# Function: updateCron
+# Description:
+# (restore=False) Set the tool to run automatically on reboot
+# (restore=True) Restore the original crontab
+def updateCron(restore=False):
+ if not restore:
+ sysvals.rootUser(True)
+ crondir = '/var/spool/cron/crontabs/'
+ if not os.path.exists(crondir):
+ crondir = '/var/spool/cron/'
+ if not os.path.exists(crondir):
+ doError('%s not found' % crondir)
+ cronfile = crondir+'root'
+ backfile = crondir+'root-analyze_boot-backup'
+ cmd = sysvals.getExec('crontab')
+ if not cmd:
+ doError('crontab not found')
+ # on restore: move the backup cron back into place
+ if restore:
+ if os.path.exists(backfile):
+ shutil.move(backfile, cronfile)
+ call([cmd, cronfile])
+ return
+ # backup current cron and install new one with reboot
+ if os.path.exists(cronfile):
+ shutil.move(cronfile, backfile)
+ else:
+ fp = open(backfile, 'w')
+ fp.close()
+ res = -1
+ try:
+ fp = open(backfile, 'r')
+ op = open(cronfile, 'w')
+ for line in fp:
+ if not sysvals.myCronJob(line):
+ op.write(line)
+ continue
+ fp.close()
+ op.write('@reboot python %s\n' % sysvals.cronjobCmdString())
+ op.close()
+ res = call([cmd, cronfile])
+ except Exception, e:
+ print 'Exception: %s' % str(e)
+ shutil.move(backfile, cronfile)
+ res = -1
+ if res != 0:
+ doError('crontab failed')
+
+# Function: updateGrub
+# Description:
+# update grub.cfg for all kernels with our parameters
+def updateGrub(restore=False):
+ # call update-grub on restore
+ if restore:
+ try:
+ call(sysvals.blexec, stderr=PIPE, stdout=PIPE,
+ env={'PATH': '.:/sbin:/usr/sbin:/usr/bin:/sbin:/bin'})
+ except Exception, e:
+ print 'Exception: %s\n' % str(e)
+ return
+ # extract the option and create a grub config without it
+ sysvals.rootUser(True)
+ tgtopt = 'GRUB_CMDLINE_LINUX_DEFAULT'
+ cmdline = ''
+ grubfile = '/etc/default/grub'
+ tempfile = '/etc/default/grub.analyze_boot'
+ shutil.move(grubfile, tempfile)
+ res = -1
+ try:
+ fp = open(tempfile, 'r')
+ op = open(grubfile, 'w')
+ cont = False
+ for line in fp:
+ line = line.strip()
+ if len(line) == 0 or line[0] == '#':
+ continue
+ opt = line.split('=')[0].strip()
+ if opt == tgtopt:
+ cmdline = line.split('=', 1)[1].strip('\\')
+ if line[-1] == '\\':
+ cont = True
+ elif cont:
+ cmdline += line.strip('\\')
+ if line[-1] != '\\':
+ cont = False
+ else:
+ op.write('%s\n' % line)
+ fp.close()
+ # if the target option value is in quotes, strip them
+ sp = '"'
+ val = cmdline.strip()
+ if val and (val[0] == '\'' or val[0] == '"'):
+ sp = val[0]
+ val = val.strip(sp)
+ cmdline = val
+ # append our cmd line options
+ if len(cmdline) > 0:
+ cmdline += ' '
+ cmdline += sysvals.kernelParams()
+ # write out the updated target option
+ op.write('\n%s=%s%s%s\n' % (tgtopt, sp, cmdline, sp))
+ op.close()
+ res = call(sysvals.blexec)
+ os.remove(grubfile)
+ except Exception, e:
+ print 'Exception: %s' % str(e)
+ res = -1
+ # cleanup
+ shutil.move(tempfile, grubfile)
+ if res != 0:
+ doError('update grub failed')
+
+# Function: updateKernelParams
+# Description:
+# update boot conf for all kernels with our parameters
+def updateKernelParams(restore=False):
+ # find the boot loader
+ sysvals.getBootLoader()
+ if sysvals.bootloader == 'grub':
+ updateGrub(restore)
+
+# Function: doError Description:
+# generic error function for catastrphic failures
+# Arguments:
+# msg: the error message to print
+# help: True if printHelp should be called after, False otherwise
+def doError(msg, help=False):
+ if help == True:
+ printHelp()
+ print 'ERROR: %s\n' % msg
+ sysvals.outputResult({'error':msg})
+ sys.exit()
+
+# Function: printHelp
+# Description:
+# print out the help text
+def printHelp():
+ print('')
+ print('%s v%s' % (sysvals.title, sysvals.version))
+ print('Usage: bootgraph <options> <command>')
+ print('')
+ print('Description:')
+ print(' This tool reads in a dmesg log of linux kernel boot and')
+ print(' creates an html representation of the boot timeline up to')
+ print(' the start of the init process.')
+ print('')
+ print(' If no specific command is given the tool reads the current dmesg')
+ print(' and/or ftrace log and creates a timeline')
+ print('')
+ print(' Generates output files in subdirectory: boot-yymmdd-HHMMSS')
+ print(' HTML output: <hostname>_boot.html')
+ print(' raw dmesg output: <hostname>_boot_dmesg.txt')
+ print(' raw ftrace output: <hostname>_boot_ftrace.txt')
+ print('')
+ print('Options:')
+ print(' -h Print this help text')
+ print(' -v Print the current tool version')
+ print(' -verbose Print extra information during execution and analysis')
+ print(' -addlogs Add the dmesg log to the html output')
+ print(' -result fn Export a results table to a text file for parsing.')
+ print(' -o name Overrides the output subdirectory name when running a new test')
+ print(' default: boot-{date}-{time}')
+ print(' [advanced]')
+ print(' -fstat Use ftrace to add function detail and statistics (default: disabled)')
+ print(' -f/-callgraph Add callgraph detail, can be very large (default: disabled)')
+ print(' -maxdepth N limit the callgraph data to N call levels (default: 2)')
+ print(' -mincg ms Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)')
+ print(' -timeprec N Number of significant digits in timestamps (0:S, 3:ms, [6:us])')
+ print(' -expandcg pre-expand the callgraph data in the html output (default: disabled)')
+ print(' -func list Limit ftrace to comma-delimited list of functions (default: do_one_initcall)')
+ print(' -cgfilter S Filter the callgraph output in the timeline')
+ print(' -cgskip file Callgraph functions to skip, off to disable (default: cgskip.txt)')
+ print(' -bl name Use the following boot loader for kernel params (default: grub)')
+ print(' -reboot Reboot the machine automatically and generate a new timeline')
+ print(' -manual Show the steps to generate a new timeline manually (used with -reboot)')
+ print('')
+ print('Other commands:')
+ print(' -flistall Print all functions capable of being captured in ftrace')
+ print(' -sysinfo Print out system info extracted from BIOS')
+ print(' [redo]')
+ print(' -dmesg file Create HTML output using dmesg input (used with -ftrace)')
+ print(' -ftrace file Create HTML output using ftrace input (used with -dmesg)')
+ print('')
+ return True
+
+# ----------------- MAIN --------------------
+# exec start (skipped if script is loaded as library)
+if __name__ == '__main__':
+ # loop through the command line arguments
+ cmd = ''
+ testrun = True
+ switchoff = ['disable', 'off', 'false', '0']
+ simplecmds = ['-sysinfo', '-kpupdate', '-flistall', '-checkbl']
+ cgskip = ''
+ if '-f' in sys.argv:
+ cgskip = sysvals.configFile('cgskip.txt')
+ args = iter(sys.argv[1:])
+ mdset = False
+ for arg in args:
+ if(arg == '-h'):
+ printHelp()
+ sys.exit()
+ elif(arg == '-v'):
+ print("Version %s" % sysvals.version)
+ sys.exit()
+ elif(arg == '-verbose'):
+ sysvals.verbose = True
+ elif(arg in simplecmds):
+ cmd = arg[1:]
+ elif(arg == '-fstat'):
+ sysvals.useftrace = True
+ elif(arg == '-callgraph' or arg == '-f'):
+ sysvals.useftrace = True
+ sysvals.usecallgraph = True
+ elif(arg == '-cgdump'):
+ sysvals.cgdump = True
+ elif(arg == '-mincg'):
+ sysvals.mincglen = aslib.getArgFloat('-mincg', args, 0.0, 10000.0)
+ elif(arg == '-cgfilter'):
+ try:
+ val = args.next()
+ except:
+ doError('No callgraph functions supplied', True)
+ sysvals.setCallgraphFilter(val)
+ elif(arg == '-cgskip'):
+ try:
+ val = args.next()
+ except:
+ doError('No file supplied', True)
+ if val.lower() in switchoff:
+ cgskip = ''
+ else:
+ cgskip = sysvals.configFile(val)
+ if(not cgskip):
+ doError('%s does not exist' % cgskip)
+ elif(arg == '-bl'):
+ try:
+ val = args.next()
+ except:
+ doError('No boot loader name supplied', True)
+ if val.lower() not in ['grub']:
+ doError('Unknown boot loader: %s' % val, True)
+ sysvals.bootloader = val.lower()
+ elif(arg == '-timeprec'):
+ sysvals.setPrecision(aslib.getArgInt('-timeprec', args, 0, 6))
+ elif(arg == '-maxdepth'):
+ mdset = True
+ sysvals.max_graph_depth = aslib.getArgInt('-maxdepth', args, 0, 1000)
+ elif(arg == '-func'):
+ try:
+ val = args.next()
+ except:
+ doError('No filter functions supplied', True)
+ sysvals.useftrace = True
+ sysvals.usecallgraph = True
+ sysvals.rootCheck(True)
+ sysvals.setGraphFilter(val)
+ elif(arg == '-ftrace'):
+ try:
+ val = args.next()
+ except:
+ doError('No ftrace file supplied', True)
+ if(os.path.exists(val) == False):
+ doError('%s does not exist' % val)
+ testrun = False
+ sysvals.ftracefile = val
+ elif(arg == '-addlogs'):
+ sysvals.dmesglog = True
+ elif(arg == '-expandcg'):
+ sysvals.cgexp = True
+ elif(arg == '-dmesg'):
+ try:
+ val = args.next()
+ except:
+ doError('No dmesg file supplied', True)
+ if(os.path.exists(val) == False):
+ doError('%s does not exist' % val)
+ testrun = False
+ sysvals.dmesgfile = val
+ elif(arg == '-o'):
+ try:
+ val = args.next()
+ except:
+ doError('No subdirectory name supplied', True)
+ sysvals.testdir = sysvals.setOutputFolder(val)
+ elif(arg == '-result'):
+ try:
+ val = args.next()
+ except:
+ doError('No result file supplied', True)
+ sysvals.result = val
+ elif(arg == '-reboot'):
+ sysvals.reboot = True
+ elif(arg == '-manual'):
+ sysvals.reboot = True
+ sysvals.manual = True
+ # remaining options are only for cron job use
+ elif(arg == '-cronjob'):
+ sysvals.iscronjob = True
+ else:
+ doError('Invalid argument: '+arg, True)
+
+ # compatibility errors and access checks
+ if(sysvals.iscronjob and (sysvals.reboot or \
+ sysvals.dmesgfile or sysvals.ftracefile or cmd)):
+ doError('-cronjob is meant for batch purposes only')
+ if(sysvals.reboot and (sysvals.dmesgfile or sysvals.ftracefile)):
+ doError('-reboot and -dmesg/-ftrace are incompatible')
+ if cmd or sysvals.reboot or sysvals.iscronjob or testrun:
+ sysvals.rootCheck(True)
+ if (testrun and sysvals.useftrace) or cmd == 'flistall':
+ if not sysvals.verifyFtrace():
+ doError('Ftrace is not properly enabled')
+
+ # run utility commands
+ sysvals.cpuInfo()
+ if cmd != '':
+ if cmd == 'kpupdate':
+ updateKernelParams()
+ elif cmd == 'flistall':
+ for f in sysvals.getBootFtraceFilterFunctions():
+ print f
+ elif cmd == 'checkbl':
+ sysvals.getBootLoader()
+ print 'Boot Loader: %s\n%s' % (sysvals.bootloader, sysvals.blexec)
+ elif(cmd == 'sysinfo'):
+ sysvals.printSystemInfo(True)
+ sys.exit()
+
+ # reboot: update grub, setup a cronjob, and reboot
+ if sysvals.reboot:
+ if (sysvals.useftrace or sysvals.usecallgraph) and \
+ not sysvals.checkFtraceKernelVersion():
+ doError('Ftrace functionality requires kernel v4.10 or newer')
+ if not sysvals.manual:
+ updateKernelParams()
+ updateCron()
+ call('reboot')
+ else:
+ sysvals.manualRebootRequired()
+ sys.exit()
+
+ if sysvals.usecallgraph and cgskip:
+ sysvals.vprint('Using cgskip file: %s' % cgskip)
+ sysvals.setCallgraphBlacklist(cgskip)
+
+ # cronjob: remove the cronjob, grub changes, and disable ftrace
+ if sysvals.iscronjob:
+ updateCron(True)
+ updateKernelParams(True)
+ try:
+ sysvals.fsetVal('0', 'tracing_on')
+ except:
+ pass
+
+ # testrun: generate copies of the logs
+ if testrun:
+ retrieveLogs()
+ else:
+ sysvals.setOutputFile()
+
+ # process the log data
+ if sysvals.dmesgfile:
+ if not mdset:
+ sysvals.max_graph_depth = 0
+ data = parseKernelLog()
+ if(not data.valid):
+ doError('No initcall data found in %s' % sysvals.dmesgfile)
+ if sysvals.useftrace and sysvals.ftracefile:
+ parseTraceLog(data)
+ if sysvals.cgdump:
+ data.debugPrint()
+ sys.exit()
+ else:
+ doError('dmesg file required')
+
+ sysvals.vprint('Creating the html timeline (%s)...' % sysvals.htmlfile)
+ sysvals.vprint('Command:\n %s' % sysvals.cmdline)
+ sysvals.vprint('Kernel parameters:\n %s' % sysvals.kparams)
+ data.printDetails()
+ createBootGraph(data)
+
+ # if running as root, change output dir owner to sudo_user
+ if testrun and os.path.isdir(sysvals.testdir) and \
+ os.getuid() == 0 and 'SUDO_USER' in os.environ:
+ cmd = 'chown -R {0}:{0} {1} > /dev/null 2>&1'
+ call(cmd.format(os.environ['SUDO_USER'], sysvals.testdir), shell=True)
+
+ sysvals.stamp['boot'] = (data.tUserMode - data.start) * 1000
+ sysvals.stamp['lastinit'] = data.end * 1000
+ sysvals.outputResult(sysvals.stamp)