pm-graph: config files and installer
[linux-block.git] / tools / power / pm-graph / bootgraph.py
CommitLineData
c4980cee
TB
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
26import sys
27import time
28import os
29import string
30import re
31import platform
32import shutil
33from datetime import datetime, timedelta
34from subprocess import call, Popen, PIPE
35import 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
43class SystemValues(aslib.SystemValues):
44 title = 'BootGraph'
370f4c23 45 version = '2.1'
c4980cee
TB
46 hostname = 'localhost'
47 testtime = ''
48 kernel = ''
49 dmesgfile = ''
50 ftracefile = ''
51 htmlfile = 'bootgraph.html'
52 outfile = ''
370f4c23
TB
53 testdir = ''
54 testdirprefix = 'boot'
55 embedded = False
56 testlog = False
57 dmesglog = False
58 ftracelog = False
c4980cee 59 useftrace = False
370f4c23 60 usecallgraph = False
c4980cee
TB
61 usedevsrc = True
62 suspendmode = 'boot'
63 max_graph_depth = 2
64 graph_filter = 'do_one_initcall'
65 reboot = False
66 manual = False
67 iscronjob = False
68 timeformat = '%.6f'
370f4c23
TB
69 bootloader = 'grub'
70 blexec = []
c4980cee
TB
71 def __init__(self):
72 if('LOG_FILE' in os.environ and 'TEST_RESULTS_IDENTIFIER' in os.environ):
370f4c23
TB
73 self.embedded = True
74 self.dmesglog = True
c4980cee
TB
75 self.outfile = os.environ['LOG_FILE']
76 self.htmlfile = os.environ['LOG_FILE']
77 self.hostname = platform.node()
78 self.testtime = datetime.now().strftime('%Y-%m-%d_%H:%M:%S')
79 if os.path.exists('/proc/version'):
80 fp = open('/proc/version', 'r')
81 val = fp.read().strip()
82 fp.close()
83 self.kernel = self.kernelVersion(val)
84 else:
85 self.kernel = 'unknown'
370f4c23 86 self.testdir = datetime.now().strftime('boot-%y%m%d-%H%M%S')
c4980cee
TB
87 def kernelVersion(self, msg):
88 return msg.split()[2]
370f4c23
TB
89 def checkFtraceKernelVersion(self):
90 val = tuple(map(int, self.kernel.split('-')[0].split('.')))
91 if val >= (4, 10, 0):
92 return True
93 return False
c4980cee
TB
94 def kernelParams(self):
95 cmdline = 'initcall_debug log_buf_len=32M'
96 if self.useftrace:
370f4c23
TB
97 if self.cpucount > 0:
98 bs = min(self.memtotal / 2, 2*1024*1024) / self.cpucount
99 else:
100 bs = 131072
101 cmdline += ' trace_buf_size=%dK trace_clock=global '\
c4980cee
TB
102 'trace_options=nooverwrite,funcgraph-abstime,funcgraph-cpu,'\
103 'funcgraph-duration,funcgraph-proc,funcgraph-tail,'\
104 'nofuncgraph-overhead,context-info,graph-time '\
105 'ftrace=function_graph '\
106 'ftrace_graph_max_depth=%d '\
107 'ftrace_graph_filter=%s' % \
370f4c23 108 (bs, self.max_graph_depth, self.graph_filter)
c4980cee
TB
109 return cmdline
110 def setGraphFilter(self, val):
370f4c23
TB
111 master = self.getBootFtraceFilterFunctions()
112 fs = ''
c4980cee
TB
113 for i in val.split(','):
114 func = i.strip()
370f4c23
TB
115 if func == '':
116 doError('badly formatted filter function string')
117 if '[' in func or ']' in func:
118 doError('loadable module functions not allowed - "%s"' % func)
119 if ' ' in func:
120 doError('spaces found in filter functions - "%s"' % func)
c4980cee
TB
121 if func not in master:
122 doError('function "%s" not available for ftrace' % func)
370f4c23
TB
123 if not fs:
124 fs = func
125 else:
126 fs += ','+func
127 if not fs:
128 doError('badly formatted filter function string')
129 self.graph_filter = fs
130 def getBootFtraceFilterFunctions(self):
131 self.rootCheck(True)
132 fp = open(self.tpath+'available_filter_functions')
133 fulllist = fp.read().split('\n')
134 fp.close()
135 list = []
136 for i in fulllist:
137 if not i or ' ' in i or '[' in i or ']' in i:
138 continue
139 list.append(i)
140 return list
141 def myCronJob(self, line):
142 if '@reboot' not in line:
143 return False
144 if 'bootgraph' in line or 'analyze_boot.py' in line or '-cronjob' in line:
145 return True
146 return False
c4980cee
TB
147 def cronjobCmdString(self):
148 cmdline = '%s -cronjob' % os.path.abspath(sys.argv[0])
149 args = iter(sys.argv[1:])
150 for arg in args:
151 if arg in ['-h', '-v', '-cronjob', '-reboot']:
152 continue
370f4c23 153 elif arg in ['-o', '-dmesg', '-ftrace', '-func']:
c4980cee
TB
154 args.next()
155 continue
156 cmdline += ' '+arg
157 if self.graph_filter != 'do_one_initcall':
370f4c23
TB
158 cmdline += ' -func "%s"' % self.graph_filter
159 cmdline += ' -o "%s"' % os.path.abspath(self.testdir)
c4980cee
TB
160 return cmdline
161 def manualRebootRequired(self):
162 cmdline = self.kernelParams()
163 print 'To generate a new timeline manually, follow these steps:\n'
164 print '1. Add the CMDLINE string to your kernel command line.'
165 print '2. Reboot the system.'
166 print '3. After reboot, re-run this tool with the same arguments but no command (w/o -reboot or -manual).\n'
167 print 'CMDLINE="%s"' % cmdline
168 sys.exit()
370f4c23
TB
169 def getExec(self, cmd):
170 dirlist = ['/sbin', '/bin', '/usr/sbin', '/usr/bin',
171 '/usr/local/sbin', '/usr/local/bin']
172 for path in dirlist:
173 cmdfull = os.path.join(path, cmd)
174 if os.path.exists(cmdfull):
175 return cmdfull
176 return ''
177 def blGrub(self):
178 blcmd = ''
179 for cmd in ['update-grub', 'grub-mkconfig', 'grub2-mkconfig']:
180 if blcmd:
181 break
182 blcmd = self.getExec(cmd)
183 if not blcmd:
184 doError('[GRUB] missing update command')
185 if not os.path.exists('/etc/default/grub'):
186 doError('[GRUB] missing /etc/default/grub')
187 if 'grub2' in blcmd:
188 cfg = '/boot/grub2/grub.cfg'
189 else:
190 cfg = '/boot/grub/grub.cfg'
191 if not os.path.exists(cfg):
192 doError('[GRUB] missing %s' % cfg)
193 if 'update-grub' in blcmd:
194 self.blexec = [blcmd]
195 else:
196 self.blexec = [blcmd, '-o', cfg]
197 def getBootLoader(self):
198 if self.bootloader == 'grub':
199 self.blGrub()
200 else:
201 doError('unknown boot loader: %s' % self.bootloader)
c4980cee
TB
202
203sysvals = SystemValues()
204
205# Class: Data
206# Description:
207# The primary container for test data.
208class Data(aslib.Data):
209 dmesg = {} # root data structure
210 start = 0.0 # test start
211 end = 0.0 # test end
212 dmesgtext = [] # dmesg text file in memory
213 testnumber = 0
214 idstr = ''
215 html_device_id = 0
216 valid = False
370f4c23 217 tUserMode = 0.0
c4980cee 218 boottime = ''
370f4c23 219 phases = ['kernel', 'user']
c4980cee
TB
220 do_one_initcall = False
221 def __init__(self, num):
222 self.testnumber = num
223 self.idstr = 'a'
224 self.dmesgtext = []
225 self.dmesg = {
370f4c23
TB
226 'kernel': {'list': dict(), 'start': -1.0, 'end': -1.0, 'row': 0,
227 'order': 0, 'color': 'linear-gradient(to bottom, #fff, #bcf)'},
228 'user': {'list': dict(), 'start': -1.0, 'end': -1.0, 'row': 0,
229 'order': 1, 'color': '#fff'}
c4980cee
TB
230 }
231 def deviceTopology(self):
232 return ''
370f4c23 233 def newAction(self, phase, name, pid, start, end, ret, ulen):
c4980cee
TB
234 # new device callback for a specific phase
235 self.html_device_id += 1
236 devid = '%s%d' % (self.idstr, self.html_device_id)
237 list = self.dmesg[phase]['list']
238 length = -1.0
239 if(start >= 0 and end >= 0):
240 length = end - start
241 i = 2
242 origname = name
243 while(name in list):
244 name = '%s[%d]' % (origname, i)
245 i += 1
246 list[name] = {'name': name, 'start': start, 'end': end,
370f4c23 247 'pid': pid, 'length': length, 'row': 0, 'id': devid,
c4980cee
TB
248 'ret': ret, 'ulen': ulen }
249 return name
370f4c23 250 def deviceMatch(self, pid, cg):
c4980cee
TB
251 if cg.end - cg.start == 0:
252 return True
370f4c23
TB
253 for p in data.phases:
254 list = self.dmesg[p]['list']
255 for devname in list:
256 dev = list[devname]
257 if pid != dev['pid']:
258 continue
259 if cg.name == 'do_one_initcall':
260 if(cg.start <= dev['start'] and cg.end >= dev['end'] and dev['length'] > 0):
261 dev['ftrace'] = cg
262 self.do_one_initcall = True
263 return True
264 else:
265 if(cg.start > dev['start'] and cg.end < dev['end']):
266 if 'ftraces' not in dev:
267 dev['ftraces'] = []
268 dev['ftraces'].append(cg)
269 return True
c4980cee
TB
270 return False
271
272# ----------------- FUNCTIONS --------------------
273
370f4c23 274# Function: parseKernelLog
c4980cee 275# Description:
370f4c23
TB
276# parse a kernel log for boot data
277def parseKernelLog():
278 phase = 'kernel'
c4980cee 279 data = Data(0)
370f4c23 280 data.dmesg['kernel']['start'] = data.start = ktime = 0.0
c4980cee
TB
281 sysvals.stamp = {
282 'time': datetime.now().strftime('%B %d %Y, %I:%M:%S %p'),
283 'host': sysvals.hostname,
284 'mode': 'boot', 'kernel': ''}
285
370f4c23 286 tp = aslib.TestProps()
c4980cee
TB
287 devtemp = dict()
288 if(sysvals.dmesgfile):
289 lf = open(sysvals.dmesgfile, 'r')
290 else:
291 lf = Popen('dmesg', stdout=PIPE).stdout
292 for line in lf:
293 line = line.replace('\r\n', '')
370f4c23
TB
294 # grab the stamp and sysinfo
295 if re.match(tp.stampfmt, line):
296 tp.stamp = line
297 continue
298 elif re.match(tp.sysinfofmt, line):
299 tp.sysinfo = line
300 continue
c4980cee
TB
301 idx = line.find('[')
302 if idx > 1:
303 line = line[idx:]
304 m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line)
305 if(not m):
306 continue
307 ktime = float(m.group('ktime'))
308 if(ktime > 120):
309 break
310 msg = m.group('msg')
c4980cee
TB
311 data.dmesgtext.append(line)
312 if(ktime == 0.0 and re.match('^Linux version .*', msg)):
313 if(not sysvals.stamp['kernel']):
314 sysvals.stamp['kernel'] = sysvals.kernelVersion(msg)
315 continue
316 m = re.match('.* setting system clock to (?P<t>.*) UTC.*', msg)
317 if(m):
318 bt = datetime.strptime(m.group('t'), '%Y-%m-%d %H:%M:%S')
319 bt = bt - timedelta(seconds=int(ktime))
320 data.boottime = bt.strftime('%Y-%m-%d_%H:%M:%S')
321 sysvals.stamp['time'] = bt.strftime('%B %d %Y, %I:%M:%S %p')
322 continue
370f4c23 323 m = re.match('^calling *(?P<f>.*)\+.* @ (?P<p>[0-9]*)', msg)
c4980cee 324 if(m):
370f4c23
TB
325 func = m.group('f')
326 pid = int(m.group('p'))
327 devtemp[func] = (ktime, pid)
c4980cee
TB
328 continue
329 m = re.match('^initcall *(?P<f>.*)\+.* returned (?P<r>.*) after (?P<t>.*) usecs', msg)
330 if(m):
331 data.valid = True
370f4c23 332 data.end = ktime
c4980cee
TB
333 f, r, t = m.group('f', 'r', 't')
334 if(f in devtemp):
370f4c23
TB
335 start, pid = devtemp[f]
336 data.newAction(phase, f, pid, start, ktime, int(r), int(t))
c4980cee
TB
337 del devtemp[f]
338 continue
339 if(re.match('^Freeing unused kernel memory.*', msg)):
370f4c23
TB
340 data.tUserMode = ktime
341 data.dmesg['kernel']['end'] = ktime
342 data.dmesg['user']['start'] = ktime
343 phase = 'user'
344
345 if tp.stamp:
346 sysvals.stamp = 0
347 tp.parseStamp(data, sysvals)
348 data.dmesg['user']['end'] = data.end
c4980cee
TB
349 lf.close()
350 return data
351
370f4c23 352# Function: parseTraceLog
c4980cee
TB
353# Description:
354# Check if trace is available and copy to a temp file
370f4c23 355def parseTraceLog(data):
c4980cee
TB
356 # parse the trace log
357 ftemp = dict()
358 tp = aslib.TestProps()
359 tp.setTracerType('function_graph')
360 tf = open(sysvals.ftracefile, 'r')
361 for line in tf:
362 if line[0] == '#':
363 continue
364 m = re.match(tp.ftrace_line_fmt, line.strip())
365 if(not m):
366 continue
367 m_time, m_proc, m_pid, m_msg, m_dur = \
368 m.group('time', 'proc', 'pid', 'msg', 'dur')
369 if float(m_time) > data.end:
370 break
371 if(m_time and m_pid and m_msg):
372 t = aslib.FTraceLine(m_time, m_msg, m_dur)
373 pid = int(m_pid)
374 else:
375 continue
376 if t.fevent or t.fkprobe:
377 continue
378 key = (m_proc, pid)
379 if(key not in ftemp):
380 ftemp[key] = []
381 ftemp[key].append(aslib.FTraceCallGraph(pid))
382 cg = ftemp[key][-1]
383 if(cg.addLine(t)):
384 ftemp[key].append(aslib.FTraceCallGraph(pid))
385 tf.close()
386
387 # add the callgraph data to the device hierarchy
388 for key in ftemp:
389 proc, pid = key
390 for cg in ftemp[key]:
391 if len(cg.list) < 1 or cg.invalid:
392 continue
393 if(not cg.postProcess()):
394 print('Sanity check failed for %s-%d' % (proc, pid))
395 continue
396 # match cg data to devices
370f4c23 397 if not data.deviceMatch(pid, cg):
c4980cee
TB
398 print ' BAD: %s %s-%d [%f - %f]' % (cg.name, proc, pid, cg.start, cg.end)
399
370f4c23
TB
400# Function: retrieveLogs
401# Description:
402# Create copies of dmesg and/or ftrace for later processing
403def retrieveLogs():
404 # check ftrace is configured first
405 if sysvals.useftrace:
406 tracer = sysvals.fgetVal('current_tracer').strip()
407 if tracer != 'function_graph':
408 doError('ftrace not configured for a boot callgraph')
409 # create the folder and get dmesg
410 sysvals.systemInfo(aslib.dmidecode(sysvals.mempath))
411 sysvals.initTestOutput('boot')
412 sysvals.writeDatafileHeader(sysvals.dmesgfile)
413 call('dmesg >> '+sysvals.dmesgfile, shell=True)
414 if not sysvals.useftrace:
415 return
416 # get ftrace
417 sysvals.writeDatafileHeader(sysvals.ftracefile)
418 call('cat '+sysvals.tpath+'trace >> '+sysvals.ftracefile, shell=True)
419
c4980cee
TB
420# Function: colorForName
421# Description:
422# Generate a repeatable color from a list for a given name
423def colorForName(name):
424 list = [
425 ('c1', '#ec9999'),
426 ('c2', '#ffc1a6'),
427 ('c3', '#fff0a6'),
428 ('c4', '#adf199'),
429 ('c5', '#9fadea'),
430 ('c6', '#a699c1'),
431 ('c7', '#ad99b4'),
432 ('c8', '#eaffea'),
433 ('c9', '#dcecfb'),
434 ('c10', '#ffffea')
435 ]
436 i = 0
437 total = 0
438 count = len(list)
439 while i < len(name):
440 total += ord(name[i])
441 i += 1
442 return list[total % count]
443
444def cgOverview(cg, minlen):
445 stats = dict()
446 large = []
447 for l in cg.list:
448 if l.fcall and l.depth == 1:
449 if l.length >= minlen:
450 large.append(l)
451 if l.name not in stats:
452 stats[l.name] = [0, 0.0]
453 stats[l.name][0] += (l.length * 1000.0)
454 stats[l.name][1] += 1
455 return (large, stats)
456
457# Function: createBootGraph
458# Description:
459# Create the output html file from the resident test data
460# Arguments:
461# testruns: array of Data objects from parseKernelLog or parseTraceLog
462# Output:
463# True if the html file was created, false if it failed
370f4c23 464def createBootGraph(data):
c4980cee
TB
465 # html function templates
466 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'
467 html_timetotal = '<table class="time1">\n<tr>'\
370f4c23
TB
468 '<td class="blue">Init process starts @ <b>{0} ms</b></td>'\
469 '<td class="blue">Last initcall ends @ <b>{1} ms</b></td>'\
c4980cee
TB
470 '</tr>\n</table>\n'
471
472 # device timeline
473 devtl = aslib.Timeline(100, 20)
474
475 # write the test title and general info header
370f4c23 476 devtl.createHeader(sysvals)
c4980cee
TB
477
478 # Generate the header for this timeline
479 t0 = data.start
480 tMax = data.end
481 tTotal = tMax - t0
482 if(tTotal == 0):
483 print('ERROR: No timeline data')
484 return False
370f4c23
TB
485 user_mode = '%.0f'%(data.tUserMode*1000)
486 last_init = '%.0f'%(tTotal*1000)
487 devtl.html += html_timetotal.format(user_mode, last_init)
c4980cee
TB
488
489 # determine the maximum number of rows we need to draw
c4980cee 490 devlist = []
370f4c23
TB
491 for p in data.phases:
492 list = data.dmesg[p]['list']
493 for devname in list:
494 d = aslib.DevItem(0, p, list[devname])
495 devlist.append(d)
496 devtl.getPhaseRows(devlist, 0, 'start')
c4980cee
TB
497 devtl.calcTotalRows()
498
499 # draw the timeline background
500 devtl.createZoomBox()
370f4c23
TB
501 devtl.html += devtl.html_tblock.format('boot', '0', '100', devtl.scaleH)
502 for p in data.phases:
503 phase = data.dmesg[p]
504 length = phase['end']-phase['start']
505 left = '%.3f' % (((phase['start']-t0)*100.0)/tTotal)
506 width = '%.3f' % ((length*100.0)/tTotal)
507 devtl.html += devtl.html_phase.format(left, width, \
508 '%.3f'%devtl.scaleH, '%.3f'%devtl.bodyH, \
509 phase['color'], '')
c4980cee
TB
510
511 # draw the device timeline
512 num = 0
513 devstats = dict()
370f4c23
TB
514 for phase in data.phases:
515 list = data.dmesg[phase]['list']
516 for devname in sorted(list):
517 cls, color = colorForName(devname)
518 dev = list[devname]
519 info = '@|%.3f|%.3f|%.3f|%d' % (dev['start']*1000.0, dev['end']*1000.0,
520 dev['ulen']/1000.0, dev['ret'])
521 devstats[dev['id']] = {'info':info}
522 dev['color'] = color
523 height = devtl.phaseRowHeight(0, phase, dev['row'])
524 top = '%.6f' % ((dev['row']*height) + devtl.scaleH)
525 left = '%.6f' % (((dev['start']-t0)*100)/tTotal)
526 width = '%.6f' % (((dev['end']-dev['start'])*100)/tTotal)
527 length = ' (%0.3f ms) ' % ((dev['end']-dev['start'])*1000)
528 devtl.html += devtl.html_device.format(dev['id'],
529 devname+length+phase+'_mode', left, top, '%.3f'%height,
530 width, devname, ' '+cls, '')
531 rowtop = devtl.phaseRowTop(0, phase, dev['row'])
532 height = '%.6f' % (devtl.rowH / 2)
533 top = '%.6f' % (rowtop + devtl.scaleH + (devtl.rowH / 2))
534 if data.do_one_initcall:
535 if('ftrace' not in dev):
536 continue
537 cg = dev['ftrace']
538 large, stats = cgOverview(cg, 0.001)
539 devstats[dev['id']]['fstat'] = stats
540 for l in large:
541 left = '%f' % (((l.time-t0)*100)/tTotal)
542 width = '%f' % (l.length*100/tTotal)
543 title = '%s (%0.3fms)' % (l.name, l.length * 1000.0)
544 devtl.html += html_srccall.format(l.name, left,
545 top, height, width, title, 'x%d'%num)
546 num += 1
547 continue
548 if('ftraces' not in dev):
c4980cee 549 continue
370f4c23
TB
550 for cg in dev['ftraces']:
551 left = '%f' % (((cg.start-t0)*100)/tTotal)
552 width = '%f' % ((cg.end-cg.start)*100/tTotal)
553 cglen = (cg.end - cg.start) * 1000.0
554 title = '%s (%0.3fms)' % (cg.name, cglen)
555 cg.id = 'x%d' % num
556 devtl.html += html_srccall.format(cg.name, left,
557 top, height, width, title, dev['id']+cg.id)
c4980cee 558 num += 1
c4980cee
TB
559
560 # draw the time scale, try to make the number of labels readable
370f4c23 561 devtl.createTimeScale(t0, tMax, tTotal, 'boot')
c4980cee
TB
562 devtl.html += '</div>\n'
563
564 # timeline is finished
565 devtl.html += '</div>\n</div>\n'
566
370f4c23
TB
567 # draw a legend which describes the phases by color
568 devtl.html += '<div class="legend">\n'
569 pdelta = 20.0
570 pmargin = 36.0
571 for phase in data.phases:
572 order = '%.2f' % ((data.dmesg[phase]['order'] * pdelta) + pmargin)
573 devtl.html += devtl.html_legend.format(order, \
574 data.dmesg[phase]['color'], phase+'_mode', phase[0])
575 devtl.html += '</div>\n'
576
c4980cee
TB
577 if(sysvals.outfile == sysvals.htmlfile):
578 hf = open(sysvals.htmlfile, 'a')
579 else:
580 hf = open(sysvals.htmlfile, 'w')
581
582 # add the css if this is not an embedded run
583 extra = '\
584 .c1 {background:rgba(209,0,0,0.4);}\n\
585 .c2 {background:rgba(255,102,34,0.4);}\n\
586 .c3 {background:rgba(255,218,33,0.4);}\n\
587 .c4 {background:rgba(51,221,0,0.4);}\n\
588 .c5 {background:rgba(17,51,204,0.4);}\n\
589 .c6 {background:rgba(34,0,102,0.4);}\n\
590 .c7 {background:rgba(51,0,68,0.4);}\n\
591 .c8 {background:rgba(204,255,204,0.4);}\n\
592 .c9 {background:rgba(169,208,245,0.4);}\n\
593 .c10 {background:rgba(255,255,204,0.4);}\n\
594 .vt {transform:rotate(-60deg);transform-origin:0 0;}\n\
595 table.fstat {table-layout:fixed;padding:150px 15px 0 0;font-size:10px;column-width:30px;}\n\
596 .fstat th {width:55px;}\n\
597 .fstat td {text-align:left;width:35px;}\n\
598 .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\
599 .srccall:hover {color:white;font-weight:bold;border:1px solid white;}\n'
370f4c23 600 if(not sysvals.embedded):
c4980cee
TB
601 aslib.addCSS(hf, sysvals, 1, False, extra)
602
603 # write the device timeline
604 hf.write(devtl.html)
605
606 # add boot specific html
607 statinfo = 'var devstats = {\n'
608 for n in sorted(devstats):
609 statinfo += '\t"%s": [\n\t\t"%s",\n' % (n, devstats[n]['info'])
610 if 'fstat' in devstats[n]:
611 funcs = devstats[n]['fstat']
612 for f in sorted(funcs, key=funcs.get, reverse=True):
613 if funcs[f][0] < 0.01 and len(funcs) > 10:
614 break
615 statinfo += '\t\t"%f|%s|%d",\n' % (funcs[f][0], f, funcs[f][1])
616 statinfo += '\t],\n'
617 statinfo += '};\n'
618 html = \
619 '<div id="devicedetailtitle"></div>\n'\
620 '<div id="devicedetail" style="display:none;">\n'\
370f4c23
TB
621 '<div id="devicedetail0">\n'
622 for p in data.phases:
623 phase = data.dmesg[p]
624 html += devtl.html_phaselet.format(p+'_mode', '0', '100', phase['color'])
625 html += '</div>\n</div>\n'\
c4980cee
TB
626 '<script type="text/javascript">\n'+statinfo+\
627 '</script>\n'
628 hf.write(html)
629
630 # add the callgraph html
631 if(sysvals.usecallgraph):
632 aslib.addCallgraphs(sysvals, hf, data)
633
634 # add the dmesg log as a hidden div
370f4c23 635 if sysvals.dmesglog:
c4980cee
TB
636 hf.write('<div id="dmesglog" style="display:none;">\n')
637 for line in data.dmesgtext:
638 line = line.replace('<', '&lt').replace('>', '&gt')
639 hf.write(line)
640 hf.write('</div>\n')
641
370f4c23 642 if(not sysvals.embedded):
c4980cee
TB
643 # write the footer and close
644 aslib.addScriptCode(hf, [data])
645 hf.write('</body>\n</html>\n')
646 else:
647 # embedded out will be loaded in a page, skip the js
648 hf.write('<div id=bounds style=display:none>%f,%f</div>' % \
370f4c23 649 (data.start*1000, data.end*1000))
c4980cee
TB
650 hf.close()
651 return True
652
653# Function: updateCron
654# Description:
655# (restore=False) Set the tool to run automatically on reboot
656# (restore=True) Restore the original crontab
657def updateCron(restore=False):
658 if not restore:
659 sysvals.rootUser(True)
660 crondir = '/var/spool/cron/crontabs/'
370f4c23
TB
661 if not os.path.exists(crondir):
662 crondir = '/var/spool/cron/'
c4980cee
TB
663 if not os.path.exists(crondir):
664 doError('%s not found' % crondir)
370f4c23
TB
665 cronfile = crondir+'root'
666 backfile = crondir+'root-analyze_boot-backup'
667 cmd = sysvals.getExec('crontab')
668 if not cmd:
c4980cee
TB
669 doError('crontab not found')
670 # on restore: move the backup cron back into place
671 if restore:
672 if os.path.exists(backfile):
673 shutil.move(backfile, cronfile)
370f4c23 674 call([cmd, cronfile])
c4980cee
TB
675 return
676 # backup current cron and install new one with reboot
677 if os.path.exists(cronfile):
678 shutil.move(cronfile, backfile)
679 else:
680 fp = open(backfile, 'w')
681 fp.close()
682 res = -1
683 try:
684 fp = open(backfile, 'r')
685 op = open(cronfile, 'w')
686 for line in fp:
370f4c23 687 if not sysvals.myCronJob(line):
c4980cee
TB
688 op.write(line)
689 continue
690 fp.close()
691 op.write('@reboot python %s\n' % sysvals.cronjobCmdString())
692 op.close()
370f4c23 693 res = call([cmd, cronfile])
c4980cee
TB
694 except Exception, e:
695 print 'Exception: %s' % str(e)
696 shutil.move(backfile, cronfile)
697 res = -1
698 if res != 0:
699 doError('crontab failed')
700
701# Function: updateGrub
702# Description:
703# update grub.cfg for all kernels with our parameters
704def updateGrub(restore=False):
705 # call update-grub on restore
706 if restore:
707 try:
370f4c23 708 call(sysvals.blexec, stderr=PIPE, stdout=PIPE,
c4980cee
TB
709 env={'PATH': '.:/sbin:/usr/sbin:/usr/bin:/sbin:/bin'})
710 except Exception, e:
711 print 'Exception: %s\n' % str(e)
712 return
c4980cee 713 # extract the option and create a grub config without it
370f4c23 714 sysvals.rootUser(True)
c4980cee
TB
715 tgtopt = 'GRUB_CMDLINE_LINUX_DEFAULT'
716 cmdline = ''
370f4c23 717 grubfile = '/etc/default/grub'
c4980cee
TB
718 tempfile = '/etc/default/grub.analyze_boot'
719 shutil.move(grubfile, tempfile)
720 res = -1
721 try:
722 fp = open(tempfile, 'r')
723 op = open(grubfile, 'w')
724 cont = False
725 for line in fp:
726 line = line.strip()
727 if len(line) == 0 or line[0] == '#':
728 continue
729 opt = line.split('=')[0].strip()
730 if opt == tgtopt:
731 cmdline = line.split('=', 1)[1].strip('\\')
732 if line[-1] == '\\':
733 cont = True
734 elif cont:
735 cmdline += line.strip('\\')
736 if line[-1] != '\\':
737 cont = False
738 else:
739 op.write('%s\n' % line)
740 fp.close()
741 # if the target option value is in quotes, strip them
742 sp = '"'
743 val = cmdline.strip()
370f4c23 744 if val and (val[0] == '\'' or val[0] == '"'):
c4980cee
TB
745 sp = val[0]
746 val = val.strip(sp)
747 cmdline = val
748 # append our cmd line options
749 if len(cmdline) > 0:
750 cmdline += ' '
751 cmdline += sysvals.kernelParams()
752 # write out the updated target option
753 op.write('\n%s=%s%s%s\n' % (tgtopt, sp, cmdline, sp))
754 op.close()
370f4c23 755 res = call(sysvals.blexec)
c4980cee
TB
756 os.remove(grubfile)
757 except Exception, e:
758 print 'Exception: %s' % str(e)
759 res = -1
760 # cleanup
761 shutil.move(tempfile, grubfile)
762 if res != 0:
370f4c23 763 doError('update grub failed')
c4980cee 764
370f4c23 765# Function: updateKernelParams
c4980cee 766# Description:
370f4c23
TB
767# update boot conf for all kernels with our parameters
768def updateKernelParams(restore=False):
769 # find the boot loader
770 sysvals.getBootLoader()
771 if sysvals.bootloader == 'grub':
772 updateGrub(restore)
773
774# Function: doError Description:
c4980cee
TB
775# generic error function for catastrphic failures
776# Arguments:
777# msg: the error message to print
778# help: True if printHelp should be called after, False otherwise
779def doError(msg, help=False):
780 if help == True:
781 printHelp()
782 print 'ERROR: %s\n' % msg
783 sys.exit()
784
785# Function: printHelp
786# Description:
787# print out the help text
788def printHelp():
789 print('')
370f4c23 790 print('%s v%s' % (sysvals.title, sysvals.version))
c4980cee
TB
791 print('Usage: bootgraph <options> <command>')
792 print('')
793 print('Description:')
794 print(' This tool reads in a dmesg log of linux kernel boot and')
795 print(' creates an html representation of the boot timeline up to')
796 print(' the start of the init process.')
797 print('')
798 print(' If no specific command is given the tool reads the current dmesg')
370f4c23
TB
799 print(' and/or ftrace log and creates a timeline')
800 print('')
801 print(' Generates output files in subdirectory: boot-yymmdd-HHMMSS')
802 print(' HTML output: <hostname>_boot.html')
803 print(' raw dmesg output: <hostname>_boot_dmesg.txt')
804 print(' raw ftrace output: <hostname>_boot_ftrace.txt')
c4980cee
TB
805 print('')
806 print('Options:')
807 print(' -h Print this help text')
808 print(' -v Print the current tool version')
809 print(' -addlogs Add the dmesg log to the html output')
370f4c23
TB
810 print(' -o name Overrides the output subdirectory name when running a new test')
811 print(' default: boot-{date}-{time}')
c4980cee
TB
812 print(' [advanced]')
813 print(' -f Use ftrace to add function detail (default: disabled)')
814 print(' -callgraph Add callgraph detail, can be very large (default: disabled)')
815 print(' -maxdepth N limit the callgraph data to N call levels (default: 2)')
816 print(' -mincg ms Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)')
817 print(' -timeprec N Number of significant digits in timestamps (0:S, 3:ms, [6:us])')
818 print(' -expandcg pre-expand the callgraph data in the html output (default: disabled)')
370f4c23
TB
819 print(' -func list Limit ftrace to comma-delimited list of functions (default: do_one_initcall)')
820 print(' -cgfilter S Filter the callgraph output in the timeline')
821 print(' -bl name Use the following boot loader for kernel params (default: grub)')
c4980cee 822 print(' -reboot Reboot the machine automatically and generate a new timeline')
370f4c23
TB
823 print(' -manual Show the steps to generate a new timeline manually (used with -reboot)')
824 print('')
825 print('Other commands:')
c4980cee 826 print(' -flistall Print all functions capable of being captured in ftrace')
370f4c23
TB
827 print(' -sysinfo Print out system info extracted from BIOS')
828 print(' [redo]')
829 print(' -dmesg file Create HTML output using dmesg input (used with -ftrace)')
830 print(' -ftrace file Create HTML output using ftrace input (used with -dmesg)')
c4980cee
TB
831 print('')
832 return True
833
834# ----------------- MAIN --------------------
835# exec start (skipped if script is loaded as library)
836if __name__ == '__main__':
837 # loop through the command line arguments
838 cmd = ''
370f4c23
TB
839 testrun = True
840 simplecmds = ['-sysinfo', '-kpupdate', '-flistall', '-checkbl']
c4980cee
TB
841 args = iter(sys.argv[1:])
842 for arg in args:
843 if(arg == '-h'):
844 printHelp()
845 sys.exit()
846 elif(arg == '-v'):
370f4c23 847 print("Version %s" % sysvals.version)
c4980cee
TB
848 sys.exit()
849 elif(arg in simplecmds):
850 cmd = arg[1:]
851 elif(arg == '-f'):
852 sysvals.useftrace = True
853 elif(arg == '-callgraph'):
854 sysvals.useftrace = True
855 sysvals.usecallgraph = True
856 elif(arg == '-mincg'):
857 sysvals.mincglen = aslib.getArgFloat('-mincg', args, 0.0, 10000.0)
370f4c23
TB
858 elif(arg == '-cgfilter'):
859 try:
860 val = args.next()
861 except:
862 doError('No callgraph functions supplied', True)
863 sysvals.setDeviceFilter(val)
864 elif(arg == '-bl'):
865 try:
866 val = args.next()
867 except:
868 doError('No boot loader name supplied', True)
869 if val.lower() not in ['grub']:
870 doError('Unknown boot loader: %s' % val, True)
871 sysvals.bootloader = val.lower()
c4980cee
TB
872 elif(arg == '-timeprec'):
873 sysvals.setPrecision(aslib.getArgInt('-timeprec', args, 0, 6))
874 elif(arg == '-maxdepth'):
875 sysvals.max_graph_depth = aslib.getArgInt('-maxdepth', args, 0, 1000)
370f4c23 876 elif(arg == '-func'):
c4980cee
TB
877 try:
878 val = args.next()
879 except:
880 doError('No filter functions supplied', True)
370f4c23
TB
881 sysvals.useftrace = True
882 sysvals.usecallgraph = True
883 sysvals.rootCheck(True)
c4980cee
TB
884 sysvals.setGraphFilter(val)
885 elif(arg == '-ftrace'):
886 try:
887 val = args.next()
888 except:
889 doError('No ftrace file supplied', True)
890 if(os.path.exists(val) == False):
891 doError('%s does not exist' % val)
370f4c23 892 testrun = False
c4980cee
TB
893 sysvals.ftracefile = val
894 elif(arg == '-addlogs'):
370f4c23 895 sysvals.dmesglog = True
c4980cee
TB
896 elif(arg == '-expandcg'):
897 sysvals.cgexp = True
898 elif(arg == '-dmesg'):
899 try:
900 val = args.next()
901 except:
902 doError('No dmesg file supplied', True)
903 if(os.path.exists(val) == False):
904 doError('%s does not exist' % val)
905 if(sysvals.htmlfile == val or sysvals.outfile == val):
906 doError('Output filename collision')
370f4c23 907 testrun = False
c4980cee
TB
908 sysvals.dmesgfile = val
909 elif(arg == '-o'):
910 try:
911 val = args.next()
912 except:
370f4c23
TB
913 doError('No subdirectory name supplied', True)
914 sysvals.testdir = sysvals.setOutputFolder(val)
c4980cee 915 elif(arg == '-reboot'):
c4980cee
TB
916 sysvals.reboot = True
917 elif(arg == '-manual'):
918 sysvals.reboot = True
919 sysvals.manual = True
920 # remaining options are only for cron job use
921 elif(arg == '-cronjob'):
922 sysvals.iscronjob = True
c4980cee
TB
923 else:
924 doError('Invalid argument: '+arg, True)
925
370f4c23
TB
926 # compatibility errors and access checks
927 if(sysvals.iscronjob and (sysvals.reboot or \
928 sysvals.dmesgfile or sysvals.ftracefile or cmd)):
929 doError('-cronjob is meant for batch purposes only')
930 if(sysvals.reboot and (sysvals.dmesgfile or sysvals.ftracefile)):
931 doError('-reboot and -dmesg/-ftrace are incompatible')
932 if cmd or sysvals.reboot or sysvals.iscronjob or testrun:
933 sysvals.rootCheck(True)
934 if (testrun and sysvals.useftrace) or cmd == 'flistall':
935 if not sysvals.verifyFtrace():
936 doError('Ftrace is not properly enabled')
937
938 # run utility commands
939 sysvals.cpuInfo()
c4980cee 940 if cmd != '':
370f4c23
TB
941 if cmd == 'kpupdate':
942 updateKernelParams()
c4980cee 943 elif cmd == 'flistall':
370f4c23
TB
944 for f in sysvals.getBootFtraceFilterFunctions():
945 print f
946 elif cmd == 'checkbl':
947 sysvals.getBootLoader()
948 print 'Boot Loader: %s\n%s' % (sysvals.bootloader, sysvals.blexec)
949 elif(cmd == 'sysinfo'):
950 sysvals.printSystemInfo()
c4980cee
TB
951 sys.exit()
952
370f4c23 953 # reboot: update grub, setup a cronjob, and reboot
c4980cee 954 if sysvals.reboot:
370f4c23
TB
955 if (sysvals.useftrace or sysvals.usecallgraph) and \
956 not sysvals.checkFtraceKernelVersion():
957 doError('Ftrace functionality requires kernel v4.10 or newer')
c4980cee 958 if not sysvals.manual:
370f4c23 959 updateKernelParams()
c4980cee
TB
960 updateCron()
961 call('reboot')
962 else:
963 sysvals.manualRebootRequired()
964 sys.exit()
965
370f4c23 966 # cronjob: remove the cronjob, grub changes, and disable ftrace
c4980cee
TB
967 if sysvals.iscronjob:
968 updateCron(True)
370f4c23
TB
969 updateKernelParams(True)
970 try:
971 sysvals.fsetVal('0', 'tracing_on')
972 except:
973 pass
c4980cee 974
370f4c23
TB
975 # testrun: generate copies of the logs
976 if testrun:
977 retrieveLogs()
978 else:
979 sysvals.setOutputFile()
c4980cee 980
370f4c23
TB
981 # process the log data
982 if sysvals.dmesgfile:
983 data = parseKernelLog()
984 if(not data.valid):
c4980cee 985 doError('No initcall data found in %s' % sysvals.dmesgfile)
370f4c23
TB
986 if sysvals.useftrace and sysvals.ftracefile:
987 parseTraceLog(data)
988 else:
989 doError('dmesg file required')
c4980cee
TB
990
991 print(' Host: %s' % sysvals.hostname)
992 print(' Test time: %s' % sysvals.testtime)
993 print(' Boot time: %s' % data.boottime)
994 print('Kernel Version: %s' % sysvals.kernel)
995 print(' Kernel start: %.3f' % (data.start * 1000))
370f4c23
TB
996 print('Usermode start: %.3f' % (data.tUserMode * 1000))
997 print('Last Init Call: %.3f' % (data.end * 1000))
998
999 # handle embedded output logs
1000 if(sysvals.outfile and sysvals.embedded):
1001 fp = open(sysvals.outfile, 'w')
1002 fp.write('pass %s initstart %.3f end %.3f boot %s\n' %
1003 (data.valid, data.tUserMode*1000, data.end*1000, data.boottime))
1004 fp.close()
1005
1006 createBootGraph(data)
c4980cee 1007
370f4c23
TB
1008 # if running as root, change output dir owner to sudo_user
1009 if testrun and os.path.isdir(sysvals.testdir) and \
1010 os.getuid() == 0 and 'SUDO_USER' in os.environ:
1011 cmd = 'chown -R {0}:{0} {1} > /dev/null 2>&1'
1012 call(cmd.format(os.environ['SUDO_USER'], sysvals.testdir), shell=True)