]> Git Repo - linux.git/blob - tools/power/pm-graph/bootgraph.py
libbpf: fix GCC8 warning for strncpy
[linux.git] / tools / power / pm-graph / bootgraph.py
1 #!/usr/bin/python2
2 # SPDX-License-Identifier: GPL-2.0-only
3 #
4 # Tool for analyzing boot timing
5 # Copyright (c) 2013, Intel Corporation.
6 #
7 # Authors:
8 #        Todd Brandt <[email protected]>
9 #
10 # Description:
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.
14 #
15
16 # ----------------- LIBRARIES --------------------
17
18 import sys
19 import time
20 import os
21 import string
22 import re
23 import platform
24 import shutil
25 from datetime import datetime, timedelta
26 from subprocess import call, Popen, PIPE
27 import sleepgraph as aslib
28
29 def pprint(msg):
30         print(msg)
31         sys.stdout.flush()
32
33 # ----------------- CLASSES --------------------
34
35 # Class: SystemValues
36 # Description:
37 #        A global, single-instance container used to
38 #        store system values and test parameters
39 class SystemValues(aslib.SystemValues):
40         title = 'BootGraph'
41         version = '2.2'
42         hostname = 'localhost'
43         testtime = ''
44         kernel = ''
45         dmesgfile = ''
46         ftracefile = ''
47         htmlfile = 'bootgraph.html'
48         testdir = ''
49         kparams = ''
50         result = ''
51         useftrace = False
52         usecallgraph = False
53         suspendmode = 'boot'
54         max_graph_depth = 2
55         graph_filter = 'do_one_initcall'
56         reboot = False
57         manual = False
58         iscronjob = False
59         timeformat = '%.6f'
60         bootloader = 'grub'
61         blexec = []
62         def __init__(self):
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()
68                         fp.close()
69                         self.kernel = self.kernelVersion(val)
70                 else:
71                         self.kernel = 'unknown'
72                 self.testdir = datetime.now().strftime('boot-%y%m%d-%H%M%S')
73         def kernelVersion(self, msg):
74                 return msg.split()[2]
75         def checkFtraceKernelVersion(self):
76                 val = tuple(map(int, self.kernel.split('-')[0].split('.')))
77                 if val >= (4, 10, 0):
78                         return True
79                 return False
80         def kernelParams(self):
81                 cmdline = 'initcall_debug log_buf_len=32M'
82                 if self.useftrace:
83                         if self.cpucount > 0:
84                                 bs = min(self.memtotal / 2, 2*1024*1024) / self.cpucount
85                         else:
86                                 bs = 131072
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)
95                 return cmdline
96         def setGraphFilter(self, val):
97                 master = self.getBootFtraceFilterFunctions()
98                 fs = ''
99                 for i in val.split(','):
100                         func = i.strip()
101                         if func == '':
102                                 doError('badly formatted filter function string')
103                         if '[' in func or ']' in func:
104                                 doError('loadable module functions not allowed - "%s"' % func)
105                         if ' ' in 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)
109                         if not fs:
110                                 fs = func
111                         else:
112                                 fs += ','+func
113                 if not fs:
114                         doError('badly formatted filter function string')
115                 self.graph_filter = fs
116         def getBootFtraceFilterFunctions(self):
117                 self.rootCheck(True)
118                 fp = open(self.tpath+'available_filter_functions')
119                 fulllist = fp.read().split('\n')
120                 fp.close()
121                 list = []
122                 for i in fulllist:
123                         if not i or ' ' in i or '[' in i or ']' in i:
124                                 continue
125                         list.append(i)
126                 return list
127         def myCronJob(self, line):
128                 if '@reboot' not in line:
129                         return False
130                 if 'bootgraph' in line or 'analyze_boot.py' in line or '-cronjob' in line:
131                         return True
132                 return False
133         def cronjobCmdString(self):
134                 cmdline = '%s -cronjob' % os.path.abspath(sys.argv[0])
135                 args = iter(sys.argv[1:])
136                 for arg in args:
137                         if arg in ['-h', '-v', '-cronjob', '-reboot', '-verbose']:
138                                 continue
139                         elif arg in ['-o', '-dmesg', '-ftrace', '-func']:
140                                 args.next()
141                                 continue
142                         elif arg == '-result':
143                                 cmdline += ' %s "%s"' % (arg, os.path.abspath(args.next()))
144                                 continue
145                         elif arg == '-cgskip':
146                                 file = self.configFile(args.next())
147                                 cmdline += ' %s "%s"' % (arg, os.path.abspath(file))
148                                 continue
149                         cmdline += ' '+arg
150                 if self.graph_filter != 'do_one_initcall':
151                         cmdline += ' -func "%s"' % self.graph_filter
152                 cmdline += ' -o "%s"' % os.path.abspath(self.testdir)
153                 return cmdline
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)
161                 sys.exit()
162         def blGrub(self):
163                 blcmd = ''
164                 for cmd in ['update-grub', 'grub-mkconfig', 'grub2-mkconfig']:
165                         if blcmd:
166                                 break
167                         blcmd = self.getExec(cmd)
168                 if not blcmd:
169                         doError('[GRUB] missing update command')
170                 if not os.path.exists('/etc/default/grub'):
171                         doError('[GRUB] missing /etc/default/grub')
172                 if 'grub2' in blcmd:
173                         cfg = '/boot/grub2/grub.cfg'
174                 else:
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]
180                 else:
181                         self.blexec = [blcmd, '-o', cfg]
182         def getBootLoader(self):
183                 if self.bootloader == 'grub':
184                         self.blGrub()
185                 else:
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)
194                 fp.close()
195
196 sysvals = SystemValues()
197
198 # Class: Data
199 # Description:
200 #        The primary container for test data.
201 class Data(aslib.Data):
202         dmesg = {}  # root data structure
203         start = 0.0 # test start
204         end = 0.0   # test end
205         dmesgtext = []   # dmesg text file in memory
206         testnumber = 0
207         idstr = ''
208         html_device_id = 0
209         valid = False
210         tUserMode = 0.0
211         boottime = ''
212         phases = ['kernel', 'user']
213         do_one_initcall = False
214         def __init__(self, num):
215                 self.testnumber = num
216                 self.idstr = 'a'
217                 self.dmesgtext = []
218                 self.dmesg = {
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'}
223                 }
224         def deviceTopology(self):
225                 return ''
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']
231                 length = -1.0
232                 if(start >= 0 and end >= 0):
233                         length = end - start
234                 i = 2
235                 origname = name
236                 while(name in list):
237                         name = '%s[%d]' % (origname, i)
238                         i += 1
239                 list[name] = {'name': name, 'start': start, 'end': end,
240                         'pid': pid, 'length': length, 'row': 0, 'id': devid,
241                         'ret': ret, 'ulen': ulen }
242                 return name
243         def deviceMatch(self, pid, cg):
244                 if cg.end - cg.start == 0:
245                         return ''
246                 for p in data.phases:
247                         list = self.dmesg[p]['list']
248                         for devname in list:
249                                 dev = list[devname]
250                                 if pid != dev['pid']:
251                                         continue
252                                 if cg.name == 'do_one_initcall':
253                                         if(cg.start <= dev['start'] and cg.end >= dev['end'] and dev['length'] > 0):
254                                                 dev['ftrace'] = cg
255                                                 self.do_one_initcall = True
256                                                 return devname
257                                 else:
258                                         if(cg.start > dev['start'] and cg.end < dev['end']):
259                                                 if 'ftraces' not in dev:
260                                                         dev['ftraces'] = []
261                                                 dev['ftraces'].append(cg)
262                                                 return devname
263                 return ''
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))
275
276 # ----------------- FUNCTIONS --------------------
277
278 # Function: parseKernelLog
279 # Description:
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))
284         phase = 'kernel'
285         data = Data(0)
286         data.dmesg['kernel']['start'] = data.start = ktime = 0.0
287         sysvals.stamp = {
288                 'time': datetime.now().strftime('%B %d %Y, %I:%M:%S %p'),
289                 'host': sysvals.hostname,
290                 'mode': 'boot', 'kernel': ''}
291
292         tp = aslib.TestProps()
293         devtemp = dict()
294         if(sysvals.dmesgfile):
295                 lf = open(sysvals.dmesgfile, 'r')
296         else:
297                 lf = Popen('dmesg', stdout=PIPE).stdout
298         for line in lf:
299                 line = line.replace('\r\n', '')
300                 # grab the stamp and sysinfo
301                 if re.match(tp.stampfmt, line):
302                         tp.stamp = line
303                         continue
304                 elif re.match(tp.sysinfofmt, line):
305                         tp.sysinfo = line
306                         continue
307                 elif re.match(tp.cmdlinefmt, line):
308                         tp.cmdline = line
309                         continue
310                 elif re.match(tp.kparamsfmt, line):
311                         tp.kparams = line
312                         continue
313                 idx = line.find('[')
314                 if idx > 1:
315                         line = line[idx:]
316                 m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line)
317                 if(not m):
318                         continue
319                 ktime = float(m.group('ktime'))
320                 if(ktime > 120):
321                         break
322                 msg = m.group('msg')
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)
327                         continue
328                 m = re.match('.* setting system clock to (?P<t>.*) UTC.*', msg)
329                 if(m):
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')
334                         continue
335                 m = re.match('^calling *(?P<f>.*)\+.* @ (?P<p>[0-9]*)', msg)
336                 if(m):
337                         func = m.group('f')
338                         pid = int(m.group('p'))
339                         devtemp[func] = (ktime, pid)
340                         continue
341                 m = re.match('^initcall *(?P<f>.*)\+.* returned (?P<r>.*) after (?P<t>.*) usecs', msg)
342                 if(m):
343                         data.valid = True
344                         data.end = ktime
345                         f, r, t = m.group('f', 'r', 't')
346                         if(f in devtemp):
347                                 start, pid = devtemp[f]
348                                 data.newAction(phase, f, pid, start, ktime, int(r), int(t))
349                                 del devtemp[f]
350                         continue
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
355                         phase = 'user'
356
357         if tp.stamp:
358                 sysvals.stamp = 0
359                 tp.parseStamp(data, sysvals)
360         data.dmesg['user']['end'] = data.end
361         lf.close()
362         return data
363
364 # Function: parseTraceLog
365 # Description:
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
371         cgfilter = []
372         if len(sysvals.cgfilter) > 0:
373                 for p in data.phases:
374                         list = data.dmesg[p]['list']
375                         for i in sysvals.cgfilter:
376                                 if i in list:
377                                         cgfilter.append([list[i]['start']-0.0001,
378                                                 list[i]['end']+0.0001])
379         # parse the trace log
380         ftemp = dict()
381         tp = aslib.TestProps()
382         tp.setTracerType('function_graph')
383         tf = open(sysvals.ftracefile, 'r')
384         for line in tf:
385                 if line[0] == '#':
386                         continue
387                 m = re.match(tp.ftrace_line_fmt, line.strip())
388                 if(not m):
389                         continue
390                 m_time, m_proc, m_pid, m_msg, m_dur = \
391                         m.group('time', 'proc', 'pid', 'msg', 'dur')
392                 t = float(m_time)
393                 if len(cgfilter) > 0:
394                         allow = False
395                         for r in cgfilter:
396                                 if t >= r[0] and t < r[1]:
397                                         allow = True
398                                         break
399                         if not allow:
400                                 continue
401                 if t > data.end:
402                         break
403                 if(m_time and m_pid and m_msg):
404                         t = aslib.FTraceLine(m_time, m_msg, m_dur)
405                         pid = int(m_pid)
406                 else:
407                         continue
408                 if t.fevent or t.fkprobe:
409                         continue
410                 key = (m_proc, pid)
411                 if(key not in ftemp):
412                         ftemp[key] = []
413                         ftemp[key].append(aslib.FTraceCallGraph(pid, sysvals))
414                 cg = ftemp[key][-1]
415                 res = cg.addLine(t)
416                 if(res != 0):
417                         ftemp[key].append(aslib.FTraceCallGraph(pid, sysvals))
418                 if(res == -1):
419                         ftemp[key][-1].addLine(t)
420
421         tf.close()
422
423         # add the callgraph data to the device hierarchy
424         for key in ftemp:
425                 proc, pid = key
426                 for cg in ftemp[key]:
427                         if len(cg.list) < 1 or cg.invalid or (cg.end - cg.start == 0):
428                                 continue
429                         if(not cg.postProcess()):
430                                 pprint('Sanity check failed for %s-%d' % (proc, pid))
431                                 continue
432                         # match cg data to devices
433                         devname = data.deviceMatch(pid, cg)
434                         if not devname:
435                                 kind = 'Orphan'
436                                 if cg.partial:
437                                         kind = 'Partial'
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)))
443
444 # Function: retrieveLogs
445 # Description:
446 #        Create copies of dmesg and/or ftrace for later processing
447 def retrieveLogs():
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:
459                 return
460         # get ftrace
461         sysvals.writeDatafileHeader(sysvals.ftracefile)
462         call('cat '+sysvals.tpath+'trace >> '+sysvals.ftracefile, shell=True)
463
464 # Function: colorForName
465 # Description:
466 #        Generate a repeatable color from a list for a given name
467 def colorForName(name):
468         list = [
469                 ('c1', '#ec9999'),
470                 ('c2', '#ffc1a6'),
471                 ('c3', '#fff0a6'),
472                 ('c4', '#adf199'),
473                 ('c5', '#9fadea'),
474                 ('c6', '#a699c1'),
475                 ('c7', '#ad99b4'),
476                 ('c8', '#eaffea'),
477                 ('c9', '#dcecfb'),
478                 ('c10', '#ffffea')
479         ]
480         i = 0
481         total = 0
482         count = len(list)
483         while i < len(name):
484                 total += ord(name[i])
485                 i += 1
486         return list[total % count]
487
488 def cgOverview(cg, minlen):
489         stats = dict()
490         large = []
491         for l in cg.list:
492                 if l.fcall and l.depth == 1:
493                         if l.length >= minlen:
494                                 large.append(l)
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)
500
501 # Function: createBootGraph
502 # Description:
503 #        Create the output html file from the resident test data
504 # Arguments:
505 #        testruns: array of Data objects from parseKernelLog or parseTraceLog
506 # Output:
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>'\
514                 '</tr>\n</table>\n'
515
516         # device timeline
517         devtl = aslib.Timeline(100, 20)
518
519         # write the test title and general info header
520         devtl.createHeader(sysvals, sysvals.stamp)
521
522         # Generate the header for this timeline
523         t0 = data.start
524         tMax = data.end
525         tTotal = tMax - t0
526         if(tTotal == 0):
527                 pprint('ERROR: No timeline data')
528                 return False
529         user_mode = '%.0f'%(data.tUserMode*1000)
530         last_init = '%.0f'%(tTotal*1000)
531         devtl.html += html_timetotal.format(user_mode, last_init)
532
533         # determine the maximum number of rows we need to draw
534         devlist = []
535         for p in data.phases:
536                 list = data.dmesg[p]['list']
537                 for devname in list:
538                         d = aslib.DevItem(0, p, list[devname])
539                         devlist.append(d)
540                 devtl.getPhaseRows(devlist, 0, 'start')
541         devtl.calcTotalRows()
542
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, \
553                         phase['color'], '')
554
555         # draw the device timeline
556         num = 0
557         devstats = dict()
558         for phase in data.phases:
559                 list = data.dmesg[phase]['list']
560                 for devname in sorted(list):
561                         cls, color = colorForName(devname)
562                         dev = list[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}
566                         dev['color'] = color
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):
580                                         continue
581                                 cg = dev['ftrace']
582                                 large, stats = cgOverview(cg, 0.001)
583                                 devstats[dev['id']]['fstat'] = stats
584                                 for l in large:
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)
590                                         num += 1
591                                 continue
592                         if('ftraces' not in dev):
593                                 continue
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)
599                                 cg.id = 'x%d' % num
600                                 devtl.html += html_srccall.format(cg.name, left,
601                                         top, height, width, title, dev['id']+cg.id)
602                                 num += 1
603
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'
607
608         # timeline is finished
609         devtl.html += '</div>\n</div>\n'
610
611         # draw a legend which describes the phases by color
612         devtl.html += '<div class="legend">\n'
613         pdelta = 20.0
614         pmargin = 36.0
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'
620
621         hf = open(sysvals.htmlfile, 'w')
622
623         # add the css
624         extra = '\
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)
642
643         # write the device timeline
644         hf.write(devtl.html)
645
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:
654                                         break
655                                 statinfo += '\t\t"%f|%s|%d",\n' % (funcs[f][0], f, funcs[f][1])
656                 statinfo += '\t],\n'
657         statinfo += '};\n'
658         html = \
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+\
667                 '</script>\n'
668         hf.write(html)
669
670         # add the callgraph html
671         if(sysvals.usecallgraph):
672                 aslib.addCallgraphs(sysvals, hf, data)
673
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
678         if sysvals.dmesglog:
679                 hf.write('<div id="dmesglog" style="display:none;">\n')
680                 for line in data.dmesgtext:
681                         line = line.replace('<', '&lt').replace('>', '&gt')
682                         hf.write(line)
683                 hf.write('</div>\n')
684
685         # write the footer and close
686         aslib.addScriptCode(hf, [data])
687         hf.write('</body>\n</html>\n')
688         hf.close()
689         return True
690
691 # Function: updateCron
692 # Description:
693 #    (restore=False) Set the tool to run automatically on reboot
694 #    (restore=True) Restore the original crontab
695 def updateCron(restore=False):
696         if not restore:
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')
706         if not cmd:
707                 doError('crontab not found')
708         # on restore: move the backup cron back into place
709         if restore:
710                 if os.path.exists(backfile):
711                         shutil.move(backfile, cronfile)
712                         call([cmd, cronfile])
713                 return
714         # backup current cron and install new one with reboot
715         if os.path.exists(cronfile):
716                 shutil.move(cronfile, backfile)
717         else:
718                 fp = open(backfile, 'w')
719                 fp.close()
720         res = -1
721         try:
722                 fp = open(backfile, 'r')
723                 op = open(cronfile, 'w')
724                 for line in fp:
725                         if not sysvals.myCronJob(line):
726                                 op.write(line)
727                                 continue
728                 fp.close()
729                 op.write('@reboot python %s\n' % sysvals.cronjobCmdString())
730                 op.close()
731                 res = call([cmd, cronfile])
732         except Exception, e:
733                 pprint('Exception: %s' % str(e))
734                 shutil.move(backfile, cronfile)
735                 res = -1
736         if res != 0:
737                 doError('crontab failed')
738
739 # Function: updateGrub
740 # Description:
741 #        update grub.cfg for all kernels with our parameters
742 def updateGrub(restore=False):
743         # call update-grub on restore
744         if restore:
745                 try:
746                         call(sysvals.blexec, stderr=PIPE, stdout=PIPE,
747                                 env={'PATH': '.:/sbin:/usr/sbin:/usr/bin:/sbin:/bin'})
748                 except Exception, e:
749                         pprint('Exception: %s\n' % str(e))
750                 return
751         # extract the option and create a grub config without it
752         sysvals.rootUser(True)
753         tgtopt = 'GRUB_CMDLINE_LINUX_DEFAULT'
754         cmdline = ''
755         grubfile = '/etc/default/grub'
756         tempfile = '/etc/default/grub.analyze_boot'
757         shutil.move(grubfile, tempfile)
758         res = -1
759         try:
760                 fp = open(tempfile, 'r')
761                 op = open(grubfile, 'w')
762                 cont = False
763                 for line in fp:
764                         line = line.strip()
765                         if len(line) == 0 or line[0] == '#':
766                                 continue
767                         opt = line.split('=')[0].strip()
768                         if opt == tgtopt:
769                                 cmdline = line.split('=', 1)[1].strip('\\')
770                                 if line[-1] == '\\':
771                                         cont = True
772                         elif cont:
773                                 cmdline += line.strip('\\')
774                                 if line[-1] != '\\':
775                                         cont = False
776                         else:
777                                 op.write('%s\n' % line)
778                 fp.close()
779                 # if the target option value is in quotes, strip them
780                 sp = '"'
781                 val = cmdline.strip()
782                 if val and (val[0] == '\'' or val[0] == '"'):
783                         sp = val[0]
784                         val = val.strip(sp)
785                 cmdline = val
786                 # append our cmd line options
787                 if len(cmdline) > 0:
788                         cmdline += ' '
789                 cmdline += sysvals.kernelParams()
790                 # write out the updated target option
791                 op.write('\n%s=%s%s%s\n' % (tgtopt, sp, cmdline, sp))
792                 op.close()
793                 res = call(sysvals.blexec)
794                 os.remove(grubfile)
795         except Exception, e:
796                 pprint('Exception: %s' % str(e))
797                 res = -1
798         # cleanup
799         shutil.move(tempfile, grubfile)
800         if res != 0:
801                 doError('update grub failed')
802
803 # Function: updateKernelParams
804 # Description:
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':
810                 updateGrub(restore)
811
812 # Function: doError Description:
813 #        generic error function for catastrphic failures
814 # Arguments:
815 #        msg: the error message to print
816 #        help: True if printHelp should be called after, False otherwise
817 def doError(msg, help=False):
818         if help == True:
819                 printHelp()
820         pprint('ERROR: %s\n' % msg)
821         sysvals.outputResult({'error':msg})
822         sys.exit()
823
824 # Function: printHelp
825 # Description:
826 #        print out the help text
827 def printHelp():
828         pprint('\n%s v%s\n'\
829         'Usage: bootgraph <options> <command>\n'\
830         '\n'\
831         'Description:\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'\
835         '\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'\
838         '\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'\
843         '\n'\
844         'Options:\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'\
852         ' [advanced]\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'\
865         '\n'\
866         'Other commands:\n'\
867         '  -flistall     Print all functions capable of being captured in ftrace\n'\
868         '  -sysinfo      Print out system info extracted from BIOS\n'\
869         ' [redo]\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))
873         return True
874
875 # ----------------- MAIN --------------------
876 # exec start (skipped if script is loaded as library)
877 if __name__ == '__main__':
878         # loop through the command line arguments
879         cmd = ''
880         testrun = True
881         switchoff = ['disable', 'off', 'false', '0']
882         simplecmds = ['-sysinfo', '-kpupdate', '-flistall', '-checkbl']
883         cgskip = ''
884         if '-f' in sys.argv:
885                 cgskip = sysvals.configFile('cgskip.txt')
886         args = iter(sys.argv[1:])
887         mdset = False
888         for arg in args:
889                 if(arg == '-h'):
890                         printHelp()
891                         sys.exit()
892                 elif(arg == '-v'):
893                         pprint("Version %s" % sysvals.version)
894                         sys.exit()
895                 elif(arg == '-verbose'):
896                         sysvals.verbose = True
897                 elif(arg in simplecmds):
898                         cmd = arg[1:]
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'):
909                         try:
910                                 val = args.next()
911                         except:
912                                 doError('No callgraph functions supplied', True)
913                         sysvals.setCallgraphFilter(val)
914                 elif(arg == '-cgskip'):
915                         try:
916                                 val = args.next()
917                         except:
918                                 doError('No file supplied', True)
919                         if val.lower() in switchoff:
920                                 cgskip = ''
921                         else:
922                                 cgskip = sysvals.configFile(val)
923                                 if(not cgskip):
924                                         doError('%s does not exist' % cgskip)
925                 elif(arg == '-bl'):
926                         try:
927                                 val = args.next()
928                         except:
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'):
936                         mdset = True
937                         sysvals.max_graph_depth = aslib.getArgInt('-maxdepth', args, 0, 1000)
938                 elif(arg == '-func'):
939                         try:
940                                 val = args.next()
941                         except:
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'):
948                         try:
949                                 val = args.next()
950                         except:
951                                 doError('No ftrace file supplied', True)
952                         if(os.path.exists(val) == False):
953                                 doError('%s does not exist' % val)
954                         testrun = False
955                         sysvals.ftracefile = val
956                 elif(arg == '-addlogs'):
957                         sysvals.dmesglog = True
958                 elif(arg == '-expandcg'):
959                         sysvals.cgexp = True
960                 elif(arg == '-dmesg'):
961                         try:
962                                 val = args.next()
963                         except:
964                                 doError('No dmesg file supplied', True)
965                         if(os.path.exists(val) == False):
966                                 doError('%s does not exist' % val)
967                         testrun = False
968                         sysvals.dmesgfile = val
969                 elif(arg == '-o'):
970                         try:
971                                 val = args.next()
972                         except:
973                                 doError('No subdirectory name supplied', True)
974                         sysvals.testdir = sysvals.setOutputFolder(val)
975                 elif(arg == '-result'):
976                         try:
977                                 val = args.next()
978                         except:
979                                 doError('No result file supplied', True)
980                         sysvals.result = val
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
989                 else:
990                         doError('Invalid argument: '+arg, True)
991
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')
1003
1004         # run utility commands
1005         sysvals.cpuInfo()
1006         if cmd != '':
1007                 if cmd == 'kpupdate':
1008                         updateKernelParams()
1009                 elif cmd == 'flistall':
1010                         for f in sysvals.getBootFtraceFilterFunctions():
1011                                 print f
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)
1017                 sys.exit()
1018
1019         # reboot: update grub, setup a cronjob, and reboot
1020         if sysvals.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()
1026                         updateCron()
1027                         call('reboot')
1028                 else:
1029                         sysvals.manualRebootRequired()
1030                 sys.exit()
1031
1032         if sysvals.usecallgraph and cgskip:
1033                 sysvals.vprint('Using cgskip file: %s' % cgskip)
1034                 sysvals.setCallgraphBlacklist(cgskip)
1035
1036         # cronjob: remove the cronjob, grub changes, and disable ftrace
1037         if sysvals.iscronjob:
1038                 updateCron(True)
1039                 updateKernelParams(True)
1040                 try:
1041                         sysvals.fsetVal('0', 'tracing_on')
1042                 except:
1043                         pass
1044
1045         # testrun: generate copies of the logs
1046         if testrun:
1047                 retrieveLogs()
1048         else:
1049                 sysvals.setOutputFile()
1050
1051         # process the log data
1052         if sysvals.dmesgfile:
1053                 if not mdset:
1054                         sysvals.max_graph_depth = 0
1055                 data = parseKernelLog()
1056                 if(not data.valid):
1057                         doError('No initcall data found in %s' % sysvals.dmesgfile)
1058                 if sysvals.useftrace and sysvals.ftracefile:
1059                         parseTraceLog(data)
1060                 if sysvals.cgdump:
1061                         data.debugPrint()
1062                         sys.exit()
1063         else:
1064                 doError('dmesg file required')
1065
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)
1069         data.printDetails()
1070         createBootGraph(data)
1071
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)
1077
1078         sysvals.stamp['boot'] = (data.tUserMode - data.start) * 1000
1079         sysvals.stamp['lastinit'] = data.end * 1000
1080         sysvals.outputResult(sysvals.stamp)
This page took 0.099645 seconds and 4 git commands to generate.