Commit | Line | Data |
---|---|---|
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 | ||
26 | import sys | |
27 | import time | |
28 | import os | |
29 | import string | |
30 | import re | |
31 | import platform | |
32 | import shutil | |
33 | from datetime import datetime, timedelta | |
34 | from subprocess import call, Popen, PIPE | |
35 | import 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 | |
43 | class 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 | |
203 | sysvals = SystemValues() | |
204 | ||
205 | # Class: Data | |
206 | # Description: | |
207 | # The primary container for test data. | |
208 | class 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 |
277 | def 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 | 355 | def 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 | |
403 | def 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 | |
423 | def 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 | ||
444 | def 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 | 464 | def 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('<', '<').replace('>', '>') | |
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 | |
657 | def 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 | |
704 | def 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 |
768 | def 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 | |
779 | def 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 | |
788 | def 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) | |
836 | if __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) |