tools: power: pm-graph: AnalyzeSuspend v4.6

Moved from scripts into tools, and updated from 4.5 to 4.6 - Changed the tool title to SleepGraph - Reformatted the code so analyze_suspend can be used as a library - Reorganized all html/js/css handling code to be used by other tools - upgraded the -summary feature to work faster with better readability

Todd E Brandt committed 9 years ago

Commit bc167c71 parent 010a5221 file · +495 −421Browse files

Showing the changes to scripts (1 of 1 file). Show all

Unified · Split

scripts/analyze_suspend.py+0−5235

@@ -1,5235 +0,0 @@
1		−#!/usr/bin/python
2		−#
3		−# Tool for analyzing suspend/resume 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		−# You should have received a copy of the GNU General Public License along with
16		−# this program; if not, write to the Free Software Foundation, Inc.,
17		−# 51 Franklin St - Fifth Floor, Boston, MA 02110-1301 USA.
18		−#
19		−# Authors:
20		−# Todd Brandt <todd.e.brandt@linux.intel.com>
21		−#
22		−# Links:
23		−# Home Page
24		−# https://01.org/suspendresume
25		−# Source repo
26		−# https://github.com/01org/suspendresume
27		−#
28		−# Description:
29		−# This tool is designed to assist kernel and OS developers in optimizing
30		−# their linux stack's suspend/resume time. Using a kernel image built
31		−# with a few extra options enabled, the tool will execute a suspend and
32		−# will capture dmesg and ftrace data until resume is complete. This data
33		−# is transformed into a device timeline and a callgraph to give a quick
34		−# and detailed view of which devices and callbacks are taking the most
35		−# time in suspend/resume. The output is a single html file which can be
36		−# viewed in firefox or chrome.
37		−#
38		−# The following kernel build options are required:
39		−# CONFIG_PM_DEBUG=y
40		−# CONFIG_PM_SLEEP_DEBUG=y
41		−# CONFIG_FTRACE=y
42		−# CONFIG_FUNCTION_TRACER=y
43		−# CONFIG_FUNCTION_GRAPH_TRACER=y
44		−# CONFIG_KPROBES=y
45		−# CONFIG_KPROBES_ON_FTRACE=y
46		−#
47		−# For kernel versions older than 3.15:
48		−# The following additional kernel parameters are required:
49		−# (e.g. in file /etc/default/grub)
50		−# GRUB_CMDLINE_LINUX_DEFAULT="... initcall_debug log_buf_len=16M ..."
51		−#
52		−
53		−# ----------------- LIBRARIES --------------------
54		−
55		−import sys
56		−import time
57		−import os
58		−import string
59		−import re
60		−import platform
61		−from datetime import datetime
62		−import struct
63		−import ConfigParser
64		−from threading import Thread
65		−from subprocess import call, Popen, PIPE
66		−
67		−# ----------------- CLASSES --------------------
68		−
69		−# Class: SystemValues
70		−# Description:
71		−# A global, single-instance container used to
72		−# store system values and test parameters
73		−class SystemValues:
74		− ansi = False
75		− version = '4.5'
76		− verbose = False
77		− addlogs = False
78		− mindevlen = 0.0
79		− mincglen = 0.0
80		− cgphase = ''
81		− cgtest = -1
82		− callloopmaxgap = 0.0001
83		− callloopmaxlen = 0.005
84		− srgap = 0
85		− cgexp = False
86		− outdir = ''
87		− testdir = '.'
88		− tpath = '/sys/kernel/debug/tracing/'
89		− fpdtpath = '/sys/firmware/acpi/tables/FPDT'
90		− epath = '/sys/kernel/debug/tracing/events/power/'
91		− traceevents = [
92		− 'suspend_resume',
93		− 'device_pm_callback_end',
94		− 'device_pm_callback_start'
95		− ]
96		− logmsg = ''
97		− testcommand = ''
98		− mempath = '/dev/mem'
99		− powerfile = '/sys/power/state'
100		− suspendmode = 'mem'
101		− hostname = 'localhost'
102		− prefix = 'test'
103		− teststamp = ''
104		− dmesgstart = 0.0
105		− dmesgfile = ''
106		− ftracefile = ''
107		− htmlfile = ''
108		− embedded = False
109		− rtcwake = False
110		− rtcwaketime = 10
111		− rtcpath = ''
112		− devicefilter = []
113		− stamp = 0
114		− execcount = 1
115		− x2delay = 0
116		− usecallgraph = False
117		− usetraceevents = False
118		− usetraceeventsonly = False
119		− usetracemarkers = True
120		− usekprobes = True
121		− usedevsrc = False
122		− useprocmon = False
123		− notestrun = False
124		− mixedphaseheight = True
125		− devprops = dict()
126		− predelay = 0
127		− postdelay = 0
128		− procexecfmt = 'ps - (?P<ps>.*)$'
129		− devpropfmt = '# Device Properties: .*'
130		− tracertypefmt = '# tracer: (?P<t>.*)'
131		− firmwarefmt = '# fwsuspend (?P<s>[0-9]) fwresume (?P<r>[0-9])$'
132		− stampfmt = '# suspend-(?P<m>[0-9]{2})(?P<d>[0-9]{2})(?P<y>[0-9]{2})-'+\
133		− '(?P<H>[0-9]{2})(?P<M>[0-9]{2})(?P<S>[0-9]{2})'+\
134		− ' (?P<host>.) (?P<mode>.) (?P<kernel>.*)$'
135		− tracefuncs = {
136		− 'sys_sync': dict(),
137		− 'pm_prepare_console': dict(),
138		− 'pm_notifier_call_chain': dict(),
139		− 'freeze_processes': dict(),
140		− 'freeze_kernel_threads': dict(),
141		− 'pm_restrict_gfp_mask': dict(),
142		− 'acpi_suspend_begin': dict(),
143		− 'suspend_console': dict(),
144		− 'acpi_pm_prepare': dict(),
145		− 'syscore_suspend': dict(),
146		− 'arch_enable_nonboot_cpus_end': dict(),
147		− 'syscore_resume': dict(),
148		− 'acpi_pm_finish': dict(),
149		− 'resume_console': dict(),
150		− 'acpi_pm_end': dict(),
151		− 'pm_restore_gfp_mask': dict(),
152		− 'thaw_processes': dict(),
153		− 'pm_restore_console': dict(),
154		− 'CPU_OFF': {
155		− 'func':'_cpu_down',
156		− 'args_x86_64': {'cpu':'%di:s32'},
157		− 'format': 'CPU_OFF[{cpu}]'
158		− },
159		− 'CPU_ON': {
160		− 'func':'_cpu_up',
161		− 'args_x86_64': {'cpu':'%di:s32'},
162		− 'format': 'CPU_ON[{cpu}]'
163		− },
164		− }
165		− dev_tracefuncs = {
166		− # general wait/delay/sleep
167		− 'msleep': { 'args_x86_64': {'time':'%di:s32'}, 'ub': 1 },
168		− 'schedule_timeout_uninterruptible': { 'args_x86_64': {'timeout':'%di:s32'}, 'ub': 1 },
169		− 'schedule_timeout': { 'args_x86_64': {'timeout':'%di:s32'}, 'ub': 1 },
170		− 'udelay': { 'func':'__const_udelay', 'args_x86_64': {'loops':'%di:s32'}, 'ub': 1 },
171		− 'usleep_range': { 'args_x86_64': {'min':'%di:s32', 'max':'%si:s32'}, 'ub': 1 },
172		− 'mutex_lock_slowpath': { 'func':'__mutex_lock_slowpath', 'ub': 1 },
173		− 'acpi_os_stall': {'ub': 1},
174		− # ACPI
175		− 'acpi_resume_power_resources': dict(),
176		− 'acpi_ps_parse_aml': dict(),
177		− # filesystem
178		− 'ext4_sync_fs': dict(),
179		− # 80211
180		− 'iwlagn_mac_start': dict(),
181		− 'iwlagn_alloc_bcast_station': dict(),
182		− 'iwl_trans_pcie_start_hw': dict(),
183		− 'iwl_trans_pcie_start_fw': dict(),
184		− 'iwl_run_init_ucode': dict(),
185		− 'iwl_load_ucode_wait_alive': dict(),
186		− 'iwl_alive_start': dict(),
187		− 'iwlagn_mac_stop': dict(),
188		− 'iwlagn_mac_suspend': dict(),
189		− 'iwlagn_mac_resume': dict(),
190		− 'iwlagn_mac_add_interface': dict(),
191		− 'iwlagn_mac_remove_interface': dict(),
192		− 'iwlagn_mac_change_interface': dict(),
193		− 'iwlagn_mac_config': dict(),
194		− 'iwlagn_configure_filter': dict(),
195		− 'iwlagn_mac_hw_scan': dict(),
196		− 'iwlagn_bss_info_changed': dict(),
197		− 'iwlagn_mac_channel_switch': dict(),
198		− 'iwlagn_mac_flush': dict(),
199		− # ATA
200		− 'ata_eh_recover': { 'args_x86_64': {'port':'+36(%di):s32'} },
201		− # i915
202		− 'i915_gem_resume': dict(),
203		− 'i915_restore_state': dict(),
204		− 'intel_opregion_setup': dict(),
205		− 'g4x_pre_enable_dp': dict(),
206		− 'vlv_pre_enable_dp': dict(),
207		− 'chv_pre_enable_dp': dict(),
208		− 'g4x_enable_dp': dict(),
209		− 'vlv_enable_dp': dict(),
210		− 'intel_hpd_init': dict(),
211		− 'intel_opregion_register': dict(),
212		− 'intel_dp_detect': dict(),
213		− 'intel_hdmi_detect': dict(),
214		− 'intel_opregion_init': dict(),
215		− 'intel_fbdev_set_suspend': dict(),
216		− }
217		− kprobes = dict()
218		− timeformat = '%.3f'
219		− def __init__(self):
220		− # if this is a phoronix test run, set some default options
221		− if('LOG_FILE' in os.environ and 'TEST_RESULTS_IDENTIFIER' in os.environ):
222		− self.embedded = True
223		− self.addlogs = True
224		− self.htmlfile = os.environ['LOG_FILE']
225		− self.archargs = 'args_'+platform.machine()
226		− self.hostname = platform.node()
227		− if(self.hostname == ''):
228		− self.hostname = 'localhost'
229		− rtc = "rtc0"
230		− if os.path.exists('/dev/rtc'):
231		− rtc = os.readlink('/dev/rtc')
232		− rtc = '/sys/class/rtc/'+rtc
233		− if os.path.exists(rtc) and os.path.exists(rtc+'/date') and \
234		− os.path.exists(rtc+'/time') and os.path.exists(rtc+'/wakealarm'):
235		− self.rtcpath = rtc
236		− if (hasattr(sys.stdout, 'isatty') and sys.stdout.isatty()):
237		− self.ansi = True
238		− def setPrecision(self, num):
239		− if num < 0 or num > 6:
240		− return
241		− self.timeformat = '%.{0}f'.format(num)
242		− def setOutputFolder(self, value):
243		− args = dict()
244		− n = datetime.now()
245		− args['date'] = n.strftime('%y%m%d')
246		− args['time'] = n.strftime('%H%M%S')
247		− args['hostname'] = self.hostname
248		− self.outdir = value.format(**args)
249		− def setOutputFile(self):
250		− if((self.htmlfile == '') and (self.dmesgfile != '')):
251		− m = re.match('(?P<name>.*)_dmesg\.txt$', self.dmesgfile)
252		− if(m):
253		− self.htmlfile = m.group('name')+'.html'
254		− if((self.htmlfile == '') and (self.ftracefile != '')):
255		− m = re.match('(?P<name>.*)_ftrace\.txt$', self.ftracefile)
256		− if(m):
257		− self.htmlfile = m.group('name')+'.html'
258		− if(self.htmlfile == ''):
259		− self.htmlfile = 'output.html'
260		− def initTestOutput(self, subdir, testpath=''):
261		− self.prefix = self.hostname
262		− v = open('/proc/version', 'r').read().strip()
263		− kver = string.split(v)[2]
264		− n = datetime.now()
265		− testtime = n.strftime('suspend-%m%d%y-%H%M%S')
266		− if not testpath:
267		− testpath = n.strftime('suspend-%y%m%d-%H%M%S')
268		− if(subdir != "."):
269		− self.testdir = subdir+"/"+testpath
270		− else:
271		− self.testdir = testpath
272		− self.teststamp = \
273		− '# '+testtime+' '+self.prefix+' '+self.suspendmode+' '+kver
274		− if(self.embedded):
275		− self.dmesgfile = \
276		− '/tmp/'+testtime+'_'+self.suspendmode+'_dmesg.txt'
277		− self.ftracefile = \
278		− '/tmp/'+testtime+'_'+self.suspendmode+'_ftrace.txt'
279		− return
280		− self.dmesgfile = \
281		− self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_dmesg.txt'
282		− self.ftracefile = \
283		− self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_ftrace.txt'
284		− self.htmlfile = \
285		− self.testdir+'/'+self.prefix+'_'+self.suspendmode+'.html'
286		− if not os.path.isdir(self.testdir):
287		− os.mkdir(self.testdir)
288		− def setDeviceFilter(self, value):
289		− self.devicefilter = []
290		− if value:
291		− value = value.split(',')
292		− for i in value:
293		− self.devicefilter.append(i.strip())
294		− def rtcWakeAlarmOn(self):
295		− call('echo 0 > '+self.rtcpath+'/wakealarm', shell=True)
296		− outD = open(self.rtcpath+'/date', 'r').read().strip()
297		− outT = open(self.rtcpath+'/time', 'r').read().strip()
298		− mD = re.match('^(?P<y>[0-9])-(?P<m>[0-9])-(?P<d>[0-9]*)', outD)
299		− mT = re.match('^(?P<h>[0-9]):(?P<m>[0-9]):(?P<s>[0-9]*)', outT)
300		− if(mD and mT):
301		− # get the current time from hardware
302		− utcoffset = int((datetime.now() - datetime.utcnow()).total_seconds())
303		− dt = datetime(\
304		− int(mD.group('y')), int(mD.group('m')), int(mD.group('d')),
305		− int(mT.group('h')), int(mT.group('m')), int(mT.group('s')))
306		− nowtime = int(dt.strftime('%s')) + utcoffset
307		− else:
308		− # if hardware time fails, use the software time
309		− nowtime = int(datetime.now().strftime('%s'))
310		− alarm = nowtime + self.rtcwaketime
311		− call('echo %d > %s/wakealarm' % (alarm, self.rtcpath), shell=True)
312		− def rtcWakeAlarmOff(self):
313		− call('echo 0 > %s/wakealarm' % self.rtcpath, shell=True)
314		− def initdmesg(self):
315		− # get the latest time stamp from the dmesg log
316		− fp = Popen('dmesg', stdout=PIPE).stdout
317		− ktime = '0'
318		− for line in fp:
319		− line = line.replace('\r\n', '')
320		− idx = line.find('[')
321		− if idx > 1:
322		− line = line[idx:]
323		− m = re.match('[ \t](\[ )(?P<ktime>[0-9\.])(\]) (?P<msg>.)', line)
324		− if(m):
325		− ktime = m.group('ktime')
326		− fp.close()
327		− self.dmesgstart = float(ktime)
328		− def getdmesg(self):
329		− # store all new dmesg lines since initdmesg was called
330		− fp = Popen('dmesg', stdout=PIPE).stdout
331		− op = open(self.dmesgfile, 'a')
332		− for line in fp:
333		− line = line.replace('\r\n', '')
334		− idx = line.find('[')
335		− if idx > 1:
336		− line = line[idx:]
337		− m = re.match('[ \t](\[ )(?P<ktime>[0-9\.])(\]) (?P<msg>.)', line)
338		− if(not m):
339		− continue
340		− ktime = float(m.group('ktime'))
341		− if ktime > self.dmesgstart:
342		− op.write(line)
343		− fp.close()
344		− op.close()
345		− def addFtraceFilterFunctions(self, file):
346		− fp = open(file)
347		− list = fp.read().split('\n')
348		− fp.close()
349		− for i in list:
350		− if len(i) < 2:
351		− continue
352		− self.tracefuncs[i] = dict()
353		− def getFtraceFilterFunctions(self, current):
354		− rootCheck(True)
355		− if not current:
356		− call('cat '+self.tpath+'available_filter_functions', shell=True)
357		− return
358		− fp = open(self.tpath+'available_filter_functions')
359		− master = fp.read().split('\n')
360		− fp.close()
361		− for i in self.tracefuncs:
362		− if 'func' in self.tracefuncs[i]:
363		− i = self.tracefuncs[i]['func']
364		− if i in master:
365		− print i
366		− else:
367		− print self.colorText(i)
368		− def setFtraceFilterFunctions(self, list):
369		− fp = open(self.tpath+'available_filter_functions')
370		− master = fp.read().split('\n')
371		− fp.close()
372		− flist = ''
373		− for i in list:
374		− if i not in master:
375		− continue
376		− if ' [' in i:
377		− flist += i.split(' ')[0]+'\n'
378		− else:
379		− flist += i+'\n'
380		− fp = open(self.tpath+'set_graph_function', 'w')
381		− fp.write(flist)
382		− fp.close()
383		− def basicKprobe(self, name):
384		− self.kprobes[name] = {'name': name,'func': name,'args': dict(),'format': name}
385		− def defaultKprobe(self, name, kdata):
386		− k = kdata
387		− for field in ['name', 'format', 'func']:
388		− if field not in k:
389		− k[field] = name
390		− if self.archargs in k:
391		− k['args'] = k[self.archargs]
392		− else:
393		− k['args'] = dict()
394		− k['format'] = name
395		− self.kprobes[name] = k
396		− def kprobeColor(self, name):
397		− if name not in self.kprobes or 'color' not in self.kprobes[name]:
398		− return ''
399		− return self.kprobes[name]['color']
400		− def kprobeDisplayName(self, name, dataraw):
401		− if name not in self.kprobes:
402		− self.basicKprobe(name)
403		− data = ''
404		− quote=0
405		− # first remvoe any spaces inside quotes, and the quotes
406		− for c in dataraw:
407		− if c == '"':
408		− quote = (quote + 1) % 2
409		− if quote and c == ' ':
410		− data += '_'
411		− elif c != '"':
412		− data += c
413		− fmt, args = self.kprobes[name]['format'], self.kprobes[name]['args']
414		− arglist = dict()
415		− # now process the args
416		− for arg in sorted(args):
417		− arglist[arg] = ''
418		− m = re.match('.* '+arg+'=(?P<arg>.*) ', data);
419		− if m:
420		− arglist[arg] = m.group('arg')
421		− else:
422		− m = re.match('.* '+arg+'=(?P<arg>.*)', data);
423		− if m:
424		− arglist[arg] = m.group('arg')
425		− out = fmt.format(**arglist)
426		− out = out.replace(' ', '_').replace('"', '')
427		− return out
428		− def kprobeText(self, kname, kprobe):
429		− name = fmt = func = kname
430		− args = dict()
431		− if 'name' in kprobe:
432		− name = kprobe['name']
433		− if 'format' in kprobe:
434		− fmt = kprobe['format']
435		− if 'func' in kprobe:
436		− func = kprobe['func']
437		− if self.archargs in kprobe:
438		− args = kprobe[self.archargs]
439		− if 'args' in kprobe:
440		− args = kprobe['args']
441		− if re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', func):
442		− doError('Kprobe "%s" has format info in the function name "%s"' % (name, func))
443		− for arg in re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', fmt):
444		− if arg not in args:
445		− doError('Kprobe "%s" is missing argument "%s"' % (name, arg))
446		− val = 'p:%s_cal %s' % (name, func)
447		− for i in sorted(args):
448		− val += ' %s=%s' % (i, args[i])
449		− val += '\nr:%s_ret %s $retval\n' % (name, func)
450		− return val
451		− def addKprobes(self, output=False):
452		− if len(sysvals.kprobes) < 1:
453		− return
454		− if output:
455		− print(' kprobe functions in this kernel:')
456		− # first test each kprobe
457		− rejects = []
458		− # sort kprobes: trace, ub-dev, custom, dev
459		− kpl = [[], [], [], []]
460		− for name in sorted(self.kprobes):
461		− res = self.colorText('YES', 32)
462		− if not self.testKprobe(name, self.kprobes[name]):
463		− res = self.colorText('NO')
464		− rejects.append(name)
465		− else:
466		− if name in self.tracefuncs:
467		− kpl[0].append(name)
468		− elif name in self.dev_tracefuncs:
469		− if 'ub' in self.dev_tracefuncs[name]:
470		− kpl[1].append(name)
471		− else:
472		− kpl[3].append(name)
473		− else:
474		− kpl[2].append(name)
475		− if output:
476		− print(' %s: %s' % (name, res))
477		− kplist = kpl[0] + kpl[1] + kpl[2] + kpl[3]
478		− # remove all failed ones from the list
479		− for name in rejects:
480		− self.kprobes.pop(name)
481		− # set the kprobes all at once
482		− self.fsetVal('', 'kprobe_events')
483		− kprobeevents = ''
484		− for kp in kplist:
485		− kprobeevents += self.kprobeText(kp, self.kprobes[kp])
486		− self.fsetVal(kprobeevents, 'kprobe_events')
487		− # verify that the kprobes were set as ordered
488		− check = self.fgetVal('kprobe_events')
489		− linesout = len(kprobeevents.split('\n')) - 1
490		− linesack = len(check.split('\n')) - 1
491		− if output:
492		− res = '%d/%d' % (linesack, linesout)
493		− if linesack < linesout:
494		− res = self.colorText(res, 31)
495		− else:
496		− res = self.colorText(res, 32)
497		− print(' working kprobe functions enabled: %s' % res)
498		− self.fsetVal('1', 'events/kprobes/enable')
499		− def testKprobe(self, kname, kprobe):
500		− self.fsetVal('0', 'events/kprobes/enable')
501		− kprobeevents = self.kprobeText(kname, kprobe)
502		− if not kprobeevents:
503		− return False
504		− try:
505		− self.fsetVal(kprobeevents, 'kprobe_events')
506		− check = self.fgetVal('kprobe_events')
507		− except:
508		− return False
509		− linesout = len(kprobeevents.split('\n'))
510		− linesack = len(check.split('\n'))
511		− if linesack < linesout:
512		− return False
513		− return True
514		− def fsetVal(self, val, path, mode='w'):
515		− file = self.tpath+path
516		− if not os.path.exists(file):
517		− return False
518		− try:
519		− fp = open(file, mode, 0)
520		− fp.write(val)
521		− fp.flush()
522		− fp.close()
523		− except:
524		− pass
525		− return True
526		− def fgetVal(self, path):
527		− file = self.tpath+path
528		− res = ''
529		− if not os.path.exists(file):
530		− return res
531		− try:
532		− fp = open(file, 'r')
533		− res = fp.read()
534		− fp.close()
535		− except:
536		− pass
537		− return res
538		− def cleanupFtrace(self):
539		− if(self.usecallgraph or self.usetraceevents):
540		− self.fsetVal('0', 'events/kprobes/enable')
541		− self.fsetVal('', 'kprobe_events')
542		− def setupAllKprobes(self):
543		− for name in self.tracefuncs:
544		− self.defaultKprobe(name, self.tracefuncs[name])
545		− for name in self.dev_tracefuncs:
546		− self.defaultKprobe(name, self.dev_tracefuncs[name])
547		− def isCallgraphFunc(self, name):
548		− if len(self.tracefuncs) < 1 and self.suspendmode == 'command':
549		− return True
550		− for i in self.tracefuncs:
551		− if 'func' in self.tracefuncs[i]:
552		− f = self.tracefuncs[i]['func']
553		− else:
554		− f = i
555		− if name == f:
556		− return True
557		− return False
558		− def initFtrace(self, testing=False):
559		− print('INITIALIZING FTRACE...')
560		− # turn trace off
561		− self.fsetVal('0', 'tracing_on')
562		− self.cleanupFtrace()
563		− # set the trace clock to global
564		− self.fsetVal('global', 'trace_clock')
565		− # set trace buffer to a huge value
566		− self.fsetVal('nop', 'current_tracer')
567		− self.fsetVal('100000', 'buffer_size_kb')
568		− # go no further if this is just a status check
569		− if testing:
570		− return
571		− # initialize the callgraph trace
572		− if(self.usecallgraph):
573		− # set trace type
574		− self.fsetVal('function_graph', 'current_tracer')
575		− self.fsetVal('', 'set_ftrace_filter')
576		− # set trace format options
577		− self.fsetVal('print-parent', 'trace_options')
578		− self.fsetVal('funcgraph-abstime', 'trace_options')
579		− self.fsetVal('funcgraph-cpu', 'trace_options')
580		− self.fsetVal('funcgraph-duration', 'trace_options')
581		− self.fsetVal('funcgraph-proc', 'trace_options')
582		− self.fsetVal('funcgraph-tail', 'trace_options')
583		− self.fsetVal('nofuncgraph-overhead', 'trace_options')
584		− self.fsetVal('context-info', 'trace_options')
585		− self.fsetVal('graph-time', 'trace_options')
586		− self.fsetVal('0', 'max_graph_depth')
587		− cf = ['dpm_run_callback']
588		− if(self.usetraceeventsonly):
589		− cf += ['dpm_prepare', 'dpm_complete']
590		− for fn in self.tracefuncs:
591		− if 'func' in self.tracefuncs[fn]:
592		− cf.append(self.tracefuncs[fn]['func'])
593		− else:
594		− cf.append(fn)
595		− self.setFtraceFilterFunctions(cf)
596		− # initialize the kprobe trace
597		− elif self.usekprobes:
598		− for name in self.tracefuncs:
599		− self.defaultKprobe(name, self.tracefuncs[name])
600		− if self.usedevsrc:
601		− for name in self.dev_tracefuncs:
602		− self.defaultKprobe(name, self.dev_tracefuncs[name])
603		− print('INITIALIZING KPROBES...')
604		− self.addKprobes(self.verbose)
605		− if(self.usetraceevents):
606		− # turn trace events on
607		− events = iter(self.traceevents)
608		− for e in events:
609		− self.fsetVal('1', 'events/power/'+e+'/enable')
610		− # clear the trace buffer
611		− self.fsetVal('', 'trace')
612		− def verifyFtrace(self):
613		− # files needed for any trace data
614		− files = ['buffer_size_kb', 'current_tracer', 'trace', 'trace_clock',
615		− 'trace_marker', 'trace_options', 'tracing_on']
616		− # files needed for callgraph trace data
617		− tp = self.tpath
618		− if(self.usecallgraph):
619		− files += [
620		− 'available_filter_functions',
621		− 'set_ftrace_filter',
622		− 'set_graph_function'
623		− ]
624		− for f in files:
625		− if(os.path.exists(tp+f) == False):
626		− return False
627		− return True
628		− def verifyKprobes(self):
629		− # files needed for kprobes to work
630		− files = ['kprobe_events', 'events']
631		− tp = self.tpath
632		− for f in files:
633		− if(os.path.exists(tp+f) == False):
634		− return False
635		− return True
636		− def colorText(self, str, color=31):
637		− if not self.ansi:
638		− return str
639		− return '\x1B[%d;40m%s\x1B[m' % (color, str)
640		−
641		−sysvals = SystemValues()
642		−
643		−# Class: DevProps
644		−# Description:
645		−# Simple class which holds property values collected
646		−# for all the devices used in the timeline.
647		−class DevProps:
648		− syspath = ''
649		− altname = ''
650		− async = True
651		− xtraclass = ''
652		− xtrainfo = ''
653		− def out(self, dev):
654		− return '%s,%s,%d;' % (dev, self.altname, self.async)
655		− def debug(self, dev):
656		− print '%s:\n\taltname = %s\n\t async = %s' % (dev, self.altname, self.async)
657		− def altName(self, dev):
658		− if not self.altname or self.altname == dev:
659		− return dev
660		− return '%s [%s]' % (self.altname, dev)
661		− def xtraClass(self):
662		− if self.xtraclass:
663		− return ' '+self.xtraclass
664		− if not self.async:
665		− return ' sync'
666		− return ''
667		− def xtraInfo(self):
668		− if self.xtraclass:
669		− return ' '+self.xtraclass
670		− if self.async:
671		− return ' async_device'
672		− return ' sync_device'
673		−
674		−# Class: DeviceNode
675		−# Description:
676		−# A container used to create a device hierachy, with a single root node
677		−# and a tree of child nodes. Used by Data.deviceTopology()
678		−class DeviceNode:
679		− name = ''
680		− children = 0
681		− depth = 0
682		− def __init__(self, nodename, nodedepth):
683		− self.name = nodename
684		− self.children = []
685		− self.depth = nodedepth
686		−
687		−# Class: Data
688		−# Description:
689		−# The primary container for suspend/resume test data. There is one for
690		−# each test run. The data is organized into a cronological hierarchy:
691		−# Data.dmesg {
692		−# phases {
693		−# 10 sequential, non-overlapping phases of S/R
694		−# contents: times for phase start/end, order/color data for html
695		−# devlist {
696		−# device callback or action list for this phase
697		−# device {
698		−# a single device callback or generic action
699		−# contents: start/stop times, pid/cpu/driver info
700		−# parents/children, html id for timeline/callgraph
701		−# optionally includes an ftrace callgraph
702		−# optionally includes dev/ps data
703		−# }
704		−# }
705		−# }
706		−# }
707		−#
708		−class Data:
709		− dmesg = {} # root data structure
710		− phases = [] # ordered list of phases
711		− start = 0.0 # test start
712		− end = 0.0 # test end
713		− tSuspended = 0.0 # low-level suspend start
714		− tResumed = 0.0 # low-level resume start
715		− tKernSus = 0.0 # kernel level suspend start
716		− tKernRes = 0.0 # kernel level resume end
717		− tLow = 0.0 # time spent in low-level suspend (standby/freeze)
718		− fwValid = False # is firmware data available
719		− fwSuspend = 0 # time spent in firmware suspend
720		− fwResume = 0 # time spent in firmware resume
721		− dmesgtext = [] # dmesg text file in memory
722		− pstl = 0 # process timeline
723		− testnumber = 0
724		− idstr = ''
725		− html_device_id = 0
726		− stamp = 0
727		− outfile = ''
728		− devpids = []
729		− kerror = False
730		− def __init__(self, num):
731		− idchar = 'abcdefghij'
732		− self.pstl = dict()
733		− self.testnumber = num
734		− self.idstr = idchar[num]
735		− self.dmesgtext = []
736		− self.phases = []
737		− self.dmesg = { # fixed list of 10 phases
738		− 'suspend_prepare': {'list': dict(), 'start': -1.0, 'end': -1.0,
739		− 'row': 0, 'color': '#CCFFCC', 'order': 0},
740		− 'suspend': {'list': dict(), 'start': -1.0, 'end': -1.0,
741		− 'row': 0, 'color': '#88FF88', 'order': 1},
742		− 'suspend_late': {'list': dict(), 'start': -1.0, 'end': -1.0,
743		− 'row': 0, 'color': '#00AA00', 'order': 2},
744		− 'suspend_noirq': {'list': dict(), 'start': -1.0, 'end': -1.0,
745		− 'row': 0, 'color': '#008888', 'order': 3},
746		− 'suspend_machine': {'list': dict(), 'start': -1.0, 'end': -1.0,
747		− 'row': 0, 'color': '#0000FF', 'order': 4},
748		− 'resume_machine': {'list': dict(), 'start': -1.0, 'end': -1.0,
749		− 'row': 0, 'color': '#FF0000', 'order': 5},
750		− 'resume_noirq': {'list': dict(), 'start': -1.0, 'end': -1.0,
751		− 'row': 0, 'color': '#FF9900', 'order': 6},
752		− 'resume_early': {'list': dict(), 'start': -1.0, 'end': -1.0,
753		− 'row': 0, 'color': '#FFCC00', 'order': 7},
754		− 'resume': {'list': dict(), 'start': -1.0, 'end': -1.0,
755		− 'row': 0, 'color': '#FFFF88', 'order': 8},
756		− 'resume_complete': {'list': dict(), 'start': -1.0, 'end': -1.0,
757		− 'row': 0, 'color': '#FFFFCC', 'order': 9}
758		− }
759		− self.phases = self.sortedPhases()
760		− self.devicegroups = []
761		− for phase in self.phases:
762		− self.devicegroups.append([phase])
763		− self.errorinfo = {'suspend':[],'resume':[]}
764		− def extractErrorInfo(self, dmesg):
765		− error = ''
766		− tm = 0.0
767		− for i in range(len(dmesg)):
768		− if 'Call Trace:' in dmesg[i]:
769		− m = re.match('[ \t](\[ )(?P<ktime>[0-9\.])(\]) .', dmesg[i])
770		− if not m:
771		− continue
772		− tm = float(m.group('ktime'))
773		− if tm < self.start or tm > self.end:
774		− continue
775		− for j in range(i-10, i+1):
776		− error += dmesg[j]
777		− continue
778		− if error:
779		− m = re.match('[ \t]\[ [0-9\.]\] \[\<[0-9a-fA-F]\>\] .*', dmesg[i])
780		− if m:
781		− error += dmesg[i]
782		− else:
783		− if tm < self.tSuspended:
784		− dir = 'suspend'
785		− else:
786		− dir = 'resume'
787		− error = error.replace('<', '&lt').replace('>', '&gt')
788		− vprint('kernel error found in %s at %f' % (dir, tm))
789		− self.errorinfo[dir].append((tm, error))
790		− self.kerror = True
791		− error = ''
792		− def setStart(self, time):
793		− self.start = time
794		− def setEnd(self, time):
795		− self.end = time
796		− def isTraceEventOutsideDeviceCalls(self, pid, time):
797		− for phase in self.phases:
798		− list = self.dmesg[phase]['list']
799		− for dev in list:
800		− d = list[dev]
801		− if(d['pid'] == pid and time >= d['start'] and
802		− time < d['end']):
803		− return False
804		− return True
805		− def sourcePhase(self, start):
806		− for phase in self.phases:
807		− pend = self.dmesg[phase]['end']
808		− if start <= pend:
809		− return phase
810		− return 'resume_complete'
811		− def sourceDevice(self, phaselist, start, end, pid, type):
812		− tgtdev = ''
813		− for phase in phaselist:
814		− list = self.dmesg[phase]['list']
815		− for devname in list:
816		− dev = list[devname]
817		− # pid must match
818		− if dev['pid'] != pid:
819		− continue
820		− devS = dev['start']
821		− devE = dev['end']
822		− if type == 'device':
823		− # device target event is entirely inside the source boundary
824		− if(start < devS or start >= devE or end <= devS or end > devE):
825		− continue
826		− elif type == 'thread':
827		− # thread target event will expand the source boundary
828		− if start < devS:
829		− dev['start'] = start
830		− if end > devE:
831		− dev['end'] = end
832		− tgtdev = dev
833		− break
834		− return tgtdev
835		− def addDeviceFunctionCall(self, displayname, kprobename, proc, pid, start, end, cdata, rdata):
836		− # try to place the call in a device
837		− tgtdev = self.sourceDevice(self.phases, start, end, pid, 'device')
838		− # calls with device pids that occur outside device bounds are dropped
839		− # TODO: include these somehow
840		− if not tgtdev and pid in self.devpids:
841		− return False
842		− # try to place the call in a thread
843		− if not tgtdev:
844		− tgtdev = self.sourceDevice(self.phases, start, end, pid, 'thread')
845		− # create new thread blocks, expand as new calls are found
846		− if not tgtdev:
847		− if proc == '<...>':
848		− threadname = 'kthread-%d' % (pid)
849		− else:
850		− threadname = '%s-%d' % (proc, pid)
851		− tgtphase = self.sourcePhase(start)
852		− self.newAction(tgtphase, threadname, pid, '', start, end, '', ' kth', '')
853		− return self.addDeviceFunctionCall(displayname, kprobename, proc, pid, start, end, cdata, rdata)
854		− # this should not happen
855		− if not tgtdev:
856		− vprint('[%f - %f] %s-%d %s %s %s' % \
857		− (start, end, proc, pid, kprobename, cdata, rdata))
858		− return False
859		− # place the call data inside the src element of the tgtdev
860		− if('src' not in tgtdev):
861		− tgtdev['src'] = []
862		− dtf = sysvals.dev_tracefuncs
863		− ubiquitous = False
864		− if kprobename in dtf and 'ub' in dtf[kprobename]:
865		− ubiquitous = True
866		− title = cdata+' '+rdata
867		− mstr = '$.$ (?P<args>.) \((?P<caller>.)\+. arg1=(?P<ret>.*)'
868		− m = re.match(mstr, title)
869		− if m:
870		− c = m.group('caller')
871		− a = m.group('args').strip()
872		− r = m.group('ret')
873		− if len(r) > 6:
874		− r = ''
875		− else:
876		− r = 'ret=%s ' % r
877		− if ubiquitous and c in dtf and 'ub' in dtf[c]:
878		− return False
879		− color = sysvals.kprobeColor(kprobename)
880		− e = DevFunction(displayname, a, c, r, start, end, ubiquitous, proc, pid, color)
881		− tgtdev['src'].append(e)
882		− return True
883		− def overflowDevices(self):
884		− # get a list of devices that extend beyond the end of this test run
885		− devlist = []
886		− for phase in self.phases:
887		− list = self.dmesg[phase]['list']
888		− for devname in list:
889		− dev = list[devname]
890		− if dev['end'] > self.end:
891		− devlist.append(dev)
892		− return devlist
893		− def mergeOverlapDevices(self, devlist):
894		− # merge any devices that overlap devlist
895		− for dev in devlist:
896		− devname = dev['name']
897		− for phase in self.phases:
898		− list = self.dmesg[phase]['list']
899		− if devname not in list:
900		− continue
901		− tdev = list[devname]
902		− o = min(dev['end'], tdev['end']) - max(dev['start'], tdev['start'])
903		− if o <= 0:
904		− continue
905		− dev['end'] = tdev['end']
906		− if 'src' not in dev or 'src' not in tdev:
907		− continue
908		− dev['src'] += tdev['src']
909		− del list[devname]
910		− def usurpTouchingThread(self, name, dev):
911		− # the caller test has priority of this thread, give it to him
912		− for phase in self.phases:
913		− list = self.dmesg[phase]['list']
914		− if name in list:
915		− tdev = list[name]
916		− if tdev['start'] - dev['end'] < 0.1:
917		− dev['end'] = tdev['end']
918		− if 'src' not in dev:
919		− dev['src'] = []
920		− if 'src' in tdev:
921		− dev['src'] += tdev['src']
922		− del list[name]
923		− break
924		− def stitchTouchingThreads(self, testlist):
925		− # merge any threads between tests that touch
926		− for phase in self.phases:
927		− list = self.dmesg[phase]['list']
928		− for devname in list:
929		− dev = list[devname]
930		− if 'htmlclass' not in dev or 'kth' not in dev['htmlclass']:
931		− continue
932		− for data in testlist:
933		− data.usurpTouchingThread(devname, dev)
934		− def optimizeDevSrc(self):
935		− # merge any src call loops to reduce timeline size
936		− for phase in self.phases:
937		− list = self.dmesg[phase]['list']
938		− for dev in list:
939		− if 'src' not in list[dev]:
940		− continue
941		− src = list[dev]['src']
942		− p = 0
943		− for e in sorted(src, key=lambda event: event.time):
944		− if not p or not e.repeat(p):
945		− p = e
946		− continue
947		− # e is another iteration of p, move it into p
948		− p.end = e.end
949		− p.length = p.end - p.time
950		− p.count += 1
951		− src.remove(e)
952		− def trimTimeVal(self, t, t0, dT, left):
953		− if left:
954		− if(t > t0):
955		− if(t - dT < t0):
956		− return t0
957		− return t - dT
958		− else:
959		− return t
960		− else:
961		− if(t < t0 + dT):
962		− if(t > t0):
963		− return t0 + dT
964		− return t + dT
965		− else:
966		− return t
967		− def trimTime(self, t0, dT, left):
968		− self.tSuspended = self.trimTimeVal(self.tSuspended, t0, dT, left)
969		− self.tResumed = self.trimTimeVal(self.tResumed, t0, dT, left)
970		− self.start = self.trimTimeVal(self.start, t0, dT, left)
971		− self.tKernSus = self.trimTimeVal(self.tKernSus, t0, dT, left)
972		− self.tKernRes = self.trimTimeVal(self.tKernRes, t0, dT, left)
973		− self.end = self.trimTimeVal(self.end, t0, dT, left)
974		− for phase in self.phases:
975		− p = self.dmesg[phase]
976		− p['start'] = self.trimTimeVal(p['start'], t0, dT, left)
977		− p['end'] = self.trimTimeVal(p['end'], t0, dT, left)
978		− list = p['list']
979		− for name in list:
980		− d = list[name]
981		− d['start'] = self.trimTimeVal(d['start'], t0, dT, left)
982		− d['end'] = self.trimTimeVal(d['end'], t0, dT, left)
983		− if('ftrace' in d):
984		− cg = d['ftrace']
985		− cg.start = self.trimTimeVal(cg.start, t0, dT, left)
986		− cg.end = self.trimTimeVal(cg.end, t0, dT, left)
987		− for line in cg.list:
988		− line.time = self.trimTimeVal(line.time, t0, dT, left)
989		− if('src' in d):
990		− for e in d['src']:
991		− e.time = self.trimTimeVal(e.time, t0, dT, left)
992		− def normalizeTime(self, tZero):
993		− # trim out any standby or freeze clock time
994		− if(self.tSuspended != self.tResumed):
995		− if(self.tResumed > tZero):
996		− self.trimTime(self.tSuspended, \
997		− self.tResumed-self.tSuspended, True)
998		− else:
999		− self.trimTime(self.tSuspended, \
1000		− self.tResumed-self.tSuspended, False)
1001		− def setPhase(self, phase, ktime, isbegin):
1002		− if(isbegin):
1003		− self.dmesg[phase]['start'] = ktime
1004		− else:
1005		− self.dmesg[phase]['end'] = ktime
1006		− def dmesgSortVal(self, phase):
1007		− return self.dmesg[phase]['order']
1008		− def sortedPhases(self):
1009		− return sorted(self.dmesg, key=self.dmesgSortVal)
1010		− def sortedDevices(self, phase):
1011		− list = self.dmesg[phase]['list']
1012		− slist = []
1013		− tmp = dict()
1014		− for devname in list:
1015		− dev = list[devname]
1016		− tmp[dev['start']] = devname
1017		− for t in sorted(tmp):
1018		− slist.append(tmp[t])
1019		− return slist
1020		− def fixupInitcalls(self, phase):
1021		− # if any calls never returned, clip them at system resume end
1022		− phaselist = self.dmesg[phase]['list']
1023		− for devname in phaselist:
1024		− dev = phaselist[devname]
1025		− if(dev['end'] < 0):
1026		− for p in self.phases:
1027		− if self.dmesg[p]['end'] > dev['start']:
1028		− dev['end'] = self.dmesg[p]['end']
1029		− break
1030		− vprint('%s (%s): callback didnt return' % (devname, phase))
1031		− def deviceFilter(self, devicefilter):
1032		− for phase in self.phases:
1033		− list = self.dmesg[phase]['list']
1034		− rmlist = []
1035		− for name in list:
1036		− keep = False
1037		− for filter in devicefilter:
1038		− if filter in name or \
1039		− ('drv' in list[name] and filter in list[name]['drv']):
1040		− keep = True
1041		− if not keep:
1042		− rmlist.append(name)
1043		− for name in rmlist:
1044		− del list[name]
1045		− def fixupInitcallsThatDidntReturn(self):
1046		− # if any calls never returned, clip them at system resume end
1047		− for phase in self.phases:
1048		− self.fixupInitcalls(phase)
1049		− def phaseOverlap(self, phases):
1050		− rmgroups = []
1051		− newgroup = []
1052		− for group in self.devicegroups:
1053		− for phase in phases:
1054		− if phase not in group:
1055		− continue
1056		− for p in group:
1057		− if p not in newgroup:
1058		− newgroup.append(p)
1059		− if group not in rmgroups:
1060		− rmgroups.append(group)
1061		− for group in rmgroups:
1062		− self.devicegroups.remove(group)
1063		− self.devicegroups.append(newgroup)
1064		− def newActionGlobal(self, name, start, end, pid=-1, color=''):
1065		− # which phase is this device callback or action in
1066		− targetphase = 'none'
1067		− htmlclass = ''
1068		− overlap = 0.0
1069		− phases = []
1070		− for phase in self.phases:
1071		− pstart = self.dmesg[phase]['start']
1072		− pend = self.dmesg[phase]['end']
1073		− # see if the action overlaps this phase
1074		− o = max(0, min(end, pend) - max(start, pstart))
1075		− if o > 0:
1076		− phases.append(phase)
1077		− # set the target phase to the one that overlaps most
1078		− if o > overlap:
1079		− if overlap > 0 and phase == 'post_resume':
1080		− continue
1081		− targetphase = phase
1082		− overlap = o
1083		− # if no target phase was found, pin it to the edge
1084		− if targetphase == 'none':
1085		− p0start = self.dmesg[self.phases[0]]['start']
1086		− if start <= p0start:
1087		− targetphase = self.phases[0]
1088		− else:
1089		− targetphase = self.phases[-1]
1090		− if pid == -2:
1091		− htmlclass = ' bg'
1092		− elif pid == -3:
1093		− htmlclass = ' ps'
1094		− if len(phases) > 1:
1095		− htmlclass = ' bg'
1096		− self.phaseOverlap(phases)
1097		− if targetphase in self.phases:
1098		− newname = self.newAction(targetphase, name, pid, '', start, end, '', htmlclass, color)
1099		− return (targetphase, newname)
1100		− return False
1101		− def newAction(self, phase, name, pid, parent, start, end, drv, htmlclass='', color=''):
1102		− # new device callback for a specific phase
1103		− self.html_device_id += 1
1104		− devid = '%s%d' % (self.idstr, self.html_device_id)
1105		− list = self.dmesg[phase]['list']
1106		− length = -1.0
1107		− if(start >= 0 and end >= 0):
1108		− length = end - start
1109		− if pid == -2:
1110		− i = 2
1111		− origname = name
1112		− while(name in list):
1113		− name = '%s[%d]' % (origname, i)
1114		− i += 1
1115		− list[name] = {'name': name, 'start': start, 'end': end, 'pid': pid,
1116		− 'par': parent, 'length': length, 'row': 0, 'id': devid, 'drv': drv }
1117		− if htmlclass:
1118		− list[name]['htmlclass'] = htmlclass
1119		− if color:
1120		− list[name]['color'] = color
1121		− return name
1122		− def deviceChildren(self, devname, phase):
1123		− devlist = []
1124		− list = self.dmesg[phase]['list']
1125		− for child in list:
1126		− if(list[child]['par'] == devname):
1127		− devlist.append(child)
1128		− return devlist
1129		− def printDetails(self):
1130		− vprint('Timeline Details:')
1131		− vprint(' test start: %f' % self.start)
1132		− vprint('kernel suspend start: %f' % self.tKernSus)
1133		− for phase in self.phases:
1134		− dc = len(self.dmesg[phase]['list'])
1135		− vprint(' %16s: %f - %f (%d devices)' % (phase, \
1136		− self.dmesg[phase]['start'], self.dmesg[phase]['end'], dc))
1137		− vprint(' kernel resume end: %f' % self.tKernRes)
1138		− vprint(' test end: %f' % self.end)
1139		− def deviceChildrenAllPhases(self, devname):
1140		− devlist = []
1141		− for phase in self.phases:
1142		− list = self.deviceChildren(devname, phase)
1143		− for dev in list:
1144		− if dev not in devlist:
1145		− devlist.append(dev)
1146		− return devlist
1147		− def masterTopology(self, name, list, depth):
1148		− node = DeviceNode(name, depth)
1149		− for cname in list:
1150		− # avoid recursions
1151		− if name == cname:
1152		− continue
1153		− clist = self.deviceChildrenAllPhases(cname)
1154		− cnode = self.masterTopology(cname, clist, depth+1)
1155		− node.children.append(cnode)
1156		− return node
1157		− def printTopology(self, node):
1158		− html = ''
1159		− if node.name:
1160		− info = ''
1161		− drv = ''
1162		− for phase in self.phases:
1163		− list = self.dmesg[phase]['list']
1164		− if node.name in list:
1165		− s = list[node.name]['start']
1166		− e = list[node.name]['end']
1167		− if list[node.name]['drv']:
1168		− drv = ' {'+list[node.name]['drv']+'}'
1169		− info += ('<li>%s: %.3fms</li>' % (phase, (e-s)*1000))
1170		− html += '<li><b>'+node.name+drv+'</b>'
1171		− if info:
1172		− html += '<ul>'+info+'</ul>'
1173		− html += '</li>'
1174		− if len(node.children) > 0:
1175		− html += '<ul>'
1176		− for cnode in node.children:
1177		− html += self.printTopology(cnode)
1178		− html += '</ul>'
1179		− return html
1180		− def rootDeviceList(self):
1181		− # list of devices graphed
1182		− real = []
1183		− for phase in self.dmesg:
1184		− list = self.dmesg[phase]['list']
1185		− for dev in list:
1186		− if list[dev]['pid'] >= 0 and dev not in real:
1187		− real.append(dev)
1188		− # list of top-most root devices
1189		− rootlist = []
1190		− for phase in self.dmesg:
1191		− list = self.dmesg[phase]['list']
1192		− for dev in list:
1193		− pdev = list[dev]['par']
1194		− pid = list[dev]['pid']
1195		− if(pid < 0 or re.match('[0-9]-[0-9]\.[0-9][\.0-9]\:[\.0-9]*$', pdev)):
1196		− continue
1197		− if pdev and pdev not in real and pdev not in rootlist:
1198		− rootlist.append(pdev)
1199		− return rootlist
1200		− def deviceTopology(self):
1201		− rootlist = self.rootDeviceList()
1202		− master = self.masterTopology('', rootlist, 0)
1203		− return self.printTopology(master)
1204		− def selectTimelineDevices(self, widfmt, tTotal, mindevlen):
1205		− # only select devices that will actually show up in html
1206		− self.tdevlist = dict()
1207		− for phase in self.dmesg:
1208		− devlist = []
1209		− list = self.dmesg[phase]['list']
1210		− for dev in list:
1211		− length = (list[dev]['end'] - list[dev]['start']) * 1000
1212		− width = widfmt % (((list[dev]['end']-list[dev]['start'])*100)/tTotal)
1213		− if width != '0.000000' and length >= mindevlen:
1214		− devlist.append(dev)
1215		− self.tdevlist[phase] = devlist
1216		− def addHorizontalDivider(self, devname, devend):
1217		− phase = 'suspend_prepare'
1218		− self.newAction(phase, devname, -2, '', \
1219		− self.start, devend, '', ' sec', '')
1220		− if phase not in self.tdevlist:
1221		− self.tdevlist[phase] = []
1222		− self.tdevlist[phase].append(devname)
1223		− d = DevItem(0, phase, self.dmesg[phase]['list'][devname])
1224		− return d
1225		− def addProcessUsageEvent(self, name, times):
1226		− # get the start and end times for this process
1227		− maxC = 0
1228		− tlast = 0
1229		− start = -1
1230		− end = -1
1231		− for t in sorted(times):
1232		− if tlast == 0:
1233		− tlast = t
1234		− continue
1235		− if name in self.pstl[t]:
1236		− if start == -1 or tlast < start:
1237		− start = tlast
1238		− if end == -1 or t > end:
1239		− end = t
1240		− tlast = t
1241		− if start == -1 or end == -1:
1242		− return 0
1243		− # add a new action for this process and get the object
1244		− out = self.newActionGlobal(name, start, end, -3)
1245		− if not out:
1246		− return 0
1247		− phase, devname = out
1248		− dev = self.dmesg[phase]['list'][devname]
1249		− # get the cpu exec data
1250		− tlast = 0
1251		− clast = 0
1252		− cpuexec = dict()
1253		− for t in sorted(times):
1254		− if tlast == 0 or t <= start or t > end:
1255		− tlast = t
1256		− continue
1257		− list = self.pstl[t]
1258		− c = 0
1259		− if name in list:
1260		− c = list[name]
1261		− if c > maxC:
1262		− maxC = c
1263		− if c != clast:
1264		− key = (tlast, t)
1265		− cpuexec[key] = c
1266		− tlast = t
1267		− clast = c
1268		− dev['cpuexec'] = cpuexec
1269		− return maxC
1270		− def createProcessUsageEvents(self):
1271		− # get an array of process names
1272		− proclist = []
1273		− for t in self.pstl:
1274		− pslist = self.pstl[t]
1275		− for ps in pslist:
1276		− if ps not in proclist:
1277		− proclist.append(ps)
1278		− # get a list of data points for suspend and resume
1279		− tsus = []
1280		− tres = []
1281		− for t in sorted(self.pstl):
1282		− if t < self.tSuspended:
1283		− tsus.append(t)
1284		− else:
1285		− tres.append(t)
1286		− # process the events for suspend and resume
1287		− if len(proclist) > 0:
1288		− vprint('Process Execution:')
1289		− for ps in proclist:
1290		− c = self.addProcessUsageEvent(ps, tsus)
1291		− if c > 0:
1292		− vprint('%25s (sus): %d' % (ps, c))
1293		− c = self.addProcessUsageEvent(ps, tres)
1294		− if c > 0:
1295		− vprint('%25s (res): %d' % (ps, c))
1296		−
1297		−# Class: DevFunction
1298		−# Description:
1299		−# A container for kprobe function data we want in the dev timeline
1300		−class DevFunction:
1301		− row = 0
1302		− count = 1
1303		− def __init__(self, name, args, caller, ret, start, end, u, proc, pid, color):
1304		− self.name = name
1305		− self.args = args
1306		− self.caller = caller
1307		− self.ret = ret
1308		− self.time = start
1309		− self.length = end - start
1310		− self.end = end
1311		− self.ubiquitous = u
1312		− self.proc = proc
1313		− self.pid = pid
1314		− self.color = color
1315		− def title(self):
1316		− cnt = ''
1317		− if self.count > 1:
1318		− cnt = '(x%d)' % self.count
1319		− l = '%0.3fms' % (self.length * 1000)
1320		− if self.ubiquitous:
1321		− title = '%s(%s)%s <- %s, %s(%s)' % \
1322		− (self.name, self.args, cnt, self.caller, self.ret, l)
1323		− else:
1324		− title = '%s(%s) %s%s(%s)' % (self.name, self.args, self.ret, cnt, l)
1325		− return title.replace('"', '')
1326		− def text(self):
1327		− if self.count > 1:
1328		− text = '%s(x%d)' % (self.name, self.count)
1329		− else:
1330		− text = self.name
1331		− return text
1332		− def repeat(self, tgt):
1333		− # is the tgt call just a repeat of this call (e.g. are we in a loop)
1334		− dt = self.time - tgt.end
1335		− # only combine calls if -all- attributes are identical
1336		− if tgt.caller == self.caller and \
1337		− tgt.name == self.name and tgt.args == self.args and \
1338		− tgt.proc == self.proc and tgt.pid == self.pid and \
1339		− tgt.ret == self.ret and dt >= 0 and \
1340		− dt <= sysvals.callloopmaxgap and \
1341		− self.length < sysvals.callloopmaxlen:
1342		− return True
1343		− return False
1344		−
1345		−# Class: FTraceLine
1346		−# Description:
1347		−# A container for a single line of ftrace data. There are six basic types:
1348		−# callgraph line:
1349		−# call: " dpm_run_callback() {"
1350		−# return: " }"
1351		−# leaf: " dpm_run_callback();"
1352		−# trace event:
1353		−# tracing_mark_write: SUSPEND START or RESUME COMPLETE
1354		−# suspend_resume: phase or custom exec block data
1355		−# device_pm_callback: device callback info
1356		−class FTraceLine:
1357		− time = 0.0
1358		− length = 0.0
1359		− fcall = False
1360		− freturn = False
1361		− fevent = False
1362		− fkprobe = False
1363		− depth = 0
1364		− name = ''
1365		− type = ''
1366		− def __init__(self, t, m='', d=''):
1367		− self.time = float(t)
1368		− if not m and not d:
1369		− return
1370		− # is this a trace event
1371		− if(d == 'traceevent' or re.match('^ \/\ (?P<msg>.) \\/ $', m)):
1372		− if(d == 'traceevent'):
1373		− # nop format trace event
1374		− msg = m
1375		− else:
1376		− # function_graph format trace event
1377		− em = re.match('^ \/\ (?P<msg>.) \\/ $', m)
1378		− msg = em.group('msg')
1379		−
1380		− emm = re.match('^(?P<call>.?): (?P<msg>.)', msg)
1381		− if(emm):
1382		− self.name = emm.group('msg')
1383		− self.type = emm.group('call')
1384		− else:
1385		− self.name = msg
1386		− km = re.match('^(?P<n>.*)_cal$', self.type)
1387		− if km:
1388		− self.fcall = True
1389		− self.fkprobe = True
1390		− self.type = km.group('n')
1391		− return
1392		− km = re.match('^(?P<n>.*)_ret$', self.type)
1393		− if km:
1394		− self.freturn = True
1395		− self.fkprobe = True
1396		− self.type = km.group('n')
1397		− return
1398		− self.fevent = True
1399		− return
1400		− # convert the duration to seconds
1401		− if(d):
1402		− self.length = float(d)/1000000
1403		− # the indentation determines the depth
1404		− match = re.match('^(?P<d> )(?P<o>.)$', m)
1405		− if(not match):
1406		− return
1407		− self.depth = self.getDepth(match.group('d'))
1408		− m = match.group('o')
1409		− # function return
1410		− if(m[0] == '}'):
1411		− self.freturn = True
1412		− if(len(m) > 1):
1413		− # includes comment with function name
1414		− match = re.match('^} \/\ (?P<n>.) \\/$', m)
1415		− if(match):
1416		− self.name = match.group('n').strip()
1417		− # function call
1418		− else:
1419		− self.fcall = True
1420		− # function call with children
1421		− if(m[-1] == '{'):
1422		− match = re.match('^(?P<n>.) \(.*', m)
1423		− if(match):
1424		− self.name = match.group('n').strip()
1425		− # function call with no children (leaf)
1426		− elif(m[-1] == ';'):
1427		− self.freturn = True
1428		− match = re.match('^(?P<n>.) \(.*', m)
1429		− if(match):
1430		− self.name = match.group('n').strip()
1431		− # something else (possibly a trace marker)
1432		− else:
1433		− self.name = m
1434		− def getDepth(self, str):
1435		− return len(str)/2
1436		− def debugPrint(self, dev=''):
1437		− if(self.freturn and self.fcall):
1438		− print('%s -- %f (%02d): %s(); (%.3f us)' % (dev, self.time, \
1439		− self.depth, self.name, self.length*1000000))
1440		− elif(self.freturn):
1441		− print('%s -- %f (%02d): %s} (%.3f us)' % (dev, self.time, \
1442		− self.depth, self.name, self.length*1000000))
1443		− else:
1444		− print('%s -- %f (%02d): %s() { (%.3f us)' % (dev, self.time, \
1445		− self.depth, self.name, self.length*1000000))
1446		− def startMarker(self):
1447		− # Is this the starting line of a suspend?
1448		− if not self.fevent:
1449		− return False
1450		− if sysvals.usetracemarkers:
1451		− if(self.name == 'SUSPEND START'):
1452		− return True
1453		− return False
1454		− else:
1455		− if(self.type == 'suspend_resume' and
1456		− re.match('suspend_enter\[.*\] begin', self.name)):
1457		− return True
1458		− return False
1459		− def endMarker(self):
1460		− # Is this the ending line of a resume?
1461		− if not self.fevent:
1462		− return False
1463		− if sysvals.usetracemarkers:
1464		− if(self.name == 'RESUME COMPLETE'):
1465		− return True
1466		− return False
1467		− else:
1468		− if(self.type == 'suspend_resume' and
1469		− re.match('thaw_processes\[.*\] end', self.name)):
1470		− return True
1471		− return False
1472		−
1473		−# Class: FTraceCallGraph
1474		−# Description:
1475		−# A container for the ftrace callgraph of a single recursive function.
1476		−# This can be a dpm_run_callback, dpm_prepare, or dpm_complete callgraph
1477		−# Each instance is tied to a single device in a single phase, and is
1478		−# comprised of an ordered list of FTraceLine objects
1479		−class FTraceCallGraph:
1480		− start = -1.0
1481		− end = -1.0
1482		− list = []
1483		− invalid = False
1484		− depth = 0
1485		− pid = 0
1486		− def __init__(self, pid):
1487		− self.start = -1.0
1488		− self.end = -1.0
1489		− self.list = []
1490		− self.depth = 0
1491		− self.pid = pid
1492		− def addLine(self, line, debug=False):
1493		− # if this is already invalid, just leave
1494		− if(self.invalid):
1495		− return False
1496		− # invalidate on too much data or bad depth
1497		− if(len(self.list) >= 1000000 or self.depth < 0):
1498		− self.invalidate(line)
1499		− return False
1500		− # compare current depth with this lines pre-call depth
1501		− prelinedep = line.depth
1502		− if(line.freturn and not line.fcall):
1503		− prelinedep += 1
1504		− last = 0
1505		− lasttime = line.time
1506		− virtualfname = 'execution_misalignment'
1507		− if len(self.list) > 0:
1508		− last = self.list[-1]
1509		− lasttime = last.time
1510		− # handle low misalignments by inserting returns
1511		− if prelinedep < self.depth:
1512		− if debug and last:
1513		− print '-------- task %d --------' % self.pid
1514		− last.debugPrint()
1515		− idx = 0
1516		− # add return calls to get the depth down
1517		− while prelinedep < self.depth:
1518		− if debug:
1519		− print 'MISALIGN LOW (add returns): C%d - eC%d' % (self.depth, prelinedep)
1520		− self.depth -= 1
1521		− if idx == 0 and last and last.fcall and not last.freturn:
1522		− # special case, turn last call into a leaf
1523		− last.depth = self.depth
1524		− last.freturn = True
1525		− last.length = line.time - last.time
1526		− if debug:
1527		− last.debugPrint()
1528		− else:
1529		− vline = FTraceLine(lasttime)
1530		− vline.depth = self.depth
1531		− vline.name = virtualfname
1532		− vline.freturn = True
1533		− self.list.append(vline)
1534		− if debug:
1535		− vline.debugPrint()
1536		− idx += 1
1537		− if debug:
1538		− line.debugPrint()
1539		− print ''
1540		− # handle high misalignments by inserting calls
1541		− elif prelinedep > self.depth:
1542		− if debug and last:
1543		− print '-------- task %d --------' % self.pid
1544		− last.debugPrint()
1545		− idx = 0
1546		− # add calls to get the depth up
1547		− while prelinedep > self.depth:
1548		− if debug:
1549		− print 'MISALIGN HIGH (add calls): C%d - eC%d' % (self.depth, prelinedep)
1550		− if idx == 0 and line.freturn and not line.fcall:
1551		− # special case, turn this return into a leaf
1552		− line.fcall = True
1553		− prelinedep -= 1
1554		− else:
1555		− vline = FTraceLine(lasttime)
1556		− vline.depth = self.depth
1557		− vline.name = virtualfname
1558		− vline.fcall = True
1559		− if debug:
1560		− vline.debugPrint()
1561		− self.list.append(vline)
1562		− self.depth += 1
1563		− if not last:
1564		− self.start = vline.time
1565		− idx += 1
1566		− if debug:
1567		− line.debugPrint()
1568		− print ''
1569		− # process the call and set the new depth
1570		− if(line.fcall and not line.freturn):
1571		− self.depth += 1
1572		− elif(line.freturn and not line.fcall):
1573		− self.depth -= 1
1574		− if len(self.list) < 1:
1575		− self.start = line.time
1576		− self.list.append(line)
1577		− if(line.depth == 0 and line.freturn):
1578		− if(self.start < 0):
1579		− self.start = line.time
1580		− self.end = line.time
1581		− if line.fcall:
1582		− self.end += line.length
1583		− if self.list[0].name == virtualfname:
1584		− self.invalid = True
1585		− return True
1586		− return False
1587		− def invalidate(self, line):
1588		− if(len(self.list) > 0):
1589		− first = self.list[0]
1590		− self.list = []
1591		− self.list.append(first)
1592		− self.invalid = True
1593		− id = 'task %s' % (self.pid)
1594		− window = '(%f - %f)' % (self.start, line.time)
1595		− if(self.depth < 0):
1596		− vprint('Too much data for '+id+\
1597		− ' (buffer overflow), ignoring this callback')
1598		− else:
1599		− vprint('Too much data for '+id+\
1600		− ' '+window+', ignoring this callback')
1601		− def slice(self, t0, tN):
1602		− minicg = FTraceCallGraph(0)
1603		− count = -1
1604		− firstdepth = 0
1605		− for l in self.list:
1606		− if(l.time < t0 or l.time > tN):
1607		− continue
1608		− if(count < 0):
1609		− if(not l.fcall or l.name == 'dev_driver_string'):
1610		− continue
1611		− firstdepth = l.depth
1612		− count = 0
1613		− l.depth -= firstdepth
1614		− minicg.addLine(l)
1615		− if((count == 0 and l.freturn and l.fcall) or
1616		− (count > 0 and l.depth <= 0)):
1617		− break
1618		− count += 1
1619		− return minicg
1620		− def repair(self, enddepth):
1621		− # bring the depth back to 0 with additional returns
1622		− fixed = False
1623		− last = self.list[-1]
1624		− for i in reversed(range(enddepth)):
1625		− t = FTraceLine(last.time)
1626		− t.depth = i
1627		− t.freturn = True
1628		− fixed = self.addLine(t)
1629		− if fixed:
1630		− self.end = last.time
1631		− return True
1632		− return False
1633		− def postProcess(self, debug=False):
1634		− stack = dict()
1635		− cnt = 0
1636		− for l in self.list:
1637		− if(l.fcall and not l.freturn):
1638		− stack[l.depth] = l
1639		− cnt += 1
1640		− elif(l.freturn and not l.fcall):
1641		− if(l.depth not in stack):
1642		− if debug:
1643		− print 'Post Process Error: Depth missing'
1644		− l.debugPrint()
1645		− return False
1646		− # transfer total time from return line to call line
1647		− stack[l.depth].length = l.length
1648		− stack.pop(l.depth)
1649		− l.length = 0
1650		− cnt -= 1
1651		− if(cnt == 0):
1652		− # trace caught the whole call tree
1653		− return True
1654		− elif(cnt < 0):
1655		− if debug:
1656		− print 'Post Process Error: Depth is less than 0'
1657		− return False
1658		− # trace ended before call tree finished
1659		− return self.repair(cnt)
1660		− def deviceMatch(self, pid, data):
1661		− found = False
1662		− # add the callgraph data to the device hierarchy
1663		− borderphase = {
1664		− 'dpm_prepare': 'suspend_prepare',
1665		− 'dpm_complete': 'resume_complete'
1666		− }
1667		− if(self.list[0].name in borderphase):
1668		− p = borderphase[self.list[0].name]
1669		− list = data.dmesg[p]['list']
1670		− for devname in list:
1671		− dev = list[devname]
1672		− if(pid == dev['pid'] and
1673		− self.start <= dev['start'] and
1674		− self.end >= dev['end']):
1675		− dev['ftrace'] = self.slice(dev['start'], dev['end'])
1676		− found = True
1677		− return found
1678		− for p in data.phases:
1679		− if(data.dmesg[p]['start'] <= self.start and
1680		− self.start <= data.dmesg[p]['end']):
1681		− list = data.dmesg[p]['list']
1682		− for devname in list:
1683		− dev = list[devname]
1684		− if(pid == dev['pid'] and
1685		− self.start <= dev['start'] and
1686		− self.end >= dev['end']):
1687		− dev['ftrace'] = self
1688		− found = True
1689		− break
1690		− break
1691		− return found
1692		− def newActionFromFunction(self, data):
1693		− name = self.list[0].name
1694		− if name in ['dpm_run_callback', 'dpm_prepare', 'dpm_complete']:
1695		− return
1696		− fs = self.start
1697		− fe = self.end
1698		− if fs < data.start or fe > data.end:
1699		− return
1700		− phase = ''
1701		− for p in data.phases:
1702		− if(data.dmesg[p]['start'] <= self.start and
1703		− self.start < data.dmesg[p]['end']):
1704		− phase = p
1705		− break
1706		− if not phase:
1707		− return
1708		− out = data.newActionGlobal(name, fs, fe, -2)
1709		− if out:
1710		− phase, myname = out
1711		− data.dmesg[phase]['list'][myname]['ftrace'] = self
1712		− def debugPrint(self):
1713		− print('[%f - %f] %s (%d)') % (self.start, self.end, self.list[0].name, self.pid)
1714		− for l in self.list:
1715		− if(l.freturn and l.fcall):
1716		− print('%f (%02d): %s(); (%.3f us)' % (l.time, \
1717		− l.depth, l.name, l.length*1000000))
1718		− elif(l.freturn):
1719		− print('%f (%02d): %s} (%.3f us)' % (l.time, \
1720		− l.depth, l.name, l.length*1000000))
1721		− else:
1722		− print('%f (%02d): %s() { (%.3f us)' % (l.time, \
1723		− l.depth, l.name, l.length*1000000))
1724		− print(' ')
1725		−
1726		−class DevItem:
1727		− def __init__(self, test, phase, dev):
1728		− self.test = test
1729		− self.phase = phase
1730		− self.dev = dev
1731		− def isa(self, cls):
1732		− if 'htmlclass' in self.dev and cls in self.dev['htmlclass']:
1733		− return True
1734		− return False
1735		−
1736		−# Class: Timeline
1737		−# Description:
1738		−# A container for a device timeline which calculates
1739		−# all the html properties to display it correctly
1740		−class Timeline:
1741		− html = {}
1742		− height = 0 # total timeline height
1743		− scaleH = 20 # timescale (top) row height
1744		− rowH = 30 # device row height
1745		− bodyH = 0 # body height
1746		− rows = 0 # total timeline rows
1747		− rowlines = dict()
1748		− rowheight = dict()
1749		− def __init__(self, rowheight, scaleheight):
1750		− self.rowH = rowheight
1751		− self.scaleH = scaleheight
1752		− self.html = {
1753		− 'header': '',
1754		− 'timeline': '',
1755		− 'legend': '',
1756		− }
1757		− # Function: getDeviceRows
1758		− # Description:
1759		− # determine how may rows the device funcs will take
1760		− # Arguments:
1761		− # rawlist: the list of devices/actions for a single phase
1762		− # Output:
1763		− # The total number of rows needed to display this phase of the timeline
1764		− def getDeviceRows(self, rawlist):
1765		− # clear all rows and set them to undefined
1766		− sortdict = dict()
1767		− for item in rawlist:
1768		− item.row = -1
1769		− sortdict[item] = item.length
1770		− sortlist = sorted(sortdict, key=sortdict.get, reverse=True)
1771		− remaining = len(sortlist)
1772		− rowdata = dict()
1773		− row = 1
1774		− # try to pack each row with as many ranges as possible
1775		− while(remaining > 0):
1776		− if(row not in rowdata):
1777		− rowdata[row] = []
1778		− for i in sortlist:
1779		− if(i.row >= 0):
1780		− continue
1781		− s = i.time
1782		− e = i.time + i.length
1783		− valid = True
1784		− for ritem in rowdata[row]:
1785		− rs = ritem.time
1786		− re = ritem.time + ritem.length
1787		− if(not (((s <= rs) and (e <= rs)) or
1788		− ((s >= re) and (e >= re)))):
1789		− valid = False
1790		− break
1791		− if(valid):
1792		− rowdata[row].append(i)
1793		− i.row = row
1794		− remaining -= 1
1795		− row += 1
1796		− return row
1797		− # Function: getPhaseRows
1798		− # Description:
1799		− # Organize the timeline entries into the smallest
1800		− # number of rows possible, with no entry overlapping
1801		− # Arguments:
1802		− # devlist: the list of devices/actions in a group of contiguous phases
1803		− # Output:
1804		− # The total number of rows needed to display this phase of the timeline
1805		− def getPhaseRows(self, devlist, row=0):
1806		− # clear all rows and set them to undefined
1807		− remaining = len(devlist)
1808		− rowdata = dict()
1809		− sortdict = dict()
1810		− myphases = []
1811		− # initialize all device rows to -1 and calculate devrows
1812		− for item in devlist:
1813		− dev = item.dev
1814		− tp = (item.test, item.phase)
1815		− if tp not in myphases:
1816		− myphases.append(tp)
1817		− dev['row'] = -1
1818		− # sort by length 1st, then name 2nd
1819		− sortdict[item] = (float(dev['end']) - float(dev['start']), item.dev['name'])
1820		− if 'src' in dev:
1821		− dev['devrows'] = self.getDeviceRows(dev['src'])
1822		− # sort the devlist by length so that large items graph on top
1823		− sortlist = sorted(sortdict, key=sortdict.get, reverse=True)
1824		− orderedlist = []
1825		− for item in sortlist:
1826		− if item.dev['pid'] == -2:
1827		− orderedlist.append(item)
1828		− for item in sortlist:
1829		− if item not in orderedlist:
1830		− orderedlist.append(item)
1831		− # try to pack each row with as many devices as possible
1832		− while(remaining > 0):
1833		− rowheight = 1
1834		− if(row not in rowdata):
1835		− rowdata[row] = []
1836		− for item in orderedlist:
1837		− dev = item.dev
1838		− if(dev['row'] < 0):
1839		− s = dev['start']
1840		− e = dev['end']
1841		− valid = True
1842		− for ritem in rowdata[row]:
1843		− rs = ritem.dev['start']
1844		− re = ritem.dev['end']
1845		− if(not (((s <= rs) and (e <= rs)) or
1846		− ((s >= re) and (e >= re)))):
1847		− valid = False
1848		− break
1849		− if(valid):
1850		− rowdata[row].append(item)
1851		− dev['row'] = row
1852		− remaining -= 1
1853		− if 'devrows' in dev and dev['devrows'] > rowheight:
1854		− rowheight = dev['devrows']
1855		− for t, p in myphases:
1856		− if t not in self.rowlines or t not in self.rowheight:
1857		− self.rowlines[t] = dict()
1858		− self.rowheight[t] = dict()
1859		− if p not in self.rowlines[t] or p not in self.rowheight[t]:
1860		− self.rowlines[t][p] = dict()
1861		− self.rowheight[t][p] = dict()
1862		− rh = self.rowH
1863		− # section headers should use a different row height
1864		− if len(rowdata[row]) == 1 and \
1865		− 'htmlclass' in rowdata[row][0].dev and \
1866		− 'sec' in rowdata[row][0].dev['htmlclass']:
1867		− rh = 15
1868		− self.rowlines[t][p][row] = rowheight
1869		− self.rowheight[t][p][row] = rowheight * rh
1870		− row += 1
1871		− if(row > self.rows):
1872		− self.rows = int(row)
1873		− return row
1874		− def phaseRowHeight(self, test, phase, row):
1875		− return self.rowheight[test][phase][row]
1876		− def phaseRowTop(self, test, phase, row):
1877		− top = 0
1878		− for i in sorted(self.rowheight[test][phase]):
1879		− if i >= row:
1880		− break
1881		− top += self.rowheight[test][phase][i]
1882		− return top
1883		− # Function: calcTotalRows
1884		− # Description:
1885		− # Calculate the heights and offsets for the header and rows
1886		− def calcTotalRows(self):
1887		− maxrows = 0
1888		− standardphases = []
1889		− for t in self.rowlines:
1890		− for p in self.rowlines[t]:
1891		− total = 0
1892		− for i in sorted(self.rowlines[t][p]):
1893		− total += self.rowlines[t][p][i]
1894		− if total > maxrows:
1895		− maxrows = total
1896		− if total == len(self.rowlines[t][p]):
1897		− standardphases.append((t, p))
1898		− self.height = self.scaleH + (maxrows*self.rowH)
1899		− self.bodyH = self.height - self.scaleH
1900		− # if there is 1 line per row, draw them the standard way
1901		− for t, p in standardphases:
1902		− for i in sorted(self.rowheight[t][p]):
1903		− self.rowheight[t][p][i] = self.bodyH/len(self.rowlines[t][p])
1904		− # Function: createTimeScale
1905		− # Description:
1906		− # Create the timescale for a timeline block
1907		− # Arguments:
1908		− # m0: start time (mode begin)
1909		− # mMax: end time (mode end)
1910		− # tTotal: total timeline time
1911		− # mode: suspend or resume
1912		− # Output:
1913		− # The html code needed to display the time scale
1914		− def createTimeScale(self, m0, mMax, tTotal, mode):
1915		− timescale = '<div class="t" style="right:{0}%">{1}</div>\n'
1916		− rline = '<div class="t" style="left:0;border-left:1px solid black;border-right:0;">Resume</div>\n'
1917		− output = '<div class="timescale">\n'
1918		− # set scale for timeline
1919		− mTotal = mMax - m0
1920		− tS = 0.1
1921		− if(tTotal <= 0):
1922		− return output+'</div>\n'
1923		− if(tTotal > 4):
1924		− tS = 1
1925		− divTotal = int(mTotal/tS) + 1
1926		− divEdge = (mTotal - tS(divTotal-1))100/mTotal
1927		− for i in range(divTotal):
1928		− htmlline = ''
1929		− if(mode == 'resume'):
1930		− pos = '%0.3f' % (100 - ((float(i)tS100)/mTotal))
1931		− val = '%0.fms' % (float(i)tS1000)
1932		− htmlline = timescale.format(pos, val)
1933		− if(i == 0):
1934		− htmlline = rline
1935		− else:
1936		− pos = '%0.3f' % (100 - ((float(i)tS100)/mTotal) - divEdge)
1937		− val = '%0.fms' % (float(i-divTotal+1)tS1000)
1938		− if(i == divTotal - 1):
1939		− val = 'Suspend'
1940		− htmlline = timescale.format(pos, val)
1941		− output += htmlline
1942		− output += '</div>\n'
1943		− return output
1944		−
1945		−# Class: TestProps
1946		−# Description:
1947		−# A list of values describing the properties of these test runs
1948		−class TestProps:
1949		− stamp = ''
1950		− S0i3 = False
1951		− fwdata = []
1952		− ftrace_line_fmt_fg = \
1953		− '^ (?P<time>[0-9\.]) \\| (?P<cpu>[0-9]*)\)'+\
1954		− ' (?P<proc>.)-(?P<pid>[0-9]) \\|'+\
1955		− '[ +!#\@$](?P<dur>[0-9\.]) .\\| (?P<msg>.*)'
1956		− ftrace_line_fmt_nop = \
1957		− ' (?P<proc>.)-(?P<pid>[0-9]) \[(?P<cpu>[0-9])\] '+\
1958		− '(?P<flags>.{4}) (?P<time>[0-9\.]): *'+\
1959		− '(?P<msg>.*)'
1960		− ftrace_line_fmt = ftrace_line_fmt_nop
1961		− cgformat = False
1962		− data = 0
1963		− ktemp = dict()
1964		− def __init__(self):
1965		− self.ktemp = dict()
1966		− def setTracerType(self, tracer):
1967		− if(tracer == 'function_graph'):
1968		− self.cgformat = True
1969		− self.ftrace_line_fmt = self.ftrace_line_fmt_fg
1970		− elif(tracer == 'nop'):
1971		− self.ftrace_line_fmt = self.ftrace_line_fmt_nop
1972		− else:
1973		− doError('Invalid tracer format: [%s]' % tracer)
1974		−
1975		−# Class: TestRun
1976		−# Description:
1977		−# A container for a suspend/resume test run. This is necessary as
1978		−# there could be more than one, and they need to be separate.
1979		−class TestRun:
1980		− ftemp = dict()
1981		− ttemp = dict()
1982		− data = 0
1983		− def __init__(self, dataobj):
1984		− self.data = dataobj
1985		− self.ftemp = dict()
1986		− self.ttemp = dict()
1987		−
1988		−class ProcessMonitor:
1989		− proclist = dict()
1990		− running = False
1991		− def procstat(self):
1992		− c = ['cat /proc/[1-9]*/stat 2>/dev/null']
1993		− process = Popen(c, shell=True, stdout=PIPE)
1994		− running = dict()
1995		− for line in process.stdout:
1996		− data = line.split()
1997		− pid = data[0]
1998		− name = re.sub('[()]', '', data[1])
1999		− user = int(data[13])
2000		− kern = int(data[14])
2001		− kjiff = ujiff = 0
2002		− if pid not in self.proclist:
2003		− self.proclist[pid] = {'name' : name, 'user' : user, 'kern' : kern}
2004		− else:
2005		− val = self.proclist[pid]
2006		− ujiff = user - val['user']
2007		− kjiff = kern - val['kern']
2008		− val['user'] = user
2009		− val['kern'] = kern
2010		− if ujiff > 0 or kjiff > 0:
2011		− running[pid] = ujiff + kjiff
2012		− result = process.wait()
2013		− out = ''
2014		− for pid in running:
2015		− jiffies = running[pid]
2016		− val = self.proclist[pid]
2017		− if out:
2018		− out += ','
2019		− out += '%s-%s %d' % (val['name'], pid, jiffies)
2020		− return 'ps - '+out
2021		− def processMonitor(self, tid):
2022		− while self.running:
2023		− out = self.procstat()
2024		− if out:
2025		− sysvals.fsetVal(out, 'trace_marker')
2026		− def start(self):
2027		− self.thread = Thread(target=self.processMonitor, args=(0,))
2028		− self.running = True
2029		− self.thread.start()
2030		− def stop(self):
2031		− self.running = False
2032		−
2033		−# ----------------- FUNCTIONS --------------------
2034		−
2035		−# Function: vprint
2036		−# Description:
2037		−# verbose print (prints only with -verbose option)
2038		−# Arguments:
2039		−# msg: the debug/log message to print
2040		−def vprint(msg):
2041		− sysvals.logmsg += msg+'\n'
2042		− if(sysvals.verbose):
2043		− print(msg)
2044		−
2045		−# Function: parseStamp
2046		−# Description:
2047		−# Pull in the stamp comment line from the data file(s),
2048		−# create the stamp, and add it to the global sysvals object
2049		−# Arguments:
2050		−# m: the valid re.match output for the stamp line
2051		−def parseStamp(line, data):
2052		− m = re.match(sysvals.stampfmt, line)
2053		− data.stamp = {'time': '', 'host': '', 'mode': ''}
2054		− dt = datetime(int(m.group('y'))+2000, int(m.group('m')),
2055		− int(m.group('d')), int(m.group('H')), int(m.group('M')),
2056		− int(m.group('S')))
2057		− data.stamp['time'] = dt.strftime('%B %d %Y, %I:%M:%S %p')
2058		− data.stamp['host'] = m.group('host')
2059		− data.stamp['mode'] = m.group('mode')
2060		− data.stamp['kernel'] = m.group('kernel')
2061		− sysvals.hostname = data.stamp['host']
2062		− sysvals.suspendmode = data.stamp['mode']
2063		− if sysvals.suspendmode == 'command' and sysvals.ftracefile != '':
2064		− modes = ['on', 'freeze', 'standby', 'mem']
2065		− out = Popen(['grep', 'suspend_enter', sysvals.ftracefile],
2066		− stderr=PIPE, stdout=PIPE).stdout.read()
2067		− m = re.match('.* suspend_enter\[(?P<mode>.*)\]', out)
2068		− if m and m.group('mode') in ['1', '2', '3']:
2069		− sysvals.suspendmode = modes[int(m.group('mode'))]
2070		− data.stamp['mode'] = sysvals.suspendmode
2071		− if not sysvals.stamp:
2072		− sysvals.stamp = data.stamp
2073		−
2074		−# Function: diffStamp
2075		−# Description:
2076		−# compare the host, kernel, and mode fields in 3 stamps
2077		−# Arguments:
2078		−# stamp1: string array with mode, kernel, and host
2079		−# stamp2: string array with mode, kernel, and host
2080		−# Return:
2081		−# True if stamps differ, False if they're the same
2082		−def diffStamp(stamp1, stamp2):
2083		− if 'host' in stamp1 and 'host' in stamp2:
2084		− if stamp1['host'] != stamp2['host']:
2085		− return True
2086		− if 'kernel' in stamp1 and 'kernel' in stamp2:
2087		− if stamp1['kernel'] != stamp2['kernel']:
2088		− return True
2089		− if 'mode' in stamp1 and 'mode' in stamp2:
2090		− if stamp1['mode'] != stamp2['mode']:
2091		− return True
2092		− return False
2093		−
2094		−# Function: doesTraceLogHaveTraceEvents
2095		−# Description:
2096		−# Quickly determine if the ftrace log has some or all of the trace events
2097		−# required for primary parsing. Set the usetraceevents and/or
2098		−# usetraceeventsonly flags in the global sysvals object
2099		−def doesTraceLogHaveTraceEvents():
2100		− # check for kprobes
2101		− sysvals.usekprobes = False
2102		− out = call('grep -q "_cal: (" '+sysvals.ftracefile, shell=True)
2103		− if(out == 0):
2104		− sysvals.usekprobes = True
2105		− # check for callgraph data on trace event blocks
2106		− out = call('grep -q "_cpu_down()" '+sysvals.ftracefile, shell=True)
2107		− if(out == 0):
2108		− sysvals.usekprobes = True
2109		− out = Popen(['head', '-1', sysvals.ftracefile],
2110		− stderr=PIPE, stdout=PIPE).stdout.read().replace('\n', '')
2111		− m = re.match(sysvals.stampfmt, out)
2112		− if m and m.group('mode') == 'command':
2113		− sysvals.usetraceeventsonly = True
2114		− sysvals.usetraceevents = True
2115		− return
2116		− # figure out what level of trace events are supported
2117		− sysvals.usetraceeventsonly = True
2118		− sysvals.usetraceevents = False
2119		− for e in sysvals.traceevents:
2120		− out = call('grep -q "'+e+': " '+sysvals.ftracefile, shell=True)
2121		− if(out != 0):
2122		− sysvals.usetraceeventsonly = False
2123		− if(e == 'suspend_resume' and out == 0):
2124		− sysvals.usetraceevents = True
2125		− # determine is this log is properly formatted
2126		− for e in ['SUSPEND START', 'RESUME COMPLETE']:
2127		− out = call('grep -q "'+e+'" '+sysvals.ftracefile, shell=True)
2128		− if(out != 0):
2129		− sysvals.usetracemarkers = False
2130		−
2131		−# Function: appendIncompleteTraceLog
2132		−# Description:
2133		−# [deprecated for kernel 3.15 or newer]
2134		−# Legacy support of ftrace outputs that lack the device_pm_callback
2135		−# and/or suspend_resume trace events. The primary data should be
2136		−# taken from dmesg, and this ftrace is used only for callgraph data
2137		−# or custom actions in the timeline. The data is appended to the Data
2138		−# objects provided.
2139		−# Arguments:
2140		−# testruns: the array of Data objects obtained from parseKernelLog
2141		−def appendIncompleteTraceLog(testruns):
2142		− # create TestRun vessels for ftrace parsing
2143		− testcnt = len(testruns)
2144		− testidx = 0
2145		− testrun = []
2146		− for data in testruns:
2147		− testrun.append(TestRun(data))
2148		−
2149		− # extract the callgraph and traceevent data
2150		− vprint('Analyzing the ftrace data...')
2151		− tp = TestProps()
2152		− tf = open(sysvals.ftracefile, 'r')
2153		− data = 0
2154		− for line in tf:
2155		− # remove any latent carriage returns
2156		− line = line.replace('\r\n', '')
2157		− # grab the time stamp
2158		− m = re.match(sysvals.stampfmt, line)
2159		− if(m):
2160		− tp.stamp = line
2161		− continue
2162		− # determine the trace data type (required for further parsing)
2163		− m = re.match(sysvals.tracertypefmt, line)
2164		− if(m):
2165		− tp.setTracerType(m.group('t'))
2166		− continue
2167		− # device properties line
2168		− if(re.match(sysvals.devpropfmt, line)):
2169		− devProps(line)
2170		− continue
2171		− # parse only valid lines, if this is not one move on
2172		− m = re.match(tp.ftrace_line_fmt, line)
2173		− if(not m):
2174		− continue
2175		− # gather the basic message data from the line
2176		− m_time = m.group('time')
2177		− m_pid = m.group('pid')
2178		− m_msg = m.group('msg')
2179		− if(tp.cgformat):
2180		− m_param3 = m.group('dur')
2181		− else:
2182		− m_param3 = 'traceevent'
2183		− if(m_time and m_pid and m_msg):
2184		− t = FTraceLine(m_time, m_msg, m_param3)
2185		− pid = int(m_pid)
2186		− else:
2187		− continue
2188		− # the line should be a call, return, or event
2189		− if(not t.fcall and not t.freturn and not t.fevent):
2190		− continue
2191		− # look for the suspend start marker
2192		− if(t.startMarker()):
2193		− data = testrun[testidx].data
2194		− parseStamp(tp.stamp, data)
2195		− data.setStart(t.time)
2196		− continue
2197		− if(not data):
2198		− continue
2199		− # find the end of resume
2200		− if(t.endMarker()):
2201		− data.setEnd(t.time)
2202		− testidx += 1
2203		− if(testidx >= testcnt):
2204		− break
2205		− continue
2206		− # trace event processing
2207		− if(t.fevent):
2208		− # general trace events have two types, begin and end
2209		− if(re.match('(?P<name>.*) begin$', t.name)):
2210		− isbegin = True
2211		− elif(re.match('(?P<name>.*) end$', t.name)):
2212		− isbegin = False
2213		− else:
2214		− continue
2215		− m = re.match('(?P<name>.)\[(?P<val>[0-9])\] .*', t.name)
2216		− if(m):
2217		− val = m.group('val')
2218		− if val == '0':
2219		− name = m.group('name')
2220		− else:
2221		− name = m.group('name')+'['+val+']'
2222		− else:
2223		− m = re.match('(?P<name>.) .', t.name)
2224		− name = m.group('name')
2225		− # special processing for trace events
2226		− if re.match('dpm_prepare\[.*', name):
2227		− continue
2228		− elif re.match('machine_suspend.*', name):
2229		− continue
2230		− elif re.match('suspend_enter\[.*', name):
2231		− if(not isbegin):
2232		− data.dmesg['suspend_prepare']['end'] = t.time
2233		− continue
2234		− elif re.match('dpm_suspend\[.*', name):
2235		− if(not isbegin):
2236		− data.dmesg['suspend']['end'] = t.time
2237		− continue
2238		− elif re.match('dpm_suspend_late\[.*', name):
2239		− if(isbegin):
2240		− data.dmesg['suspend_late']['start'] = t.time
2241		− else:
2242		− data.dmesg['suspend_late']['end'] = t.time
2243		− continue
2244		− elif re.match('dpm_suspend_noirq\[.*', name):
2245		− if(isbegin):
2246		− data.dmesg['suspend_noirq']['start'] = t.time
2247		− else:
2248		− data.dmesg['suspend_noirq']['end'] = t.time
2249		− continue
2250		− elif re.match('dpm_resume_noirq\[.*', name):
2251		− if(isbegin):
2252		− data.dmesg['resume_machine']['end'] = t.time
2253		− data.dmesg['resume_noirq']['start'] = t.time
2254		− else:
2255		− data.dmesg['resume_noirq']['end'] = t.time
2256		− continue
2257		− elif re.match('dpm_resume_early\[.*', name):
2258		− if(isbegin):
2259		− data.dmesg['resume_early']['start'] = t.time
2260		− else:
2261		− data.dmesg['resume_early']['end'] = t.time
2262		− continue
2263		− elif re.match('dpm_resume\[.*', name):
2264		− if(isbegin):
2265		− data.dmesg['resume']['start'] = t.time
2266		− else:
2267		− data.dmesg['resume']['end'] = t.time
2268		− continue
2269		− elif re.match('dpm_complete\[.*', name):
2270		− if(isbegin):
2271		− data.dmesg['resume_complete']['start'] = t.time
2272		− else:
2273		− data.dmesg['resume_complete']['end'] = t.time
2274		− continue
2275		− # skip trace events inside devices calls
2276		− if(not data.isTraceEventOutsideDeviceCalls(pid, t.time)):
2277		− continue
2278		− # global events (outside device calls) are simply graphed
2279		− if(isbegin):
2280		− # store each trace event in ttemp
2281		− if(name not in testrun[testidx].ttemp):
2282		− testrun[testidx].ttemp[name] = []
2283		− testrun[testidx].ttemp[name].append(\
2284		− {'begin': t.time, 'end': t.time})
2285		− else:
2286		− # finish off matching trace event in ttemp
2287		− if(name in testrun[testidx].ttemp):
2288		− testrun[testidx].ttemp[name][-1]['end'] = t.time
2289		− # call/return processing
2290		− elif sysvals.usecallgraph:
2291		− # create a callgraph object for the data
2292		− if(pid not in testrun[testidx].ftemp):
2293		− testrun[testidx].ftemp[pid] = []
2294		− testrun[testidx].ftemp[pid].append(FTraceCallGraph(pid))
2295		− # when the call is finished, see which device matches it
2296		− cg = testrun[testidx].ftemp[pid][-1]
2297		− if(cg.addLine(t)):
2298		− testrun[testidx].ftemp[pid].append(FTraceCallGraph(pid))
2299		− tf.close()
2300		−
2301		− for test in testrun:
2302		− # add the traceevent data to the device hierarchy
2303		− if(sysvals.usetraceevents):
2304		− for name in test.ttemp:
2305		− for event in test.ttemp[name]:
2306		− test.data.newActionGlobal(name, event['begin'], event['end'])
2307		−
2308		− # add the callgraph data to the device hierarchy
2309		− for pid in test.ftemp:
2310		− for cg in test.ftemp[pid]:
2311		− if len(cg.list) < 1 or cg.invalid:
2312		− continue
2313		− if(not cg.postProcess()):
2314		− id = 'task %s cpu %s' % (pid, m.group('cpu'))
2315		− vprint('Sanity check failed for '+\
2316		− id+', ignoring this callback')
2317		− continue
2318		− callstart = cg.start
2319		− callend = cg.end
2320		− for p in test.data.phases:
2321		− if(test.data.dmesg[p]['start'] <= callstart and
2322		− callstart <= test.data.dmesg[p]['end']):
2323		− list = test.data.dmesg[p]['list']
2324		− for devname in list:
2325		− dev = list[devname]
2326		− if(pid == dev['pid'] and
2327		− callstart <= dev['start'] and
2328		− callend >= dev['end']):
2329		− dev['ftrace'] = cg
2330		− break
2331		−
2332		− test.data.printDetails()
2333		−
2334		−# Function: parseTraceLog
2335		−# Description:
2336		−# Analyze an ftrace log output file generated from this app during
2337		−# the execution phase. Used when the ftrace log is the primary data source
2338		−# and includes the suspend_resume and device_pm_callback trace events
2339		−# The ftrace filename is taken from sysvals
2340		−# Output:
2341		−# An array of Data objects
2342		−def parseTraceLog():
2343		− vprint('Analyzing the ftrace data...')
2344		− if(os.path.exists(sysvals.ftracefile) == False):
2345		− doError('%s does not exist' % sysvals.ftracefile)
2346		−
2347		− sysvals.setupAllKprobes()
2348		− tracewatch = []
2349		− if sysvals.usekprobes:
2350		− tracewatch += ['sync_filesystems', 'freeze_processes', 'syscore_suspend',
2351		− 'syscore_resume', 'resume_console', 'thaw_processes', 'CPU_ON', 'CPU_OFF']
2352		−
2353		− # extract the callgraph and traceevent data
2354		− tp = TestProps()
2355		− testruns = []
2356		− testdata = []
2357		− testrun = 0
2358		− data = 0
2359		− tf = open(sysvals.ftracefile, 'r')
2360		− phase = 'suspend_prepare'
2361		− for line in tf:
2362		− # remove any latent carriage returns
2363		− line = line.replace('\r\n', '')
2364		− # stamp line: each stamp means a new test run
2365		− m = re.match(sysvals.stampfmt, line)
2366		− if(m):
2367		− tp.stamp = line
2368		− continue
2369		− # firmware line: pull out any firmware data
2370		− m = re.match(sysvals.firmwarefmt, line)
2371		− if(m):
2372		− tp.fwdata.append((int(m.group('s')), int(m.group('r'))))
2373		− continue
2374		− # tracer type line: determine the trace data type
2375		− m = re.match(sysvals.tracertypefmt, line)
2376		− if(m):
2377		− tp.setTracerType(m.group('t'))
2378		− continue
2379		− # device properties line
2380		− if(re.match(sysvals.devpropfmt, line)):
2381		− devProps(line)
2382		− continue
2383		− # ignore all other commented lines
2384		− if line[0] == '#':
2385		− continue
2386		− # ftrace line: parse only valid lines
2387		− m = re.match(tp.ftrace_line_fmt, line)
2388		− if(not m):
2389		− continue
2390		− # gather the basic message data from the line
2391		− m_time = m.group('time')
2392		− m_proc = m.group('proc')
2393		− m_pid = m.group('pid')
2394		− m_msg = m.group('msg')
2395		− if(tp.cgformat):
2396		− m_param3 = m.group('dur')
2397		− else:
2398		− m_param3 = 'traceevent'
2399		− if(m_time and m_pid and m_msg):
2400		− t = FTraceLine(m_time, m_msg, m_param3)
2401		− pid = int(m_pid)
2402		− else:
2403		− continue
2404		− # the line should be a call, return, or event
2405		− if(not t.fcall and not t.freturn and not t.fevent):
2406		− continue
2407		− # find the start of suspend
2408		− if(t.startMarker()):
2409		− phase = 'suspend_prepare'
2410		− data = Data(len(testdata))
2411		− testdata.append(data)
2412		− testrun = TestRun(data)
2413		− testruns.append(testrun)
2414		− parseStamp(tp.stamp, data)
2415		− data.setStart(t.time)
2416		− data.tKernSus = t.time
2417		− continue
2418		− if(not data):
2419		− continue
2420		− # process cpu exec line
2421		− if t.type == 'tracing_mark_write':
2422		− m = re.match(sysvals.procexecfmt, t.name)
2423		− if(m):
2424		− proclist = dict()
2425		− for ps in m.group('ps').split(','):
2426		− val = ps.split()
2427		− if not val:
2428		− continue
2429		− name = val[0].replace('--', '-')
2430		− proclist[name] = int(val[1])
2431		− data.pstl[t.time] = proclist
2432		− continue
2433		− # find the end of resume
2434		− if(t.endMarker()):
2435		− data.setEnd(t.time)
2436		− if data.tKernRes == 0.0:
2437		− data.tKernRes = t.time
2438		− if data.dmesg['resume_complete']['end'] < 0:
2439		− data.dmesg['resume_complete']['end'] = t.time
2440		− if sysvals.suspendmode == 'mem' and len(tp.fwdata) > data.testnumber:
2441		− data.fwSuspend, data.fwResume = tp.fwdata[data.testnumber]
2442		− if(data.tSuspended != 0 and data.tResumed != 0 and \
2443		− (data.fwSuspend > 0 or data.fwResume > 0)):
2444		− data.fwValid = True
2445		− if(not sysvals.usetracemarkers):
2446		− # no trace markers? then quit and be sure to finish recording
2447		− # the event we used to trigger resume end
2448		− if(len(testrun.ttemp['thaw_processes']) > 0):
2449		− # if an entry exists, assume this is its end
2450		− testrun.ttemp['thaw_processes'][-1]['end'] = t.time
2451		− break
2452		− continue
2453		− # trace event processing
2454		− if(t.fevent):
2455		− if(phase == 'post_resume'):
2456		− data.setEnd(t.time)
2457		− if(t.type == 'suspend_resume'):
2458		− # suspend_resume trace events have two types, begin and end
2459		− if(re.match('(?P<name>.*) begin$', t.name)):
2460		− isbegin = True
2461		− elif(re.match('(?P<name>.*) end$', t.name)):
2462		− isbegin = False
2463		− else:
2464		− continue
2465		− m = re.match('(?P<name>.)\[(?P<val>[0-9])\] .*', t.name)
2466		− if(m):
2467		− val = m.group('val')
2468		− if val == '0':
2469		− name = m.group('name')
2470		− else:
2471		− name = m.group('name')+'['+val+']'
2472		− else:
2473		− m = re.match('(?P<name>.) .', t.name)
2474		− name = m.group('name')
2475		− # ignore these events
2476		− if(name.split('[')[0] in tracewatch):
2477		− continue
2478		− # -- phase changes --
2479		− # start of kernel suspend
2480		− if(re.match('suspend_enter\[.*', t.name)):
2481		− if(isbegin):
2482		− data.dmesg[phase]['start'] = t.time
2483		− data.tKernSus = t.time
2484		− continue
2485		− # suspend_prepare start
2486		− elif(re.match('dpm_prepare\[.*', t.name)):
2487		− phase = 'suspend_prepare'
2488		− if(not isbegin):
2489		− data.dmesg[phase]['end'] = t.time
2490		− continue
2491		− # suspend start
2492		− elif(re.match('dpm_suspend\[.*', t.name)):
2493		− phase = 'suspend'
2494		− data.setPhase(phase, t.time, isbegin)
2495		− continue
2496		− # suspend_late start
2497		− elif(re.match('dpm_suspend_late\[.*', t.name)):
2498		− phase = 'suspend_late'
2499		− data.setPhase(phase, t.time, isbegin)
2500		− continue
2501		− # suspend_noirq start
2502		− elif(re.match('dpm_suspend_noirq\[.*', t.name)):
2503		− phase = 'suspend_noirq'
2504		− data.setPhase(phase, t.time, isbegin)
2505		− if(not isbegin):
2506		− phase = 'suspend_machine'
2507		− data.dmesg[phase]['start'] = t.time
2508		− continue
2509		− # suspend_machine/resume_machine
2510		− elif(re.match('machine_suspend\[.*', t.name)):
2511		− if(isbegin):
2512		− phase = 'suspend_machine'
2513		− data.dmesg[phase]['end'] = t.time
2514		− data.tSuspended = t.time
2515		− else:
2516		− if(sysvals.suspendmode in ['mem', 'disk'] and not tp.S0i3):
2517		− data.dmesg['suspend_machine']['end'] = t.time
2518		− data.tSuspended = t.time
2519		− phase = 'resume_machine'
2520		− data.dmesg[phase]['start'] = t.time
2521		− data.tResumed = t.time
2522		− data.tLow = data.tResumed - data.tSuspended
2523		− continue
2524		− # acpi_suspend
2525		− elif(re.match('acpi_suspend\[.*', t.name)):
2526		− # acpi_suspend[0] S0i3
2527		− if(re.match('acpi_suspend\[0\] begin', t.name)):
2528		− if(sysvals.suspendmode == 'mem'):
2529		− tp.S0i3 = True
2530		− data.dmesg['suspend_machine']['end'] = t.time
2531		− data.tSuspended = t.time
2532		− continue
2533		− # resume_noirq start
2534		− elif(re.match('dpm_resume_noirq\[.*', t.name)):
2535		− phase = 'resume_noirq'
2536		− data.setPhase(phase, t.time, isbegin)
2537		− if(isbegin):
2538		− data.dmesg['resume_machine']['end'] = t.time
2539		− continue
2540		− # resume_early start
2541		− elif(re.match('dpm_resume_early\[.*', t.name)):
2542		− phase = 'resume_early'
2543		− data.setPhase(phase, t.time, isbegin)
2544		− continue
2545		− # resume start
2546		− elif(re.match('dpm_resume\[.*', t.name)):
2547		− phase = 'resume'
2548		− data.setPhase(phase, t.time, isbegin)
2549		− continue
2550		− # resume complete start
2551		− elif(re.match('dpm_complete\[.*', t.name)):
2552		− phase = 'resume_complete'
2553		− if(isbegin):
2554		− data.dmesg[phase]['start'] = t.time
2555		− continue
2556		− # skip trace events inside devices calls
2557		− if(not data.isTraceEventOutsideDeviceCalls(pid, t.time)):
2558		− continue
2559		− # global events (outside device calls) are graphed
2560		− if(name not in testrun.ttemp):
2561		− testrun.ttemp[name] = []
2562		− if(isbegin):
2563		− # create a new list entry
2564		− testrun.ttemp[name].append(\
2565		− {'begin': t.time, 'end': t.time, 'pid': pid})
2566		− else:
2567		− if(len(testrun.ttemp[name]) > 0):
2568		− # if an entry exists, assume this is its end
2569		− testrun.ttemp[name][-1]['end'] = t.time
2570		− elif(phase == 'post_resume'):
2571		− # post resume events can just have ends
2572		− testrun.ttemp[name].append({
2573		− 'begin': data.dmesg[phase]['start'],
2574		− 'end': t.time})
2575		− # device callback start
2576		− elif(t.type == 'device_pm_callback_start'):
2577		− m = re.match('(?P<drv>.) (?P<d>.), parent: (?P<p>.), .*',\
2578		− t.name);
2579		− if(not m):
2580		− continue
2581		− drv = m.group('drv')
2582		− n = m.group('d')
2583		− p = m.group('p')
2584		− if(n and p):
2585		− data.newAction(phase, n, pid, p, t.time, -1, drv)
2586		− if pid not in data.devpids:
2587		− data.devpids.append(pid)
2588		− # device callback finish
2589		− elif(t.type == 'device_pm_callback_end'):
2590		− m = re.match('(?P<drv>.) (?P<d>.), err.*', t.name);
2591		− if(not m):
2592		− continue
2593		− n = m.group('d')
2594		− list = data.dmesg[phase]['list']
2595		− if(n in list):
2596		− dev = list[n]
2597		− dev['length'] = t.time - dev['start']
2598		− dev['end'] = t.time
2599		− # kprobe event processing
2600		− elif(t.fkprobe):
2601		− kprobename = t.type
2602		− kprobedata = t.name
2603		− key = (kprobename, pid)
2604		− # displayname is generated from kprobe data
2605		− displayname = ''
2606		− if(t.fcall):
2607		− displayname = sysvals.kprobeDisplayName(kprobename, kprobedata)
2608		− if not displayname:
2609		− continue
2610		− if(key not in tp.ktemp):
2611		− tp.ktemp[key] = []
2612		− tp.ktemp[key].append({
2613		− 'pid': pid,
2614		− 'begin': t.time,
2615		− 'end': t.time,
2616		− 'name': displayname,
2617		− 'cdata': kprobedata,
2618		− 'proc': m_proc,
2619		− })
2620		− elif(t.freturn):
2621		− if(key not in tp.ktemp) or len(tp.ktemp[key]) < 1:
2622		− continue
2623		− e = tp.ktemp[key][-1]
2624		− if e['begin'] < 0.0 or t.time - e['begin'] < 0.000001:
2625		− tp.ktemp[key].pop()
2626		− else:
2627		− e['end'] = t.time
2628		− e['rdata'] = kprobedata
2629		− # end of kernel resume
2630		− if(kprobename == 'pm_notifier_call_chain' or \
2631		− kprobename == 'pm_restore_console'):
2632		− data.dmesg[phase]['end'] = t.time
2633		− data.tKernRes = t.time
2634		−
2635		− # callgraph processing
2636		− elif sysvals.usecallgraph:
2637		− # create a callgraph object for the data
2638		− key = (m_proc, pid)
2639		− if(key not in testrun.ftemp):
2640		− testrun.ftemp[key] = []
2641		− testrun.ftemp[key].append(FTraceCallGraph(pid))
2642		− # when the call is finished, see which device matches it
2643		− cg = testrun.ftemp[key][-1]
2644		− if(cg.addLine(t)):
2645		− testrun.ftemp[key].append(FTraceCallGraph(pid))
2646		− tf.close()
2647		−
2648		− if sysvals.suspendmode == 'command':
2649		− for test in testruns:
2650		− for p in test.data.phases:
2651		− if p == 'suspend_prepare':
2652		− test.data.dmesg[p]['start'] = test.data.start
2653		− test.data.dmesg[p]['end'] = test.data.end
2654		− else:
2655		− test.data.dmesg[p]['start'] = test.data.end
2656		− test.data.dmesg[p]['end'] = test.data.end
2657		− test.data.tSuspended = test.data.end
2658		− test.data.tResumed = test.data.end
2659		− test.data.tLow = 0
2660		− test.data.fwValid = False
2661		−
2662		− # dev source and procmon events can be unreadable with mixed phase height
2663		− if sysvals.usedevsrc or sysvals.useprocmon:
2664		− sysvals.mixedphaseheight = False
2665		−
2666		− for i in range(len(testruns)):
2667		− test = testruns[i]
2668		− data = test.data
2669		− # find the total time range for this test (begin, end)
2670		− tlb, tle = data.start, data.end
2671		− if i < len(testruns) - 1:
2672		− tle = testruns[i+1].data.start
2673		− # add the process usage data to the timeline
2674		− if sysvals.useprocmon:
2675		− data.createProcessUsageEvents()
2676		− # add the traceevent data to the device hierarchy
2677		− if(sysvals.usetraceevents):
2678		− # add actual trace funcs
2679		− for name in test.ttemp:
2680		− for event in test.ttemp[name]:
2681		− data.newActionGlobal(name, event['begin'], event['end'], event['pid'])
2682		− # add the kprobe based virtual tracefuncs as actual devices
2683		− for key in tp.ktemp:
2684		− name, pid = key
2685		− if name not in sysvals.tracefuncs:
2686		− continue
2687		− for e in tp.ktemp[key]:
2688		− kb, ke = e['begin'], e['end']
2689		− if kb == ke or tlb > kb or tle <= kb:
2690		− continue
2691		− color = sysvals.kprobeColor(name)
2692		− data.newActionGlobal(e['name'], kb, ke, pid, color)
2693		− # add config base kprobes and dev kprobes
2694		− if sysvals.usedevsrc:
2695		− for key in tp.ktemp:
2696		− name, pid = key
2697		− if name in sysvals.tracefuncs or name not in sysvals.dev_tracefuncs:
2698		− continue
2699		− for e in tp.ktemp[key]:
2700		− kb, ke = e['begin'], e['end']
2701		− if kb == ke or tlb > kb or tle <= kb:
2702		− continue
2703		− data.addDeviceFunctionCall(e['name'], name, e['proc'], pid, kb,
2704		− ke, e['cdata'], e['rdata'])
2705		− if sysvals.usecallgraph:
2706		− # add the callgraph data to the device hierarchy
2707		− sortlist = dict()
2708		− for key in test.ftemp:
2709		− proc, pid = key
2710		− for cg in test.ftemp[key]:
2711		− if len(cg.list) < 1 or cg.invalid:
2712		− continue
2713		− if(not cg.postProcess()):
2714		− id = 'task %s' % (pid)
2715		− vprint('Sanity check failed for '+\
2716		− id+', ignoring this callback')
2717		− continue
2718		− # match cg data to devices
2719		− if sysvals.suspendmode == 'command' or not cg.deviceMatch(pid, data):
2720		− sortkey = '%f%f%d' % (cg.start, cg.end, pid)
2721		− sortlist[sortkey] = cg
2722		− # create blocks for orphan cg data
2723		− for sortkey in sorted(sortlist):
2724		− cg = sortlist[sortkey]
2725		− name = cg.list[0].name
2726		− if sysvals.isCallgraphFunc(name):
2727		− vprint('Callgraph found for task %d: %.3fms, %s' % (cg.pid, (cg.end - cg.start)*1000, name))
2728		− cg.newActionFromFunction(data)
2729		−
2730		− if sysvals.suspendmode == 'command':
2731		− for data in testdata:
2732		− data.printDetails()
2733		− return testdata
2734		−
2735		− # fill in any missing phases
2736		− for data in testdata:
2737		− lp = data.phases[0]
2738		− for p in data.phases:
2739		− if(data.dmesg[p]['start'] < 0 and data.dmesg[p]['end'] < 0):
2740		− vprint('WARNING: phase "%s" is missing!' % p)
2741		− if(data.dmesg[p]['start'] < 0):
2742		− data.dmesg[p]['start'] = data.dmesg[lp]['end']
2743		− if(p == 'resume_machine'):
2744		− data.tSuspended = data.dmesg[lp]['end']
2745		− data.tResumed = data.dmesg[lp]['end']
2746		− data.tLow = 0
2747		− if(data.dmesg[p]['end'] < 0):
2748		− data.dmesg[p]['end'] = data.dmesg[p]['start']
2749		− if(p != lp and not ('machine' in p and 'machine' in lp)):
2750		− data.dmesg[lp]['end'] = data.dmesg[p]['start']
2751		− lp = p
2752		−
2753		− if(len(sysvals.devicefilter) > 0):
2754		− data.deviceFilter(sysvals.devicefilter)
2755		− data.fixupInitcallsThatDidntReturn()
2756		− if sysvals.usedevsrc:
2757		− data.optimizeDevSrc()
2758		− data.printDetails()
2759		−
2760		− # x2: merge any overlapping devices between test runs
2761		− if sysvals.usedevsrc and len(testdata) > 1:
2762		− tc = len(testdata)
2763		− for i in range(tc - 1):
2764		− devlist = testdata[i].overflowDevices()
2765		− for j in range(i + 1, tc):
2766		− testdata[j].mergeOverlapDevices(devlist)
2767		− testdata[0].stitchTouchingThreads(testdata[1:])
2768		− return testdata
2769		−
2770		−# Function: loadKernelLog
2771		−# Description:
2772		−# [deprecated for kernel 3.15.0 or newer]
2773		−# load the dmesg file into memory and fix up any ordering issues
2774		−# The dmesg filename is taken from sysvals
2775		−# Output:
2776		−# An array of empty Data objects with only their dmesgtext attributes set
2777		−def loadKernelLog(justtext=False):
2778		− vprint('Analyzing the dmesg data...')
2779		− if(os.path.exists(sysvals.dmesgfile) == False):
2780		− doError('%s does not exist' % sysvals.dmesgfile)
2781		−
2782		− if justtext:
2783		− dmesgtext = []
2784		− # there can be multiple test runs in a single file
2785		− tp = TestProps()
2786		− tp.stamp = datetime.now().strftime('# suspend-%m%d%y-%H%M%S localhost mem unknown')
2787		− testruns = []
2788		− data = 0
2789		− lf = open(sysvals.dmesgfile, 'r')
2790		− for line in lf:
2791		− line = line.replace('\r\n', '')
2792		− idx = line.find('[')
2793		− if idx > 1:
2794		− line = line[idx:]
2795		− m = re.match(sysvals.stampfmt, line)
2796		− if(m):
2797		− tp.stamp = line
2798		− continue
2799		− m = re.match(sysvals.firmwarefmt, line)
2800		− if(m):
2801		− tp.fwdata.append((int(m.group('s')), int(m.group('r'))))
2802		− continue
2803		− m = re.match('[ \t](\[ )(?P<ktime>[0-9\.])(\]) (?P<msg>.)', line)
2804		− if(not m):
2805		− continue
2806		− msg = m.group("msg")
2807		− if justtext:
2808		− dmesgtext.append(line)
2809		− continue
2810		− if(re.match('PM: Syncing filesystems.*', msg)):
2811		− if(data):
2812		− testruns.append(data)
2813		− data = Data(len(testruns))
2814		− parseStamp(tp.stamp, data)
2815		− if len(tp.fwdata) > data.testnumber:
2816		− data.fwSuspend, data.fwResume = tp.fwdata[data.testnumber]
2817		− if(data.fwSuspend > 0 or data.fwResume > 0):
2818		− data.fwValid = True
2819		− if(not data):
2820		− continue
2821		− m = re.match('.* (?P<k>[0-9]\.[0-9]{2}\.[0-9]-.) .*', msg)
2822		− if(m):
2823		− sysvals.stamp['kernel'] = m.group('k')
2824		− m = re.match('PM: Preparing system for (?P<m>.*) sleep', msg)
2825		− if(m):
2826		− sysvals.stamp['mode'] = sysvals.suspendmode = m.group('m')
2827		− data.dmesgtext.append(line)
2828		− lf.close()
2829		−
2830		− if justtext:
2831		− return dmesgtext
2832		− if data:
2833		− testruns.append(data)
2834		− if len(testruns) < 1:
2835		− doError(' dmesg log has no suspend/resume data: %s' \
2836		− % sysvals.dmesgfile)
2837		−
2838		− # fix lines with same timestamp/function with the call and return swapped
2839		− for data in testruns:
2840		− last = ''
2841		− for line in data.dmesgtext:
2842		− mc = re.match('.(\[ )(?P<t>[0-9\.]*)(\]) calling '+\
2843		− '(?P<f>.)\+ @ ., parent: .*', line)
2844		− mr = re.match('.(\[ )(?P<t>[0-9\.]*)(\]) call '+\
2845		− '(?P<f>.)\+ returned . after (?P<dt>.*) usecs', last)
2846		− if(mc and mr and (mc.group('t') == mr.group('t')) and
2847		− (mc.group('f') == mr.group('f'))):
2848		− i = data.dmesgtext.index(last)
2849		− j = data.dmesgtext.index(line)
2850		− data.dmesgtext[i] = line
2851		− data.dmesgtext[j] = last
2852		− last = line
2853		− return testruns
2854		−
2855		−# Function: parseKernelLog
2856		−# Description:
2857		−# [deprecated for kernel 3.15.0 or newer]
2858		−# Analyse a dmesg log output file generated from this app during
2859		−# the execution phase. Create a set of device structures in memory
2860		−# for subsequent formatting in the html output file
2861		−# This call is only for legacy support on kernels where the ftrace
2862		−# data lacks the suspend_resume or device_pm_callbacks trace events.
2863		−# Arguments:
2864		−# data: an empty Data object (with dmesgtext) obtained from loadKernelLog
2865		−# Output:
2866		−# The filled Data object
2867		−def parseKernelLog(data):
2868		− phase = 'suspend_runtime'
2869		−
2870		− if(data.fwValid):
2871		− vprint('Firmware Suspend = %u ns, Firmware Resume = %u ns' % \
2872		− (data.fwSuspend, data.fwResume))
2873		−
2874		− # dmesg phase match table
2875		− dm = {
2876		− 'suspend_prepare': 'PM: Syncing filesystems.*',
2877		− 'suspend': 'PM: Entering [a-z]* sleep.*',
2878		− 'suspend_late': 'PM: suspend of devices complete after.*',
2879		− 'suspend_noirq': 'PM: late suspend of devices complete after.*',
2880		− 'suspend_machine': 'PM: noirq suspend of devices complete after.*',
2881		− 'resume_machine': 'ACPI: Low-level resume complete.*',
2882		− 'resume_noirq': 'ACPI: Waking up from system sleep state.*',
2883		− 'resume_early': 'PM: noirq resume of devices complete after.*',
2884		− 'resume': 'PM: early resume of devices complete after.*',
2885		− 'resume_complete': 'PM: resume of devices complete after.*',
2886		− 'post_resume': '.Restarting tasks \.\.\..',
2887		− }
2888		− if(sysvals.suspendmode == 'standby'):
2889		− dm['resume_machine'] = 'PM: Restoring platform NVS memory'
2890		− elif(sysvals.suspendmode == 'disk'):
2891		− dm['suspend_late'] = 'PM: freeze of devices complete after.*'
2892		− dm['suspend_noirq'] = 'PM: late freeze of devices complete after.*'
2893		− dm['suspend_machine'] = 'PM: noirq freeze of devices complete after.*'
2894		− dm['resume_machine'] = 'PM: Restoring platform NVS memory'
2895		− dm['resume_early'] = 'PM: noirq restore of devices complete after.*'
2896		− dm['resume'] = 'PM: early restore of devices complete after.*'
2897		− dm['resume_complete'] = 'PM: restore of devices complete after.*'
2898		− elif(sysvals.suspendmode == 'freeze'):
2899		− dm['resume_machine'] = 'ACPI: resume from mwait'
2900		−
2901		− # action table (expected events that occur and show up in dmesg)
2902		− at = {
2903		− 'sync_filesystems': {
2904		− 'smsg': 'PM: Syncing filesystems.*',
2905		− 'emsg': 'PM: Preparing system for mem sleep.*' },
2906		− 'freeze_user_processes': {
2907		− 'smsg': 'Freezing user space processes .*',
2908		− 'emsg': 'Freezing remaining freezable tasks.*' },
2909		− 'freeze_tasks': {
2910		− 'smsg': 'Freezing remaining freezable tasks.*',
2911		− 'emsg': 'PM: Entering (?P<mode>[a-z,A-Z]) sleep.' },
2912		− 'ACPI prepare': {
2913		− 'smsg': 'ACPI: Preparing to enter system sleep state.*',
2914		− 'emsg': 'PM: Saving platform NVS memory.*' },
2915		− 'PM vns': {
2916		− 'smsg': 'PM: Saving platform NVS memory.*',
2917		− 'emsg': 'Disabling non-boot CPUs .*' },
2918		− }
2919		−
2920		− t0 = -1.0
2921		− cpu_start = -1.0
2922		− prevktime = -1.0
2923		− actions = dict()
2924		− for line in data.dmesgtext:
2925		− # parse each dmesg line into the time and message
2926		− m = re.match('[ \t](\[ )(?P<ktime>[0-9\.])(\]) (?P<msg>.)', line)
2927		− if(m):
2928		− val = m.group('ktime')
2929		− try:
2930		− ktime = float(val)
2931		− except:
2932		− continue
2933		− msg = m.group('msg')
2934		− # initialize data start to first line time
2935		− if t0 < 0:
2936		− data.setStart(ktime)
2937		− t0 = ktime
2938		− else:
2939		− continue
2940		−
2941		− # hack for determining resume_machine end for freeze
2942		− if(not sysvals.usetraceevents and sysvals.suspendmode == 'freeze' \
2943		− and phase == 'resume_machine' and \
2944		− re.match('calling (?P<f>.)\+ @ ., parent: .*', msg)):
2945		− data.dmesg['resume_machine']['end'] = ktime
2946		− phase = 'resume_noirq'
2947		− data.dmesg[phase]['start'] = ktime
2948		−
2949		− # suspend start
2950		− if(re.match(dm['suspend_prepare'], msg)):
2951		− phase = 'suspend_prepare'
2952		− data.dmesg[phase]['start'] = ktime
2953		− data.setStart(ktime)
2954		− data.tKernSus = ktime
2955		− # suspend start
2956		− elif(re.match(dm['suspend'], msg)):
2957		− data.dmesg['suspend_prepare']['end'] = ktime
2958		− phase = 'suspend'
2959		− data.dmesg[phase]['start'] = ktime
2960		− # suspend_late start
2961		− elif(re.match(dm['suspend_late'], msg)):
2962		− data.dmesg['suspend']['end'] = ktime
2963		− phase = 'suspend_late'
2964		− data.dmesg[phase]['start'] = ktime
2965		− # suspend_noirq start
2966		− elif(re.match(dm['suspend_noirq'], msg)):
2967		− data.dmesg['suspend_late']['end'] = ktime
2968		− phase = 'suspend_noirq'
2969		− data.dmesg[phase]['start'] = ktime
2970		− # suspend_machine start
2971		− elif(re.match(dm['suspend_machine'], msg)):
2972		− data.dmesg['suspend_noirq']['end'] = ktime
2973		− phase = 'suspend_machine'
2974		− data.dmesg[phase]['start'] = ktime
2975		− # resume_machine start
2976		− elif(re.match(dm['resume_machine'], msg)):
2977		− if(sysvals.suspendmode in ['freeze', 'standby']):
2978		− data.tSuspended = prevktime
2979		− data.dmesg['suspend_machine']['end'] = prevktime
2980		− else:
2981		− data.tSuspended = ktime
2982		− data.dmesg['suspend_machine']['end'] = ktime
2983		− phase = 'resume_machine'
2984		− data.tResumed = ktime
2985		− data.tLow = data.tResumed - data.tSuspended
2986		− data.dmesg[phase]['start'] = ktime
2987		− # resume_noirq start
2988		− elif(re.match(dm['resume_noirq'], msg)):
2989		− data.dmesg['resume_machine']['end'] = ktime
2990		− phase = 'resume_noirq'
2991		− data.dmesg[phase]['start'] = ktime
2992		− # resume_early start
2993		− elif(re.match(dm['resume_early'], msg)):
2994		− data.dmesg['resume_noirq']['end'] = ktime
2995		− phase = 'resume_early'
2996		− data.dmesg[phase]['start'] = ktime
2997		− # resume start
2998		− elif(re.match(dm['resume'], msg)):
2999		− data.dmesg['resume_early']['end'] = ktime
3000		− phase = 'resume'
3001		− data.dmesg[phase]['start'] = ktime
3002		− # resume complete start
3003		− elif(re.match(dm['resume_complete'], msg)):
3004		− data.dmesg['resume']['end'] = ktime
3005		− phase = 'resume_complete'
3006		− data.dmesg[phase]['start'] = ktime
3007		− # post resume start
3008		− elif(re.match(dm['post_resume'], msg)):
3009		− data.dmesg['resume_complete']['end'] = ktime
3010		− data.setEnd(ktime)
3011		− data.tKernRes = ktime
3012		− break
3013		−
3014		− # -- device callbacks --
3015		− if(phase in data.phases):
3016		− # device init call
3017		− if(re.match('calling (?P<f>.)\+ @ ., parent: .*', msg)):
3018		− sm = re.match('calling (?P<f>.*)\+ @ '+\
3019		− '(?P<n>.), parent: (?P<p>.)', msg);
3020		− f = sm.group('f')
3021		− n = sm.group('n')
3022		− p = sm.group('p')
3023		− if(f and n and p):
3024		− data.newAction(phase, f, int(n), p, ktime, -1, '')
3025		− # device init return
3026		− elif(re.match('call (?P<f>.)\+ returned . after '+\
3027		− '(?P<t>.*) usecs', msg)):
3028		− sm = re.match('call (?P<f>.)\+ returned . after '+\
3029		− '(?P<t>.) usecs(?P<a>.)', msg);
3030		− f = sm.group('f')
3031		− t = sm.group('t')
3032		− list = data.dmesg[phase]['list']
3033		− if(f in list):
3034		− dev = list[f]
3035		− dev['length'] = int(t)
3036		− dev['end'] = ktime
3037		−
3038		− # if trace events are not available, these are better than nothing
3039		− if(not sysvals.usetraceevents):
3040		− # look for known actions
3041		− for a in at:
3042		− if(re.match(at[a]['smsg'], msg)):
3043		− if(a not in actions):
3044		− actions[a] = []
3045		− actions[a].append({'begin': ktime, 'end': ktime})
3046		− if(re.match(at[a]['emsg'], msg)):
3047		− if(a in actions):
3048		− actions[a][-1]['end'] = ktime
3049		− # now look for CPU on/off events
3050		− if(re.match('Disabling non-boot CPUs .*', msg)):
3051		− # start of first cpu suspend
3052		− cpu_start = ktime
3053		− elif(re.match('Enabling non-boot CPUs .*', msg)):
3054		− # start of first cpu resume
3055		− cpu_start = ktime
3056		− elif(re.match('smpboot: CPU (?P<cpu>[0-9]*) is now offline', msg)):
3057		− # end of a cpu suspend, start of the next
3058		− m = re.match('smpboot: CPU (?P<cpu>[0-9]*) is now offline', msg)
3059		− cpu = 'CPU'+m.group('cpu')
3060		− if(cpu not in actions):
3061		− actions[cpu] = []
3062		− actions[cpu].append({'begin': cpu_start, 'end': ktime})
3063		− cpu_start = ktime
3064		− elif(re.match('CPU(?P<cpu>[0-9]*) is up', msg)):
3065		− # end of a cpu resume, start of the next
3066		− m = re.match('CPU(?P<cpu>[0-9]*) is up', msg)
3067		− cpu = 'CPU'+m.group('cpu')
3068		− if(cpu not in actions):
3069		− actions[cpu] = []
3070		− actions[cpu].append({'begin': cpu_start, 'end': ktime})
3071		− cpu_start = ktime
3072		− prevktime = ktime
3073		−
3074		− # fill in any missing phases
3075		− lp = data.phases[0]
3076		− for p in data.phases:
3077		− if(data.dmesg[p]['start'] < 0 and data.dmesg[p]['end'] < 0):
3078		− print('WARNING: phase "%s" is missing, something went wrong!' % p)
3079		− print(' In %s, this dmesg line denotes the start of %s:' % \
3080		− (sysvals.suspendmode, p))
3081		− print(' "%s"' % dm[p])
3082		− if(data.dmesg[p]['start'] < 0):
3083		− data.dmesg[p]['start'] = data.dmesg[lp]['end']
3084		− if(p == 'resume_machine'):
3085		− data.tSuspended = data.dmesg[lp]['end']
3086		− data.tResumed = data.dmesg[lp]['end']
3087		− data.tLow = 0
3088		− if(data.dmesg[p]['end'] < 0):
3089		− data.dmesg[p]['end'] = data.dmesg[p]['start']
3090		− lp = p
3091		−
3092		− # fill in any actions we've found
3093		− for name in actions:
3094		− for event in actions[name]:
3095		− data.newActionGlobal(name, event['begin'], event['end'])
3096		−
3097		− data.printDetails()
3098		− if(len(sysvals.devicefilter) > 0):
3099		− data.deviceFilter(sysvals.devicefilter)
3100		− data.fixupInitcallsThatDidntReturn()
3101		− return True
3102		−
3103		−# Function: createHTMLSummarySimple
3104		−# Description:
3105		−# Create summary html file for a series of tests
3106		−# Arguments:
3107		−# testruns: array of Data objects from parseTraceLog
3108		−def createHTMLSummarySimple(testruns, htmlfile):
3109		− # print out the basic summary of all the tests
3110		− hf = open(htmlfile, 'w')
3111		−
3112		− # write the html header first (html head, css code, up to body start)
3113		− html = '<!DOCTYPE html>\n<html>\n<head>\n\
3114		− <meta http-equiv="content-type" content="text/html; charset=UTF-8">\n\
3115		− <title>AnalyzeSuspend Summary</title>\n\
3116		− <style type=\'text/css\'>\n\
3117		− body {overflow-y: scroll;}\n\
3118		− .stamp {width: 100%;text-align:center;background-color:#495E09;line-height:30px;color:white;font: 25px Arial;}\n\
3119		− table {width:100%;border-collapse: collapse;}\n\
3120		− .summary {font: 22px Arial;border:1px solid;}\n\
3121		− th {border: 1px solid black;background-color:#A7C942;color:white;}\n\
3122		− td {text-align: center;}\n\
3123		− tr.alt td {background-color:#EAF2D3;}\n\
3124		− tr.avg td {background-color:#BDE34C;}\n\
3125		− a:link {color: #90B521;}\n\
3126		− a:visited {color: #495E09;}\n\
3127		− a:hover {color: #B1DF28;}\n\
3128		− a:active {color: #FFFFFF;}\n\
3129		− </style>\n</head>\n<body>\n'
3130		−
3131		− # group test header
3132		− count = len(testruns)
3133		− headline_stamp = '<div class="stamp">{0} {1} {2} {3} ({4} tests)</div>\n'
3134		− html += headline_stamp.format(sysvals.stamp['host'],
3135		− sysvals.stamp['kernel'], sysvals.stamp['mode'],
3136		− sysvals.stamp['time'], count)
3137		−
3138		− # check to see if all the tests have the same value
3139		− stampcolumns = False
3140		− for data in testruns:
3141		− if diffStamp(sysvals.stamp, data.stamp):
3142		− stampcolumns = True
3143		− break
3144		−
3145		− th = '\t<th>{0}</th>\n'
3146		− td = '\t<td>{0}</td>\n'
3147		− tdlink = '\t<td><a href="{0}">Click Here</a></td>\n'
3148		−
3149		− # table header
3150		− html += '<table class="summary">\n<tr>\n'
3151		− html += th.format("Test #")
3152		− if stampcolumns:
3153		− html += th.format("Hostname")
3154		− html += th.format("Kernel Version")
3155		− html += th.format("Suspend Mode")
3156		− html += th.format("Test Time")
3157		− html += th.format("Suspend Time")
3158		− html += th.format("Resume Time")
3159		− html += th.format("Detail")
3160		− html += '</tr>\n'
3161		−
3162		− # test data, 1 row per test
3163		− sTimeAvg = 0.0
3164		− rTimeAvg = 0.0
3165		− num = 1
3166		− for data in testruns:
3167		− # data.end is the end of post_resume
3168		− resumeEnd = data.dmesg['resume_complete']['end']
3169		− if num % 2 == 1:
3170		− html += '<tr class="alt">\n'
3171		− else:
3172		− html += '<tr>\n'
3173		−
3174		− # test num
3175		− html += td.format("test %d" % num)
3176		− num += 1
3177		− if stampcolumns:
3178		− # host name
3179		− val = "unknown"
3180		− if('host' in data.stamp):
3181		− val = data.stamp['host']
3182		− html += td.format(val)
3183		− # host kernel
3184		− val = "unknown"
3185		− if('kernel' in data.stamp):
3186		− val = data.stamp['kernel']
3187		− html += td.format(val)
3188		− # suspend mode
3189		− val = "unknown"
3190		− if('mode' in data.stamp):
3191		− val = data.stamp['mode']
3192		− html += td.format(val)
3193		− # test time
3194		− val = "unknown"
3195		− if('time' in data.stamp):
3196		− val = data.stamp['time']
3197		− html += td.format(val)
3198		− # suspend time
3199		− sTime = (data.tSuspended - data.start)*1000
3200		− sTimeAvg += sTime
3201		− html += td.format("%3.3f ms" % sTime)
3202		− # resume time
3203		− rTime = (resumeEnd - data.tResumed)*1000
3204		− rTimeAvg += rTime
3205		− html += td.format("%3.3f ms" % rTime)
3206		− # link to the output html
3207		− html += tdlink.format(data.outfile)
3208		−
3209		− html += '</tr>\n'
3210		−
3211		− # last line: test average
3212		− if(count > 0):
3213		− sTimeAvg /= count
3214		− rTimeAvg /= count
3215		− html += '<tr class="avg">\n'
3216		− html += td.format('Average') # name
3217		− if stampcolumns:
3218		− html += td.format('') # host
3219		− html += td.format('') # kernel
3220		− html += td.format('') # mode
3221		− html += td.format('') # time
3222		− html += td.format("%3.3f ms" % sTimeAvg) # suspend time
3223		− html += td.format("%3.3f ms" % rTimeAvg) # resume time
3224		− html += td.format('') # output link
3225		− html += '</tr>\n'
3226		−
3227		− # flush the data to file
3228		− hf.write(html+'</table>\n')
3229		− hf.write('</body>\n</html>\n')
3230		− hf.close()
3231		−
3232		−def htmlTitle():
3233		− modename = {
3234		− 'freeze': 'Freeze (S0)',
3235		− 'standby': 'Standby (S1)',
3236		− 'mem': 'Suspend (S3)',
3237		− 'disk': 'Hibernate (S4)'
3238		− }
3239		− kernel = sysvals.stamp['kernel']
3240		− host = sysvals.hostname[0].upper()+sysvals.hostname[1:]
3241		− mode = sysvals.suspendmode
3242		− if sysvals.suspendmode in modename:
3243		− mode = modename[sysvals.suspendmode]
3244		− return host+' '+mode+' '+kernel
3245		−
3246		−def ordinal(value):
3247		− suffix = 'th'
3248		− if value < 10 or value > 19:
3249		− if value % 10 == 1:
3250		− suffix = 'st'
3251		− elif value % 10 == 2:
3252		− suffix = 'nd'
3253		− elif value % 10 == 3:
3254		− suffix = 'rd'
3255		− return '%d%s' % (value, suffix)
3256		−
3257		−# Function: createHTML
3258		−# Description:
3259		−# Create the output html file from the resident test data
3260		−# Arguments:
3261		−# testruns: array of Data objects from parseKernelLog or parseTraceLog
3262		−# Output:
3263		−# True if the html file was created, false if it failed
3264		−def createHTML(testruns):
3265		− if len(testruns) < 1:
3266		− print('ERROR: Not enough test data to build a timeline')
3267		− return
3268		−
3269		− kerror = False
3270		− for data in testruns:
3271		− if data.kerror:
3272		− kerror = True
3273		− data.normalizeTime(testruns[-1].tSuspended)
3274		−
3275		− x2changes = ['', 'absolute']
3276		− if len(testruns) > 1:
3277		− x2changes = ['1', 'relative']
3278		− # html function templates
3279		− headline_version = '<div class="version"><a href="https://01.org/suspendresume">AnalyzeSuspend v%s</a></div>' % sysvals.version
3280		− headline_stamp = '<div class="stamp">{0} {1} {2} {3}</div>\n'
3281		− html_devlist1 = '<button id="devlist1" class="devlist" style="float:left;">Device Detail%s</button>' % x2changes[0]
3282		− html_zoombox = '<center><button id="zoomin">ZOOM IN +</button><button id="zoomout">ZOOM OUT -</button><button id="zoomdef">ZOOM 1:1</button></center>\n'
3283		− html_devlist2 = '<button id="devlist2" class="devlist" style="float:right;">Device Detail2</button>\n'
3284		− html_timeline = '<div id="dmesgzoombox" class="zoombox">\n<div id="{0}" class="timeline" style="height:{1}px">\n'
3285		− html_tblock = '<div id="block{0}" class="tblock" style="left:{1}%;width:{2}%;"><div class="tback" style="height:{3}px"></div>\n'
3286		− html_device = '<div id="{0}" title="{1}" class="thread{7}" style="left:{2}%;top:{3}px;height:{4}px;width:{5}%;{8}">{6}</div>\n'
3287		− html_error = '<div id="{1}" title="kernel error/warning" class="err" style="right:{0}%">ERROR→</div>\n'
3288		− html_traceevent = '<div title="{0}" class="traceevent{6}" style="left:{1}%;top:{2}px;height:{3}px;width:{4}%;line-height:{3}px;{7}">{5}</div>\n'
3289		− html_cpuexec = '<div class="jiffie" style="left:{0}%;top:{1}px;height:{2}px;width:{3}%;background:{4};"></div>\n'
3290		− html_phase = '<div class="phase" style="left:{0}%;width:{1}%;top:{2}px;height:{3}px;background-color:{4}">{5}</div>\n'
3291		− html_phaselet = '<div id="{0}" class="phaselet" style="left:{1}%;width:{2}%;background:{3}"></div>\n'
3292		− html_legend = '<div id="p{3}" class="square" style="left:{0}%;background-color:{1}"> {2}</div>\n'
3293		− html_timetotal = '<table class="time1">\n<tr>'\
3294		− '<td class="green" title="{3}">{2} Suspend Time: <b>{0} ms</b></td>'\
3295		− '<td class="yellow" title="{4}">{2} Resume Time: <b>{1} ms</b></td>'\
3296		− '</tr>\n</table>\n'
3297		− html_timetotal2 = '<table class="time1">\n<tr>'\
3298		− '<td class="green" title="{4}">{3} Suspend Time: <b>{0} ms</b></td>'\
3299		− '<td class="gray" title="time spent in low-power mode with clock running">'+sysvals.suspendmode+' time: <b>{1} ms</b></td>'\
3300		− '<td class="yellow" title="{5}">{3} Resume Time: <b>{2} ms</b></td>'\
3301		− '</tr>\n</table>\n'
3302		− html_timetotal3 = '<table class="time1">\n<tr>'\
3303		− '<td class="green">Execution Time: <b>{0} ms</b></td>'\
3304		− '<td class="yellow">Command: <b>{1}</b></td>'\
3305		− '</tr>\n</table>\n'
3306		− html_timegroups = '<table class="time2">\n<tr>'\
3307		− '<td class="green" title="time from kernel enter_state({5}) to firmware mode [kernel time only]">{4}Kernel Suspend: {0} ms</td>'\
3308		− '<td class="purple">{4}Firmware Suspend: {1} ms</td>'\
3309		− '<td class="purple">{4}Firmware Resume: {2} ms</td>'\
3310		− '<td class="yellow" title="time from firmware mode to return from kernel enter_state({5}) [kernel time only]">{4}Kernel Resume: {3} ms</td>'\
3311		− '</tr>\n</table>\n'
3312		−
3313		− # html format variables
3314		− hoverZ = 'z-index:8;'
3315		− if sysvals.usedevsrc:
3316		− hoverZ = ''
3317		− scaleH = 20
3318		− scaleTH = 20
3319		− if kerror:
3320		− scaleH = 40
3321		− scaleTH = 60
3322		−
3323		− # device timeline
3324		− vprint('Creating Device Timeline...')
3325		−
3326		− devtl = Timeline(30, scaleH)
3327		−
3328		− # Generate the header for this timeline
3329		− for data in testruns:
3330		− tTotal = data.end - data.start
3331		− sktime = (data.dmesg['suspend_machine']['end'] - \
3332		− data.tKernSus) * 1000
3333		− rktime = (data.dmesg['resume_complete']['end'] - \
3334		− data.dmesg['resume_machine']['start']) * 1000
3335		− if(tTotal == 0):
3336		− print('ERROR: No timeline data')
3337		− sys.exit()
3338		− if(data.tLow > 0):
3339		− low_time = '%.0f'%(data.tLow*1000)
3340		− if sysvals.suspendmode == 'command':
3341		− run_time = '%.0f'%((data.end-data.start)*1000)
3342		− if sysvals.testcommand:
3343		− testdesc = sysvals.testcommand
3344		− else:
3345		− testdesc = 'unknown'
3346		− if(len(testruns) > 1):
3347		− testdesc = ordinal(data.testnumber+1)+' '+testdesc
3348		− thtml = html_timetotal3.format(run_time, testdesc)
3349		− devtl.html['header'] += thtml
3350		− elif data.fwValid:
3351		− suspend_time = '%.0f'%(sktime + (data.fwSuspend/1000000.0))
3352		− resume_time = '%.0f'%(rktime + (data.fwResume/1000000.0))
3353		− testdesc1 = 'Total'
3354		− testdesc2 = ''
3355		− stitle = 'time from kernel enter_state(%s) to low-power mode [kernel & firmware time]' % sysvals.suspendmode
3356		− rtitle = 'time from low-power mode to return from kernel enter_state(%s) [firmware & kernel time]' % sysvals.suspendmode
3357		− if(len(testruns) > 1):
3358		− testdesc1 = testdesc2 = ordinal(data.testnumber+1)
3359		− testdesc2 += ' '
3360		− if(data.tLow == 0):
3361		− thtml = html_timetotal.format(suspend_time, \
3362		− resume_time, testdesc1, stitle, rtitle)
3363		− else:
3364		− thtml = html_timetotal2.format(suspend_time, low_time, \
3365		− resume_time, testdesc1, stitle, rtitle)
3366		− devtl.html['header'] += thtml
3367		− sftime = '%.3f'%(data.fwSuspend / 1000000.0)
3368		− rftime = '%.3f'%(data.fwResume / 1000000.0)
3369		− devtl.html['header'] += html_timegroups.format('%.3f'%sktime, \
3370		− sftime, rftime, '%.3f'%rktime, testdesc2, sysvals.suspendmode)
3371		− else:
3372		− suspend_time = '%.3f' % sktime
3373		− resume_time = '%.3f' % rktime
3374		− testdesc = 'Kernel'
3375		− stitle = 'time from kernel enter_state(%s) to firmware mode [kernel time only]' % sysvals.suspendmode
3376		− rtitle = 'time from firmware mode to return from kernel enter_state(%s) [kernel time only]' % sysvals.suspendmode
3377		− if(len(testruns) > 1):
3378		− testdesc = ordinal(data.testnumber+1)+' '+testdesc
3379		− if(data.tLow == 0):
3380		− thtml = html_timetotal.format(suspend_time, \
3381		− resume_time, testdesc, stitle, rtitle)
3382		− else:
3383		− thtml = html_timetotal2.format(suspend_time, low_time, \
3384		− resume_time, testdesc, stitle, rtitle)
3385		− devtl.html['header'] += thtml
3386		−
3387		− # time scale for potentially multiple datasets
3388		− t0 = testruns[0].start
3389		− tMax = testruns[-1].end
3390		− tTotal = tMax - t0
3391		−
3392		− # determine the maximum number of rows we need to draw
3393		− fulllist = []
3394		− threadlist = []
3395		− pscnt = 0
3396		− devcnt = 0
3397		− for data in testruns:
3398		− data.selectTimelineDevices('%f', tTotal, sysvals.mindevlen)
3399		− for group in data.devicegroups:
3400		− devlist = []
3401		− for phase in group:
3402		− for devname in data.tdevlist[phase]:
3403		− d = DevItem(data.testnumber, phase, data.dmesg[phase]['list'][devname])
3404		− devlist.append(d)
3405		− if d.isa('kth'):
3406		− threadlist.append(d)
3407		− else:
3408		− if d.isa('ps'):
3409		− pscnt += 1
3410		− else:
3411		− devcnt += 1
3412		− fulllist.append(d)
3413		− if sysvals.mixedphaseheight:
3414		− devtl.getPhaseRows(devlist)
3415		− if not sysvals.mixedphaseheight:
3416		− if len(threadlist) > 0 and len(fulllist) > 0:
3417		− if pscnt > 0 and devcnt > 0:
3418		− msg = 'user processes & device pm callbacks'
3419		− elif pscnt > 0:
3420		− msg = 'user processes'
3421		− else:
3422		− msg = 'device pm callbacks'
3423		− d = testruns[0].addHorizontalDivider(msg, testruns[-1].end)
3424		− fulllist.insert(0, d)
3425		− devtl.getPhaseRows(fulllist)
3426		− if len(threadlist) > 0:
3427		− d = testruns[0].addHorizontalDivider('asynchronous kernel threads', testruns[-1].end)
3428		− threadlist.insert(0, d)
3429		− devtl.getPhaseRows(threadlist, devtl.rows)
3430		− devtl.calcTotalRows()
3431		−
3432		− # create bounding box, add buttons
3433		− if sysvals.suspendmode != 'command':
3434		− devtl.html['timeline'] += html_devlist1
3435		− if len(testruns) > 1:
3436		− devtl.html['timeline'] += html_devlist2
3437		− devtl.html['timeline'] += html_zoombox
3438		− devtl.html['timeline'] += html_timeline.format('dmesg', devtl.height)
3439		−
3440		− # draw the full timeline
3441		− phases = {'suspend':[],'resume':[]}
3442		− for phase in data.dmesg:
3443		− if 'resume' in phase:
3444		− phases['resume'].append(phase)
3445		− else:
3446		− phases['suspend'].append(phase)
3447		−
3448		− # draw each test run chronologically
3449		− for data in testruns:
3450		− # now draw the actual timeline blocks
3451		− for dir in phases:
3452		− # draw suspend and resume blocks separately
3453		− bname = '%s%d' % (dir[0], data.testnumber)
3454		− if dir == 'suspend':
3455		− m0 = testruns[data.testnumber].start
3456		− mMax = testruns[data.testnumber].tSuspended
3457		− mTotal = mMax - m0
3458		− left = '%f' % (((m0-t0)*100.0)/tTotal)
3459		− else:
3460		− m0 = testruns[data.testnumber].tSuspended
3461		− mMax = testruns[data.testnumber].end
3462		− # in an x2 run, remove any gap between blocks
3463		− if len(testruns) > 1 and data.testnumber == 0:
3464		− mMax = testruns[1].start
3465		− mTotal = mMax - m0
3466		− left = '%f' % ((((m0-t0)*100.0)+sysvals.srgap/2)/tTotal)
3467		− # if a timeline block is 0 length, skip altogether
3468		− if mTotal == 0:
3469		− continue
3470		− width = '%f' % (((mTotal*100.0)-sysvals.srgap/2)/tTotal)
3471		− devtl.html['timeline'] += html_tblock.format(bname, left, width, devtl.scaleH)
3472		− for b in sorted(phases[dir]):
3473		− # draw the phase color background
3474		− phase = data.dmesg[b]
3475		− length = phase['end']-phase['start']
3476		− left = '%f' % (((phase['start']-m0)*100.0)/mTotal)
3477		− width = '%f' % ((length*100.0)/mTotal)
3478		− devtl.html['timeline'] += html_phase.format(left, width, \
3479		− '%.3f'%devtl.scaleH, '%.3f'%devtl.bodyH, \
3480		− data.dmesg[b]['color'], '')
3481		− for e in data.errorinfo[dir]:
3482		− # draw red lines for any kernel errors found
3483		− t, err = e
3484		− right = '%f' % (((mMax-t)*100.0)/mTotal)
3485		− devtl.html['timeline'] += html_error.format(right, err)
3486		− for b in sorted(phases[dir]):
3487		− # draw the devices for this phase
3488		− phaselist = data.dmesg[b]['list']
3489		− for d in data.tdevlist[b]:
3490		− name = d
3491		− drv = ''
3492		− dev = phaselist[d]
3493		− xtraclass = ''
3494		− xtrainfo = ''
3495		− xtrastyle = ''
3496		− if 'htmlclass' in dev:
3497		− xtraclass = dev['htmlclass']
3498		− if 'color' in dev:
3499		− xtrastyle = 'background-color:%s;' % dev['color']
3500		− if(d in sysvals.devprops):
3501		− name = sysvals.devprops[d].altName(d)
3502		− xtraclass = sysvals.devprops[d].xtraClass()
3503		− xtrainfo = sysvals.devprops[d].xtraInfo()
3504		− elif xtraclass == ' kth':
3505		− xtrainfo = ' kernel_thread'
3506		− if('drv' in dev and dev['drv']):
3507		− drv = ' {%s}' % dev['drv']
3508		− rowheight = devtl.phaseRowHeight(data.testnumber, b, dev['row'])
3509		− rowtop = devtl.phaseRowTop(data.testnumber, b, dev['row'])
3510		− top = '%.3f' % (rowtop + devtl.scaleH)
3511		− left = '%f' % (((dev['start']-m0)*100)/mTotal)
3512		− width = '%f' % (((dev['end']-dev['start'])*100)/mTotal)
3513		− length = ' (%0.3f ms) ' % ((dev['end']-dev['start'])*1000)
3514		− title = name+drv+xtrainfo+length
3515		− if sysvals.suspendmode == 'command':
3516		− title += sysvals.testcommand
3517		− elif xtraclass == ' ps':
3518		− if 'suspend' in b:
3519		− title += 'pre_suspend_process'
3520		− else:
3521		− title += 'post_resume_process'
3522		− else:
3523		− title += b
3524		− devtl.html['timeline'] += html_device.format(dev['id'], \
3525		− title, left, top, '%.3f'%rowheight, width, \
3526		− d+drv, xtraclass, xtrastyle)
3527		− if('cpuexec' in dev):
3528		− for t in sorted(dev['cpuexec']):
3529		− start, end = t
3530		− j = float(dev['cpuexec'][t]) / 5
3531		− if j > 1.0:
3532		− j = 1.0
3533		− height = '%.3f' % (rowheight/3)
3534		− top = '%.3f' % (rowtop + devtl.scaleH + 2*rowheight/3)
3535		− left = '%f' % (((start-m0)*100)/mTotal)
3536		− width = '%f' % ((end-start)*100/mTotal)
3537		− color = 'rgba(255, 0, 0, %f)' % j
3538		− devtl.html['timeline'] += \
3539		− html_cpuexec.format(left, top, height, width, color)
3540		− if('src' not in dev):
3541		− continue
3542		− # draw any trace events for this device
3543		− for e in dev['src']:
3544		− height = '%.3f' % devtl.rowH
3545		− top = '%.3f' % (rowtop + devtl.scaleH + (e.row*devtl.rowH))
3546		− left = '%f' % (((e.time-m0)*100)/mTotal)
3547		− width = '%f' % (e.length*100/mTotal)
3548		− xtrastyle = ''
3549		− if e.color:
3550		− xtrastyle = 'background:%s;' % e.color
3551		− devtl.html['timeline'] += \
3552		− html_traceevent.format(e.title(), \
3553		− left, top, height, width, e.text(), '', xtrastyle)
3554		− # draw the time scale, try to make the number of labels readable
3555		− devtl.html['timeline'] += devtl.createTimeScale(m0, mMax, tTotal, dir)
3556		− devtl.html['timeline'] += '</div>\n'
3557		−
3558		− # timeline is finished
3559		− devtl.html['timeline'] += '</div>\n</div>\n'
3560		−
3561		− # draw a legend which describes the phases by color
3562		− if sysvals.suspendmode != 'command':
3563		− data = testruns[-1]
3564		− devtl.html['legend'] = '<div class="legend">\n'
3565		− pdelta = 100.0/len(data.phases)
3566		− pmargin = pdelta / 4.0
3567		− for phase in data.phases:
3568		− tmp = phase.split('_')
3569		− id = tmp[0][0]
3570		− if(len(tmp) > 1):
3571		− id += tmp[1][0]
3572		− order = '%.2f' % ((data.dmesg[phase]['order'] * pdelta) + pmargin)
3573		− name = string.replace(phase, '_', '  ')
3574		− devtl.html['legend'] += html_legend.format(order, \
3575		− data.dmesg[phase]['color'], name, id)
3576		− devtl.html['legend'] += '</div>\n'
3577		−
3578		− hf = open(sysvals.htmlfile, 'w')
3579		−
3580		− if not sysvals.cgexp:
3581		− cgchk = 'checked'
3582		− cgnchk = 'not(:checked)'
3583		− else:
3584		− cgchk = 'not(:checked)'
3585		− cgnchk = 'checked'
3586		−
3587		− # write the html header first (html head, css code, up to body start)
3588		− html_header = '<!DOCTYPE html>\n<html>\n<head>\n\
3589		− <meta http-equiv="content-type" content="text/html; charset=UTF-8">\n\
3590		− <title>'+htmlTitle()+'</title>\n\
3591		− <style type=\'text/css\'>\n\
3592		− body {overflow-y:scroll;}\n\
3593		− .stamp {width:100%;text-align:center;background-color:gray;line-height:30px;color:white;font:25px Arial;}\n\
3594		− .callgraph {margin-top:30px;box-shadow:5px 5px 20px black;}\n\
3595		− .callgraph article * {padding-left:28px;}\n\
3596		− h1 {color:black;font:bold 30px Times;}\n\
3597		− t0 {color:black;font:bold 30px Times;}\n\
3598		− t1 {color:black;font:30px Times;}\n\
3599		− t2 {color:black;font:25px Times;}\n\
3600		− t3 {color:black;font:20px Times;white-space:nowrap;}\n\
3601		− t4 {color:black;font:bold 30px Times;line-height:60px;white-space:nowrap;}\n\
3602		− cS {font:bold 13px Times;}\n\
3603		− table {width:100%;}\n\
3604		− .gray {background-color:rgba(80,80,80,0.1);}\n\
3605		− .green {background-color:rgba(204,255,204,0.4);}\n\
3606		− .purple {background-color:rgba(128,0,128,0.2);}\n\
3607		− .yellow {background-color:rgba(255,255,204,0.4);}\n\
3608		− .time1 {font:22px Arial;border:1px solid;}\n\
3609		− .time2 {font:15px Arial;border-bottom:1px solid;border-left:1px solid;border-right:1px solid;}\n\
3610		− td {text-align:center;}\n\
3611		− r {color:#500000;font:15px Tahoma;}\n\
3612		− n {color:#505050;font:15px Tahoma;}\n\
3613		− .tdhl {color:red;}\n\
3614		− .hide {display:none;}\n\
3615		− .pf {display:none;}\n\
3616		− .pf:'+cgchk+' + label {background:url(\'data:image/svg+xml;utf,<?xml version="1.0" standalone="no"?><svg xmlns="http://www.w3.org/2000/svg" height="18" width="18" version="1.1"><circle cx="9" cy="9" r="8" stroke="black" stroke-width="1" fill="white"/><rect x="4" y="8" width="10" height="2" style="fill:black;stroke-width:0"/><rect x="8" y="4" width="2" height="10" style="fill:black;stroke-width:0"/></svg>\') no-repeat left center;}\n\
3617		− .pf:'+cgnchk+' ~ label {background:url(\'data:image/svg+xml;utf,<?xml version="1.0" standalone="no"?><svg xmlns="http://www.w3.org/2000/svg" height="18" width="18" version="1.1"><circle cx="9" cy="9" r="8" stroke="black" stroke-width="1" fill="white"/><rect x="4" y="8" width="10" height="2" style="fill:black;stroke-width:0"/></svg>\') no-repeat left center;}\n\
3618		− .pf:'+cgchk+' ~ *:not(:nth-child(2)) {display:none;}\n\
3619		− .zoombox {position:relative;width:100%;overflow-x:scroll;-webkit-user-select:none;-moz-user-select:none;user-select:none;}\n\
3620		− .timeline {position:relative;font-size:14px;cursor:pointer;width:100%; overflow:hidden;background:linear-gradient(#cccccc, white);}\n\
3621		− .thread {position:absolute;height:0%;overflow:hidden;z-index:7;line-height:30px;font-size:14px;border:1px solid;text-align:center;white-space:nowrap;}\n\
3622		− .thread.ps {border-radius:3px;background:linear-gradient(to top, #ccc, #eee);}\n\
3623		− .thread:hover {background-color:white;border:1px solid red;'+hoverZ+'}\n\
3624		− .thread.sec,.thread.sec:hover {background-color:black;border:0;color:white;line-height:15px;font-size:10px;}\n\
3625		− .hover {background-color:white;border:1px solid red;'+hoverZ+'}\n\
3626		− .hover.sync {background-color:white;}\n\
3627		− .hover.bg,.hover.kth,.hover.sync,.hover.ps {background-color:white;}\n\
3628		− .jiffie {position:absolute;pointer-events: none;z-index:8;}\n\
3629		− .traceevent {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\
3630		− .traceevent:hover {color:white;font-weight:bold;border:1px solid white;}\n\
3631		− .phase {position:absolute;overflow:hidden;border:0px;text-align:center;}\n\
3632		− .phaselet {position:absolute;overflow:hidden;border:0px;text-align:center;height:100px;font-size:24px;}\n\
3633		− .t {position:absolute;line-height:'+('%d'%scaleTH)+'px;pointer-events:none;top:0;height:100%;border-right:1px solid black;z-index:6;}\n\
3634		− .err {position:absolute;top:0%;height:100%;border-right:3px solid red;color:red;font:bold 14px Times;line-height:18px;}\n\
3635		− .legend {position:relative; width:100%; height:40px; text-align:center;margin-bottom:20px}\n\
3636		− .legend .square {position:absolute;cursor:pointer;top:10px; width:0px;height:20px;border:1px solid;padding-left:20px;}\n\
3637		− button {height:40px;width:200px;margin-bottom:20px;margin-top:20px;font-size:24px;}\n\
3638		− .logbtn {position:relative;float:right;height:25px;width:50px;margin-top:3px;margin-bottom:0;font-size:10px;text-align:center;}\n\
3639		− .devlist {position:'+x2changes[1]+';width:190px;}\n\
3640		− a:link {color:white;text-decoration:none;}\n\
3641		− a:visited {color:white;}\n\
3642		− a:hover {color:white;}\n\
3643		− a:active {color:white;}\n\
3644		− .version {position:relative;float:left;color:white;font-size:10px;line-height:30px;margin-left:10px;}\n\
3645		− #devicedetail {height:100px;box-shadow:5px 5px 20px black;}\n\
3646		− .tblock {position:absolute;height:100%;background-color:#ddd;}\n\
3647		− .tback {position:absolute;width:100%;background:linear-gradient(#ccc, #ddd);}\n\
3648		− .bg {z-index:1;}\n\
3649		− </style>\n</head>\n<body>\n'
3650		−
3651		− # no header or css if its embedded
3652		− if(sysvals.embedded):
3653		− hf.write('pass True tSus %.3f tRes %.3f tLow %.3f fwvalid %s tSus %.3f tRes %.3f\n' %
3654		− (data.tSuspended-data.start, data.end-data.tSuspended, data.tLow, data.fwValid, \
3655		− data.fwSuspend/1000000, data.fwResume/1000000))
3656		− else:
3657		− hf.write(html_header)
3658		−
3659		− # write the test title and general info header
3660		− if(sysvals.stamp['time'] != ""):
3661		− hf.write(headline_version)
3662		− if sysvals.logmsg:
3663		− hf.write('<button id="showtest" class="logbtn">log</button>')
3664		− if sysvals.addlogs and sysvals.dmesgfile:
3665		− hf.write('<button id="showdmesg" class="logbtn">dmesg</button>')
3666		− if sysvals.addlogs and sysvals.ftracefile:
3667		− hf.write('<button id="showftrace" class="logbtn">ftrace</button>')
3668		− hf.write(headline_stamp.format(sysvals.stamp['host'],
3669		− sysvals.stamp['kernel'], sysvals.stamp['mode'], \
3670		− sysvals.stamp['time']))
3671		−
3672		− # write the device timeline
3673		− hf.write(devtl.html['header'])
3674		− hf.write(devtl.html['timeline'])
3675		− hf.write(devtl.html['legend'])
3676		− hf.write('<div id="devicedetailtitle"></div>\n')
3677		− hf.write('<div id="devicedetail" style="display:none;">\n')
3678		− # draw the colored boxes for the device detail section
3679		− for data in testruns:
3680		− hf.write('<div id="devicedetail%d">\n' % data.testnumber)
3681		− pscolor = 'linear-gradient(to top left, #ccc, #eee)'
3682		− hf.write(html_phaselet.format('pre_suspend_process', \
3683		− '0', '0', pscolor))
3684		− for b in data.phases:
3685		− phase = data.dmesg[b]
3686		− length = phase['end']-phase['start']
3687		− left = '%.3f' % (((phase['start']-t0)*100.0)/tTotal)
3688		− width = '%.3f' % ((length*100.0)/tTotal)
3689		− hf.write(html_phaselet.format(b, left, width, \
3690		− data.dmesg[b]['color']))
3691		− hf.write(html_phaselet.format('post_resume_process', \
3692		− '0', '0', pscolor))
3693		− if sysvals.suspendmode == 'command':
3694		− hf.write(html_phaselet.format('cmdexec', '0', '0', pscolor))
3695		− hf.write('</div>\n')
3696		− hf.write('</div>\n')
3697		−
3698		− # write the ftrace data (callgraph)
3699		− if sysvals.cgtest >= 0 and len(testruns) > sysvals.cgtest:
3700		− data = testruns[sysvals.cgtest]
3701		− else:
3702		− data = testruns[-1]
3703		− if(sysvals.usecallgraph and not sysvals.embedded):
3704		− hf.write('<section id="callgraphs" class="callgraph">\n')
3705		− # write out the ftrace data converted to html
3706		− html_func_top = '<article id="{0}" class="atop" style="background-color:{1}">\n<input type="checkbox" class="pf" id="f{2}" checked/><label for="f{2}">{3} {4}</label>\n'
3707		− html_func_start = '<article>\n<input type="checkbox" class="pf" id="f{0}" checked/><label for="f{0}">{1} {2}</label>\n'
3708		− html_func_end = '</article>\n'
3709		− html_func_leaf = '<article>{0} {1}</article>\n'
3710		− num = 0
3711		− for p in data.phases:
3712		− if sysvals.cgphase and p != sysvals.cgphase:
3713		− continue
3714		− list = data.dmesg[p]['list']
3715		− for devname in data.sortedDevices(p):
3716		− if('ftrace' not in list[devname]):
3717		− continue
3718		− devid = list[devname]['id']
3719		− cg = list[devname]['ftrace']
3720		− clen = (cg.end - cg.start) * 1000
3721		− if clen < sysvals.mincglen:
3722		− continue
3723		− fmt = '<r>(%.3f ms @ '+sysvals.timeformat+' to '+sysvals.timeformat+')</r>'
3724		− flen = fmt % (clen, cg.start, cg.end)
3725		− name = devname
3726		− if(devname in sysvals.devprops):
3727		− name = sysvals.devprops[devname].altName(devname)
3728		− if sysvals.suspendmode == 'command':
3729		− ftitle = name
3730		− else:
3731		− ftitle = name+' '+p
3732		− hf.write(html_func_top.format(devid, data.dmesg[p]['color'], \
3733		− num, ftitle, flen))
3734		− num += 1
3735		− for line in cg.list:
3736		− if(line.length < 0.000000001):
3737		− flen = ''
3738		− else:
3739		− fmt = '<n>(%.3f ms @ '+sysvals.timeformat+')</n>'
3740		− flen = fmt % (line.length*1000, line.time)
3741		− if(line.freturn and line.fcall):
3742		− hf.write(html_func_leaf.format(line.name, flen))
3743		− elif(line.freturn):
3744		− hf.write(html_func_end)
3745		− else:
3746		− hf.write(html_func_start.format(num, line.name, flen))
3747		− num += 1
3748		− hf.write(html_func_end)
3749		− hf.write('\n\n </section>\n')
3750		−
3751		− # add the test log as a hidden div
3752		− if sysvals.logmsg:
3753		− hf.write('<div id="testlog" style="display:none;">\n'+sysvals.logmsg+'</div>\n')
3754		− # add the dmesg log as a hidden div
3755		− if sysvals.addlogs and sysvals.dmesgfile:
3756		− hf.write('<div id="dmesglog" style="display:none;">\n')
3757		− lf = open(sysvals.dmesgfile, 'r')
3758		− for line in lf:
3759		− line = line.replace('<', '&lt').replace('>', '&gt')
3760		− hf.write(line)
3761		− lf.close()
3762		− hf.write('</div>\n')
3763		− # add the ftrace log as a hidden div
3764		− if sysvals.addlogs and sysvals.ftracefile:
3765		− hf.write('<div id="ftracelog" style="display:none;">\n')
3766		− lf = open(sysvals.ftracefile, 'r')
3767		− for line in lf:
3768		− hf.write(line)
3769		− lf.close()
3770		− hf.write('</div>\n')
3771		−
3772		− if(not sysvals.embedded):
3773		− # write the footer and close
3774		− addScriptCode(hf, testruns)
3775		− hf.write('</body>\n</html>\n')
3776		− else:
3777		− # embedded out will be loaded in a page, skip the js
3778		− t0 = (testruns[0].start - testruns[-1].tSuspended) * 1000
3779		− tMax = (testruns[-1].end - testruns[-1].tSuspended) * 1000
3780		− # add js code in a div entry for later evaluation
3781		− detail = 'var bounds = [%f,%f];\n' % (t0, tMax)
3782		− detail += 'var devtable = [\n'
3783		− for data in testruns:
3784		− topo = data.deviceTopology()
3785		− detail += '\t"%s",\n' % (topo)
3786		− detail += '];\n'
3787		− hf.write('<div id=customcode style=display:none>\n'+detail+'</div>\n')
3788		− hf.close()
3789		− return True
3790		−
3791		−# Function: addScriptCode
3792		−# Description:
3793		−# Adds the javascript code to the output html
3794		−# Arguments:
3795		−# hf: the open html file pointer
3796		−# testruns: array of Data objects from parseKernelLog or parseTraceLog
3797		−def addScriptCode(hf, testruns):
3798		− t0 = testruns[0].start * 1000
3799		− tMax = testruns[-1].end * 1000
3800		− # create an array in javascript memory with the device details
3801		− detail = ' var devtable = [];\n'
3802		− for data in testruns:
3803		− topo = data.deviceTopology()
3804		− detail += ' devtable[%d] = "%s";\n' % (data.testnumber, topo)
3805		− detail += ' var bounds = [%f,%f];\n' % (t0, tMax)
3806		− # add the code which will manipulate the data in the browser
3807		− script_code = \
3808		− '<script type="text/javascript">\n'+detail+\
3809		− ' var resolution = -1;\n'\
3810		− ' var dragval = [0, 0];\n'\
3811		− ' function redrawTimescale(t0, tMax, tS) {\n'\
3812		− ' var rline = \'<div class="t" style="left:0;border-left:1px solid black;border-right:0;"><cS>←R</cS></div>\';\n'\
3813		− ' var tTotal = tMax - t0;\n'\
3814		− ' var list = document.getElementsByClassName("tblock");\n'\
3815		− ' for (var i = 0; i < list.length; i++) {\n'\
3816		− ' var timescale = list[i].getElementsByClassName("timescale")[0];\n'\
3817		− ' var m0 = t0 + (tTotal*parseFloat(list[i].style.left)/100);\n'\
3818		− ' var mTotal = tTotal*parseFloat(list[i].style.width)/100;\n'\
3819		− ' var mMax = m0 + mTotal;\n'\
3820		− ' var html = "";\n'\
3821		− ' var divTotal = Math.floor(mTotal/tS) + 1;\n'\
3822		− ' if(divTotal > 1000) continue;\n'\
3823		− ' var divEdge = (mTotal - tS(divTotal-1))100/mTotal;\n'\
3824		− ' var pos = 0.0, val = 0.0;\n'\
3825		− ' for (var j = 0; j < divTotal; j++) {\n'\
3826		− ' var htmlline = "";\n'\
3827		− ' if(list[i].id[5] == "r") {\n'\
3828		− ' pos = 100 - (((j)tS100)/mTotal);\n'\
3829		− ' val = (j)*tS;\n'\
3830		− ' htmlline = \'<div class="t" style="right:\'+pos+\'%">\'+val+\'ms</div>\';\n'\
3831		− ' if(j == 0)\n'\
3832		− ' htmlline = rline;\n'\
3833		− ' } else {\n'\
3834		− ' pos = 100 - (((j)tS100)/mTotal) - divEdge;\n'\
3835		− ' val = (j-divTotal+1)*tS;\n'\
3836		− ' if(j == divTotal - 1)\n'\
3837		− ' htmlline = \'<div class="t" style="right:\'+pos+\'%"><cS>S→</cS></div>\';\n'\
3838		− ' else\n'\
3839		− ' htmlline = \'<div class="t" style="right:\'+pos+\'%">\'+val+\'ms</div>\';\n'\
3840		− ' }\n'\
3841		− ' html += htmlline;\n'\
3842		− ' }\n'\
3843		− ' timescale.innerHTML = html;\n'\
3844		− ' }\n'\
3845		− ' }\n'\
3846		− ' function zoomTimeline() {\n'\
3847		− ' var dmesg = document.getElementById("dmesg");\n'\
3848		− ' var zoombox = document.getElementById("dmesgzoombox");\n'\
3849		− ' var left = zoombox.scrollLeft;\n'\
3850		− ' var val = parseFloat(dmesg.style.width);\n'\
3851		− ' var newval = 100;\n'\
3852		− ' var sh = window.outerWidth / 2;\n'\
3853		− ' if(this.id == "zoomin") {\n'\
3854		− ' newval = val * 1.2;\n'\
3855		− ' if(newval > 910034) newval = 910034;\n'\
3856		− ' dmesg.style.width = newval+"%";\n'\
3857		− ' zoombox.scrollLeft = ((left + sh) * newval / val) - sh;\n'\
3858		− ' } else if (this.id == "zoomout") {\n'\
3859		− ' newval = val / 1.2;\n'\
3860		− ' if(newval < 100) newval = 100;\n'\
3861		− ' dmesg.style.width = newval+"%";\n'\
3862		− ' zoombox.scrollLeft = ((left + sh) * newval / val) - sh;\n'\
3863		− ' } else {\n'\
3864		− ' zoombox.scrollLeft = 0;\n'\
3865		− ' dmesg.style.width = "100%";\n'\
3866		− ' }\n'\
3867		− ' var tS = [10000, 5000, 2000, 1000, 500, 200, 100, 50, 20, 10, 5, 2, 1];\n'\
3868		− ' var t0 = bounds[0];\n'\
3869		− ' var tMax = bounds[1];\n'\
3870		− ' var tTotal = tMax - t0;\n'\
3871		− ' var wTotal = tTotal * 100.0 / newval;\n'\
3872		− ' var idx = 7*window.innerWidth/1100;\n'\
3873		− ' for(var i = 0; (i < tS.length)&&((wTotal / tS[i]) < idx); i++);\n'\
3874		− ' if(i >= tS.length) i = tS.length - 1;\n'\
3875		− ' if(tS[i] == resolution) return;\n'\
3876		− ' resolution = tS[i];\n'\
3877		− ' redrawTimescale(t0, tMax, tS[i]);\n'\
3878		− ' }\n'\
3879		− ' function deviceName(title) {\n'\
3880		− ' var name = title.slice(0, title.indexOf(" ("));\n'\
3881		− ' return name;\n'\
3882		− ' }\n'\
3883		− ' function deviceHover() {\n'\
3884		− ' var name = deviceName(this.title);\n'\
3885		− ' var dmesg = document.getElementById("dmesg");\n'\
3886		− ' var dev = dmesg.getElementsByClassName("thread");\n'\
3887		− ' var cpu = -1;\n'\
3888		− ' if(name.match("CPU_ON\[[0-9]*\]"))\n'\
3889		− ' cpu = parseInt(name.slice(7));\n'\
3890		− ' else if(name.match("CPU_OFF\[[0-9]*\]"))\n'\
3891		− ' cpu = parseInt(name.slice(8));\n'\
3892		− ' for (var i = 0; i < dev.length; i++) {\n'\
3893		− ' dname = deviceName(dev[i].title);\n'\
3894		− ' var cname = dev[i].className.slice(dev[i].className.indexOf("thread"));\n'\
3895		− ' if((cpu >= 0 && dname.match("CPU_O[NF]\\\["+cpu+"\\\]")) \|\|\n'\
3896		− ' (name == dname))\n'\
3897		− ' {\n'\
3898		− ' dev[i].className = "hover "+cname;\n'\
3899		− ' } else {\n'\
3900		− ' dev[i].className = cname;\n'\
3901		− ' }\n'\
3902		− ' }\n'\
3903		− ' }\n'\
3904		− ' function deviceUnhover() {\n'\
3905		− ' var dmesg = document.getElementById("dmesg");\n'\
3906		− ' var dev = dmesg.getElementsByClassName("thread");\n'\
3907		− ' for (var i = 0; i < dev.length; i++) {\n'\
3908		− ' dev[i].className = dev[i].className.slice(dev[i].className.indexOf("thread"));\n'\
3909		− ' }\n'\
3910		− ' }\n'\
3911		− ' function deviceTitle(title, total, cpu) {\n'\
3912		− ' var prefix = "Total";\n'\
3913		− ' if(total.length > 3) {\n'\
3914		− ' prefix = "Average";\n'\
3915		− ' total[1] = (total[1]+total[3])/2;\n'\
3916		− ' total[2] = (total[2]+total[4])/2;\n'\
3917		− ' }\n'\
3918		− ' var devtitle = document.getElementById("devicedetailtitle");\n'\
3919		− ' var name = deviceName(title);\n'\
3920		− ' if(cpu >= 0) name = "CPU"+cpu;\n'\
3921		− ' var driver = "";\n'\
3922		− ' var tS = "<t2>(</t2>";\n'\
3923		− ' var tR = "<t2>)</t2>";\n'\
3924		− ' if(total[1] > 0)\n'\
3925		− ' tS = "<t2>("+prefix+" Suspend:</t2><t0> "+total[1].toFixed(3)+" ms</t0> ";\n'\
3926		− ' if(total[2] > 0)\n'\
3927		− ' tR = " <t2>"+prefix+" Resume:</t2><t0> "+total[2].toFixed(3)+" ms<t2>)</t2></t0>";\n'\
3928		− ' var s = title.indexOf("{");\n'\
3929		− ' var e = title.indexOf("}");\n'\
3930		− ' if((s >= 0) && (e >= 0))\n'\
3931		− ' driver = title.slice(s+1, e) + " <t1>@</t1> ";\n'\
3932		− ' if(total[1] > 0 && total[2] > 0)\n'\
3933		− ' devtitle.innerHTML = "<t0>"+driver+name+"</t0> "+tS+tR;\n'\
3934		− ' else\n'\
3935		− ' devtitle.innerHTML = "<t0>"+title+"</t0>";\n'\
3936		− ' return name;\n'\
3937		− ' }\n'\
3938		− ' function deviceDetail() {\n'\
3939		− ' var devinfo = document.getElementById("devicedetail");\n'\
3940		− ' devinfo.style.display = "block";\n'\
3941		− ' var name = deviceName(this.title);\n'\
3942		− ' var cpu = -1;\n'\
3943		− ' if(name.match("CPU_ON\[[0-9]*\]"))\n'\
3944		− ' cpu = parseInt(name.slice(7));\n'\
3945		− ' else if(name.match("CPU_OFF\[[0-9]*\]"))\n'\
3946		− ' cpu = parseInt(name.slice(8));\n'\
3947		− ' var dmesg = document.getElementById("dmesg");\n'\
3948		− ' var dev = dmesg.getElementsByClassName("thread");\n'\
3949		− ' var idlist = [];\n'\
3950		− ' var pdata = [[]];\n'\
3951		− ' if(document.getElementById("devicedetail1"))\n'\
3952		− ' pdata = [[], []];\n'\
3953		− ' var pd = pdata[0];\n'\
3954		− ' var total = [0.0, 0.0, 0.0];\n'\
3955		− ' for (var i = 0; i < dev.length; i++) {\n'\
3956		− ' dname = deviceName(dev[i].title);\n'\
3957		− ' if((cpu >= 0 && dname.match("CPU_O[NF]\\\["+cpu+"\\\]")) \|\|\n'\
3958		− ' (name == dname))\n'\
3959		− ' {\n'\
3960		− ' idlist[idlist.length] = dev[i].id;\n'\
3961		− ' var tidx = 1;\n'\
3962		− ' if(dev[i].id[0] == "a") {\n'\
3963		− ' pd = pdata[0];\n'\
3964		− ' } else {\n'\
3965		− ' if(pdata.length == 1) pdata[1] = [];\n'\
3966		− ' if(total.length == 3) total[3]=total[4]=0.0;\n'\
3967		− ' pd = pdata[1];\n'\
3968		− ' tidx = 3;\n'\
3969		− ' }\n'\
3970		− ' var info = dev[i].title.split(" ");\n'\
3971		− ' var pname = info[info.length-1];\n'\
3972		− ' pd[pname] = parseFloat(info[info.length-3].slice(1));\n'\
3973		− ' total[0] += pd[pname];\n'\
3974		− ' if(pname.indexOf("suspend") >= 0)\n'\
3975		− ' total[tidx] += pd[pname];\n'\
3976		− ' else\n'\
3977		− ' total[tidx+1] += pd[pname];\n'\
3978		− ' }\n'\
3979		− ' }\n'\
3980		− ' var devname = deviceTitle(this.title, total, cpu);\n'\
3981		− ' var left = 0.0;\n'\
3982		− ' for (var t = 0; t < pdata.length; t++) {\n'\
3983		− ' pd = pdata[t];\n'\
3984		− ' devinfo = document.getElementById("devicedetail"+t);\n'\
3985		− ' var phases = devinfo.getElementsByClassName("phaselet");\n'\
3986		− ' for (var i = 0; i < phases.length; i++) {\n'\
3987		− ' if(phases[i].id in pd) {\n'\
3988		− ' var w = 100.0*pd[phases[i].id]/total[0];\n'\
3989		− ' var fs = 32;\n'\
3990		− ' if(w < 8) fs = 4*w \| 0;\n'\
3991		− ' var fs2 = fs*3/4;\n'\
3992		− ' phases[i].style.width = w+"%";\n'\
3993		− ' phases[i].style.left = left+"%";\n'\
3994		− ' phases[i].title = phases[i].id+" "+pd[phases[i].id]+" ms";\n'\
3995		− ' left += w;\n'\
3996		− ' var time = "<t4 style=\\"font-size:"+fs+"px\\">"+pd[phases[i].id]+" ms<br></t4>";\n'\
3997		− ' var pname = "<t3 style=\\"font-size:"+fs2+"px\\">"+phases[i].id.replace(new RegExp("_", "g"), " ")+"</t3>";\n'\
3998		− ' phases[i].innerHTML = time+pname;\n'\
3999		− ' } else {\n'\
4000		− ' phases[i].style.width = "0%";\n'\
4001		− ' phases[i].style.left = left+"%";\n'\
4002		− ' }\n'\
4003		− ' }\n'\
4004		− ' }\n'\
4005		− ' var cglist = document.getElementById("callgraphs");\n'\
4006		− ' if(!cglist) return;\n'\
4007		− ' var cg = cglist.getElementsByClassName("atop");\n'\
4008		− ' if(cg.length < 10) return;\n'\
4009		− ' for (var i = 0; i < cg.length; i++) {\n'\
4010		− ' if(idlist.indexOf(cg[i].id) >= 0) {\n'\
4011		− ' cg[i].style.display = "block";\n'\
4012		− ' } else {\n'\
4013		− ' cg[i].style.display = "none";\n'\
4014		− ' }\n'\
4015		− ' }\n'\
4016		− ' }\n'\
4017		− ' function devListWindow(e) {\n'\
4018		− ' var win = window.open();\n'\
4019		− ' var html = "<title>"+e.target.innerHTML+"</title>"+\n'\
4020		− ' "<style type=\\"text/css\\">"+\n'\
4021		− ' " ul {list-style-type:circle;padding-left:10px;margin-left:10px;}"+\n'\
4022		− ' "</style>"\n'\
4023		− ' var dt = devtable[0];\n'\
4024		− ' if(e.target.id != "devlist1")\n'\
4025		− ' dt = devtable[1];\n'\
4026		− ' win.document.write(html+dt);\n'\
4027		− ' }\n'\
4028		− ' function errWindow() {\n'\
4029		− ' var text = this.id;\n'\
4030		− ' var win = window.open();\n'\
4031		− ' win.document.write("<pre>"+text+"</pre>");\n'\
4032		− ' win.document.close();\n'\
4033		− ' }\n'\
4034		− ' function logWindow(e) {\n'\
4035		− ' var name = e.target.id.slice(4);\n'\
4036		− ' var win = window.open();\n'\
4037		− ' var log = document.getElementById(name+"log");\n'\
4038		− ' var title = "<title>"+document.title.split(" ")[0]+" "+name+" log</title>";\n'\
4039		− ' win.document.write(title+"<pre>"+log.innerHTML+"</pre>");\n'\
4040		− ' win.document.close();\n'\
4041		− ' }\n'\
4042		− ' function onClickPhase(e) {\n'\
4043		− ' }\n'\
4044		− ' function onMouseDown(e) {\n'\
4045		− ' dragval[0] = e.clientX;\n'\
4046		− ' dragval[1] = document.getElementById("dmesgzoombox").scrollLeft;\n'\
4047		− ' document.onmousemove = onMouseMove;\n'\
4048		− ' }\n'\
4049		− ' function onMouseMove(e) {\n'\
4050		− ' var zoombox = document.getElementById("dmesgzoombox");\n'\
4051		− ' zoombox.scrollLeft = dragval[1] + dragval[0] - e.clientX;\n'\
4052		− ' }\n'\
4053		− ' function onMouseUp(e) {\n'\
4054		− ' document.onmousemove = null;\n'\
4055		− ' }\n'\
4056		− ' function onKeyPress(e) {\n'\
4057		− ' var c = e.charCode;\n'\
4058		− ' if(c != 42 && c != 43 && c != 45) return;\n'\
4059		− ' var click = document.createEvent("Events");\n'\
4060		− ' click.initEvent("click", true, false);\n'\
4061		− ' if(c == 43) \n'\
4062		− ' document.getElementById("zoomin").dispatchEvent(click);\n'\
4063		− ' else if(c == 45)\n'\
4064		− ' document.getElementById("zoomout").dispatchEvent(click);\n'\
4065		− ' else if(c == 42)\n'\
4066		− ' document.getElementById("zoomdef").dispatchEvent(click);\n'\
4067		− ' }\n'\
4068		− ' window.addEventListener("resize", function () {zoomTimeline();});\n'\
4069		− ' window.addEventListener("load", function () {\n'\
4070		− ' var dmesg = document.getElementById("dmesg");\n'\
4071		− ' dmesg.style.width = "100%"\n'\
4072		− ' dmesg.onmousedown = onMouseDown;\n'\
4073		− ' document.onmouseup = onMouseUp;\n'\
4074		− ' document.onkeypress = onKeyPress;\n'\
4075		− ' document.getElementById("zoomin").onclick = zoomTimeline;\n'\
4076		− ' document.getElementById("zoomout").onclick = zoomTimeline;\n'\
4077		− ' document.getElementById("zoomdef").onclick = zoomTimeline;\n'\
4078		− ' var list = document.getElementsByClassName("square");\n'\
4079		− ' for (var i = 0; i < list.length; i++)\n'\
4080		− ' list[i].onclick = onClickPhase;\n'\
4081		− ' var list = document.getElementsByClassName("err");\n'\
4082		− ' for (var i = 0; i < list.length; i++)\n'\
4083		− ' list[i].onclick = errWindow;\n'\
4084		− ' var list = document.getElementsByClassName("logbtn");\n'\
4085		− ' for (var i = 0; i < list.length; i++)\n'\
4086		− ' list[i].onclick = logWindow;\n'\
4087		− ' list = document.getElementsByClassName("devlist");\n'\
4088		− ' for (var i = 0; i < list.length; i++)\n'\
4089		− ' list[i].onclick = devListWindow;\n'\
4090		− ' var dev = dmesg.getElementsByClassName("thread");\n'\
4091		− ' for (var i = 0; i < dev.length; i++) {\n'\
4092		− ' dev[i].onclick = deviceDetail;\n'\
4093		− ' dev[i].onmouseover = deviceHover;\n'\
4094		− ' dev[i].onmouseout = deviceUnhover;\n'\
4095		− ' }\n'\
4096		− ' zoomTimeline();\n'\
4097		− ' });\n'\
4098		− '</script>\n'
4099		− hf.write(script_code);
4100		−
4101		−# Function: executeSuspend
4102		−# Description:
4103		−# Execute system suspend through the sysfs interface, then copy the output
4104		−# dmesg and ftrace files to the test output directory.
4105		−def executeSuspend():
4106		− pm = ProcessMonitor()
4107		− tp = sysvals.tpath
4108		− fwdata = []
4109		− # mark the start point in the kernel ring buffer just as we start
4110		− sysvals.initdmesg()
4111		− # start ftrace
4112		− if(sysvals.usecallgraph or sysvals.usetraceevents):
4113		− print('START TRACING')
4114		− sysvals.fsetVal('1', 'tracing_on')
4115		− if sysvals.useprocmon:
4116		− pm.start()
4117		− # execute however many s/r runs requested
4118		− for count in range(1,sysvals.execcount+1):
4119		− # x2delay in between test runs
4120		− if(count > 1 and sysvals.x2delay > 0):
4121		− sysvals.fsetVal('WAIT %d' % sysvals.x2delay, 'trace_marker')
4122		− time.sleep(sysvals.x2delay/1000.0)
4123		− sysvals.fsetVal('WAIT END', 'trace_marker')
4124		− # start message
4125		− if sysvals.testcommand != '':
4126		− print('COMMAND START')
4127		− else:
4128		− if(sysvals.rtcwake):
4129		− print('SUSPEND START')
4130		− else:
4131		− print('SUSPEND START (press a key to resume)')
4132		− # set rtcwake
4133		− if(sysvals.rtcwake):
4134		− print('will issue an rtcwake in %d seconds' % sysvals.rtcwaketime)
4135		− sysvals.rtcWakeAlarmOn()
4136		− # start of suspend trace marker
4137		− if(sysvals.usecallgraph or sysvals.usetraceevents):
4138		− sysvals.fsetVal('SUSPEND START', 'trace_marker')
4139		− # predelay delay
4140		− if(count == 1 and sysvals.predelay > 0):
4141		− sysvals.fsetVal('WAIT %d' % sysvals.predelay, 'trace_marker')
4142		− time.sleep(sysvals.predelay/1000.0)
4143		− sysvals.fsetVal('WAIT END', 'trace_marker')
4144		− # initiate suspend or command
4145		− if sysvals.testcommand != '':
4146		− call(sysvals.testcommand+' 2>&1', shell=True);
4147		− else:
4148		− pf = open(sysvals.powerfile, 'w')
4149		− pf.write(sysvals.suspendmode)
4150		− # execution will pause here
4151		− try:
4152		− pf.close()
4153		− except:
4154		− pass
4155		− if(sysvals.rtcwake):
4156		− sysvals.rtcWakeAlarmOff()
4157		− # postdelay delay
4158		− if(count == sysvals.execcount and sysvals.postdelay > 0):
4159		− sysvals.fsetVal('WAIT %d' % sysvals.postdelay, 'trace_marker')
4160		− time.sleep(sysvals.postdelay/1000.0)
4161		− sysvals.fsetVal('WAIT END', 'trace_marker')
4162		− # return from suspend
4163		− print('RESUME COMPLETE')
4164		− if(sysvals.usecallgraph or sysvals.usetraceevents):
4165		− sysvals.fsetVal('RESUME COMPLETE', 'trace_marker')
4166		− if(sysvals.suspendmode == 'mem' or sysvals.suspendmode == 'command'):
4167		− fwdata.append(getFPDT(False))
4168		− # stop ftrace
4169		− if(sysvals.usecallgraph or sysvals.usetraceevents):
4170		− if sysvals.useprocmon:
4171		− pm.stop()
4172		− sysvals.fsetVal('0', 'tracing_on')
4173		− print('CAPTURING TRACE')
4174		− writeDatafileHeader(sysvals.ftracefile, fwdata)
4175		− call('cat '+tp+'trace >> '+sysvals.ftracefile, shell=True)
4176		− sysvals.fsetVal('', 'trace')
4177		− devProps()
4178		− # grab a copy of the dmesg output
4179		− print('CAPTURING DMESG')
4180		− writeDatafileHeader(sysvals.dmesgfile, fwdata)
4181		− sysvals.getdmesg()
4182		−
4183		−def writeDatafileHeader(filename, fwdata):
4184		− fp = open(filename, 'a')
4185		− fp.write(sysvals.teststamp+'\n')
4186		− if(sysvals.suspendmode == 'mem' or sysvals.suspendmode == 'command'):
4187		− for fw in fwdata:
4188		− if(fw):
4189		− fp.write('# fwsuspend %u fwresume %u\n' % (fw[0], fw[1]))
4190		− fp.close()
4191		−
4192		−# Function: setUSBDevicesAuto
4193		−# Description:
4194		−# Set the autosuspend control parameter of all USB devices to auto
4195		−# This can be dangerous, so use at your own risk, most devices are set
4196		−# to always-on since the kernel cant determine if the device can
4197		−# properly autosuspend
4198		−def setUSBDevicesAuto():
4199		− rootCheck(True)
4200		− for dirname, dirnames, filenames in os.walk('/sys/devices'):
4201		− if(re.match('./usb[0-9].*', dirname) and
4202		− 'idVendor' in filenames and 'idProduct' in filenames):
4203		− call('echo auto > %s/power/control' % dirname, shell=True)
4204		− name = dirname.split('/')[-1]
4205		− desc = Popen(['cat', '%s/product' % dirname],
4206		− stderr=PIPE, stdout=PIPE).stdout.read().replace('\n', '')
4207		− ctrl = Popen(['cat', '%s/power/control' % dirname],
4208		− stderr=PIPE, stdout=PIPE).stdout.read().replace('\n', '')
4209		− print('control is %s for %6s: %s' % (ctrl, name, desc))
4210		−
4211		−# Function: yesno
4212		−# Description:
4213		−# Print out an equivalent Y or N for a set of known parameter values
4214		−# Output:
4215		−# 'Y', 'N', or ' ' if the value is unknown
4216		−def yesno(val):
4217		− yesvals = ['auto', 'enabled', 'active', '1']
4218		− novals = ['on', 'disabled', 'suspended', 'forbidden', 'unsupported']
4219		− if val in yesvals:
4220		− return 'Y'
4221		− elif val in novals:
4222		− return 'N'
4223		− return ' '
4224		−
4225		−# Function: ms2nice
4226		−# Description:
4227		−# Print out a very concise time string in minutes and seconds
4228		−# Output:
4229		−# The time string, e.g. "1901m16s"
4230		−def ms2nice(val):
4231		− ms = 0
4232		− try:
4233		− ms = int(val)
4234		− except:
4235		− return 0.0
4236		− m = ms / 60000
4237		− s = (ms / 1000) - (m * 60)
4238		− return '%3dm%2ds' % (m, s)
4239		−
4240		−# Function: detectUSB
4241		−# Description:
4242		−# Detect all the USB hosts and devices currently connected and add
4243		−# a list of USB device names to sysvals for better timeline readability
4244		−def detectUSB():
4245		− field = {'idVendor':'', 'idProduct':'', 'product':'', 'speed':''}
4246		− power = {'async':'', 'autosuspend':'', 'autosuspend_delay_ms':'',
4247		− 'control':'', 'persist':'', 'runtime_enabled':'',
4248		− 'runtime_status':'', 'runtime_usage':'',
4249		− 'runtime_active_time':'',
4250		− 'runtime_suspended_time':'',
4251		− 'active_duration':'',
4252		− 'connected_duration':''}
4253		−
4254		− print('LEGEND')
4255		− print('---------------------------------------------------------------------------------------------')
4256		− print(' A = async/sync PM queue Y/N D = autosuspend delay (seconds)')
4257		− print(' S = autosuspend Y/N rACTIVE = runtime active (min/sec)')
4258		− print(' P = persist across suspend Y/N rSUSPEN = runtime suspend (min/sec)')
4259		− print(' E = runtime suspend enabled/forbidden Y/N ACTIVE = active duration (min/sec)')
4260		− print(' R = runtime status active/suspended Y/N CONNECT = connected duration (min/sec)')
4261		− print(' U = runtime usage count')
4262		− print('---------------------------------------------------------------------------------------------')
4263		− print(' NAME ID DESCRIPTION SPEED A S P E R U D rACTIVE rSUSPEN ACTIVE CONNECT')
4264		− print('---------------------------------------------------------------------------------------------')
4265		−
4266		− for dirname, dirnames, filenames in os.walk('/sys/devices'):
4267		− if(re.match('./usb[0-9].*', dirname) and
4268		− 'idVendor' in filenames and 'idProduct' in filenames):
4269		− for i in field:
4270		− field[i] = Popen(['cat', '%s/%s' % (dirname, i)],
4271		− stderr=PIPE, stdout=PIPE).stdout.read().replace('\n', '')
4272		− name = dirname.split('/')[-1]
4273		− for i in power:
4274		− power[i] = Popen(['cat', '%s/power/%s' % (dirname, i)],
4275		− stderr=PIPE, stdout=PIPE).stdout.read().replace('\n', '')
4276		− if(re.match('usb[0-9]*', name)):
4277		− first = '%-8s' % name
4278		− else:
4279		− first = '%8s' % name
4280		− print('%s [%s:%s] %-20s %-4s %1s %1s %1s %1s %1s %1s %1s %s %s %s %s' % \
4281		− (first, field['idVendor'], field['idProduct'], \
4282		− field['product'][0:20], field['speed'], \
4283		− yesno(power['async']), \
4284		− yesno(power['control']), \
4285		− yesno(power['persist']), \
4286		− yesno(power['runtime_enabled']), \
4287		− yesno(power['runtime_status']), \
4288		− power['runtime_usage'], \
4289		− power['autosuspend'], \
4290		− ms2nice(power['runtime_active_time']), \
4291		− ms2nice(power['runtime_suspended_time']), \
4292		− ms2nice(power['active_duration']), \
4293		− ms2nice(power['connected_duration'])))
4294		−
4295		−# Function: devProps
4296		−# Description:
4297		−# Retrieve a list of properties for all devices in the trace log
4298		−def devProps(data=0):
4299		− props = dict()
4300		−
4301		− if data:
4302		− idx = data.index(': ') + 2
4303		− if idx >= len(data):
4304		− return
4305		− devlist = data[idx:].split(';')
4306		− for dev in devlist:
4307		− f = dev.split(',')
4308		− if len(f) < 3:
4309		− continue
4310		− dev = f[0]
4311		− props[dev] = DevProps()
4312		− props[dev].altname = f[1]
4313		− if int(f[2]):
4314		− props[dev].async = True
4315		− else:
4316		− props[dev].async = False
4317		− sysvals.devprops = props
4318		− if sysvals.suspendmode == 'command' and 'testcommandstring' in props:
4319		− sysvals.testcommand = props['testcommandstring'].altname
4320		− return
4321		−
4322		− if(os.path.exists(sysvals.ftracefile) == False):
4323		− doError('%s does not exist' % sysvals.ftracefile)
4324		−
4325		− # first get the list of devices we need properties for
4326		− msghead = 'Additional data added by AnalyzeSuspend'
4327		− alreadystamped = False
4328		− tp = TestProps()
4329		− tf = open(sysvals.ftracefile, 'r')
4330		− for line in tf:
4331		− if msghead in line:
4332		− alreadystamped = True
4333		− continue
4334		− # determine the trace data type (required for further parsing)
4335		− m = re.match(sysvals.tracertypefmt, line)
4336		− if(m):
4337		− tp.setTracerType(m.group('t'))
4338		− continue
4339		− # parse only valid lines, if this is not one move on
4340		− m = re.match(tp.ftrace_line_fmt, line)
4341		− if(not m or 'device_pm_callback_start' not in line):
4342		− continue
4343		− m = re.match('.: (?P<drv>.) (?P<d>.), parent: (?P<p>.), .', m.group('msg'));
4344		− if(not m):
4345		− continue
4346		− dev = m.group('d')
4347		− if dev not in props:
4348		− props[dev] = DevProps()
4349		− tf.close()
4350		−
4351		− if not alreadystamped and sysvals.suspendmode == 'command':
4352		− out = '#\n# '+msghead+'\n# Device Properties: '
4353		− out += 'testcommandstring,%s,0;' % (sysvals.testcommand)
4354		− with open(sysvals.ftracefile, 'a') as fp:
4355		− fp.write(out+'\n')
4356		− sysvals.devprops = props
4357		− return
4358		−
4359		− # now get the syspath for each of our target devices
4360		− for dirname, dirnames, filenames in os.walk('/sys/devices'):
4361		− if(re.match('.*/power', dirname) and 'async' in filenames):
4362		− dev = dirname.split('/')[-2]
4363		− if dev in props and (not props[dev].syspath or len(dirname) < len(props[dev].syspath)):
4364		− props[dev].syspath = dirname[:-6]
4365		−
4366		− # now fill in the properties for our target devices
4367		− for dev in props:
4368		− dirname = props[dev].syspath
4369		− if not dirname or not os.path.exists(dirname):
4370		− continue
4371		− with open(dirname+'/power/async') as fp:
4372		− text = fp.read()
4373		− props[dev].async = False
4374		− if 'enabled' in text:
4375		− props[dev].async = True
4376		− fields = os.listdir(dirname)
4377		− if 'product' in fields:
4378		− with open(dirname+'/product') as fp:
4379		− props[dev].altname = fp.read()
4380		− elif 'name' in fields:
4381		− with open(dirname+'/name') as fp:
4382		− props[dev].altname = fp.read()
4383		− elif 'model' in fields:
4384		− with open(dirname+'/model') as fp:
4385		− props[dev].altname = fp.read()
4386		− elif 'description' in fields:
4387		− with open(dirname+'/description') as fp:
4388		− props[dev].altname = fp.read()
4389		− elif 'id' in fields:
4390		− with open(dirname+'/id') as fp:
4391		− props[dev].altname = fp.read()
4392		− elif 'idVendor' in fields and 'idProduct' in fields:
4393		− idv, idp = '', ''
4394		− with open(dirname+'/idVendor') as fp:
4395		− idv = fp.read().strip()
4396		− with open(dirname+'/idProduct') as fp:
4397		− idp = fp.read().strip()
4398		− props[dev].altname = '%s:%s' % (idv, idp)
4399		−
4400		− if props[dev].altname:
4401		− out = props[dev].altname.strip().replace('\n', ' ')
4402		− out = out.replace(',', ' ')
4403		− out = out.replace(';', ' ')
4404		− props[dev].altname = out
4405		−
4406		− # and now write the data to the ftrace file
4407		− if not alreadystamped:
4408		− out = '#\n# '+msghead+'\n# Device Properties: '
4409		− for dev in sorted(props):
4410		− out += props[dev].out(dev)
4411		− with open(sysvals.ftracefile, 'a') as fp:
4412		− fp.write(out+'\n')
4413		−
4414		− sysvals.devprops = props
4415		−
4416		−# Function: getModes
4417		−# Description:
4418		−# Determine the supported power modes on this system
4419		−# Output:
4420		−# A string list of the available modes
4421		−def getModes():
4422		− modes = ''
4423		− if(os.path.exists(sysvals.powerfile)):
4424		− fp = open(sysvals.powerfile, 'r')
4425		− modes = string.split(fp.read())
4426		− fp.close()
4427		− return modes
4428		−
4429		−# Function: getFPDT
4430		−# Description:
4431		−# Read the acpi bios tables and pull out FPDT, the firmware data
4432		−# Arguments:
4433		−# output: True to output the info to stdout, False otherwise
4434		−def getFPDT(output):
4435		− rectype = {}
4436		− rectype[0] = 'Firmware Basic Boot Performance Record'
4437		− rectype[1] = 'S3 Performance Table Record'
4438		− prectype = {}
4439		− prectype[0] = 'Basic S3 Resume Performance Record'
4440		− prectype[1] = 'Basic S3 Suspend Performance Record'
4441		−
4442		− rootCheck(True)
4443		− if(not os.path.exists(sysvals.fpdtpath)):
4444		− if(output):
4445		− doError('file does not exist: %s' % sysvals.fpdtpath)
4446		− return False
4447		− if(not os.access(sysvals.fpdtpath, os.R_OK)):
4448		− if(output):
4449		− doError('file is not readable: %s' % sysvals.fpdtpath)
4450		− return False
4451		− if(not os.path.exists(sysvals.mempath)):
4452		− if(output):
4453		− doError('file does not exist: %s' % sysvals.mempath)
4454		− return False
4455		− if(not os.access(sysvals.mempath, os.R_OK)):
4456		− if(output):
4457		− doError('file is not readable: %s' % sysvals.mempath)
4458		− return False
4459		−
4460		− fp = open(sysvals.fpdtpath, 'rb')
4461		− buf = fp.read()
4462		− fp.close()
4463		−
4464		− if(len(buf) < 36):
4465		− if(output):
4466		− doError('Invalid FPDT table data, should '+\
4467		− 'be at least 36 bytes')
4468		− return False
4469		−
4470		− table = struct.unpack('4sIBB6s8sI4sI', buf[0:36])
4471		− if(output):
4472		− print('')
4473		− print('Firmware Performance Data Table (%s)' % table[0])
4474		− print(' Signature : %s' % table[0])
4475		− print(' Table Length : %u' % table[1])
4476		− print(' Revision : %u' % table[2])
4477		− print(' Checksum : 0x%x' % table[3])
4478		− print(' OEM ID : %s' % table[4])
4479		− print(' OEM Table ID : %s' % table[5])
4480		− print(' OEM Revision : %u' % table[6])
4481		− print(' Creator ID : %s' % table[7])
4482		− print(' Creator Revision : 0x%x' % table[8])
4483		− print('')
4484		−
4485		− if(table[0] != 'FPDT'):
4486		− if(output):
4487		− doError('Invalid FPDT table')
4488		− return False
4489		− if(len(buf) <= 36):
4490		− return False
4491		− i = 0
4492		− fwData = [0, 0]
4493		− records = buf[36:]
4494		− fp = open(sysvals.mempath, 'rb')
4495		− while(i < len(records)):
4496		− header = struct.unpack('HBB', records[i:i+4])
4497		− if(header[0] not in rectype):
4498		− i += header[1]
4499		− continue
4500		− if(header[1] != 16):
4501		− i += header[1]
4502		− continue
4503		− addr = struct.unpack('Q', records[i+8:i+16])[0]
4504		− try:
4505		− fp.seek(addr)
4506		− first = fp.read(8)
4507		− except:
4508		− if(output):
4509		− print('Bad address 0x%x in %s' % (addr, sysvals.mempath))
4510		− return [0, 0]
4511		− rechead = struct.unpack('4sI', first)
4512		− recdata = fp.read(rechead[1]-8)
4513		− if(rechead[0] == 'FBPT'):
4514		− record = struct.unpack('HBBIQQQQQ', recdata)
4515		− if(output):
4516		− print('%s (%s)' % (rectype[header[0]], rechead[0]))
4517		− print(' Reset END : %u ns' % record[4])
4518		− print(' OS Loader LoadImage Start : %u ns' % record[5])
4519		− print(' OS Loader StartImage Start : %u ns' % record[6])
4520		− print(' ExitBootServices Entry : %u ns' % record[7])
4521		− print(' ExitBootServices Exit : %u ns' % record[8])
4522		− elif(rechead[0] == 'S3PT'):
4523		− if(output):
4524		− print('%s (%s)' % (rectype[header[0]], rechead[0]))
4525		− j = 0
4526		− while(j < len(recdata)):
4527		− prechead = struct.unpack('HBB', recdata[j:j+4])
4528		− if(prechead[0] not in prectype):
4529		− continue
4530		− if(prechead[0] == 0):
4531		− record = struct.unpack('IIQQ', recdata[j:j+prechead[1]])
4532		− fwData[1] = record[2]
4533		− if(output):
4534		− print(' %s' % prectype[prechead[0]])
4535		− print(' Resume Count : %u' % \
4536		− record[1])
4537		− print(' FullResume : %u ns' % \
4538		− record[2])
4539		− print(' AverageResume : %u ns' % \
4540		− record[3])
4541		− elif(prechead[0] == 1):
4542		− record = struct.unpack('QQ', recdata[j+4:j+prechead[1]])
4543		− fwData[0] = record[1] - record[0]
4544		− if(output):
4545		− print(' %s' % prectype[prechead[0]])
4546		− print(' SuspendStart : %u ns' % \
4547		− record[0])
4548		− print(' SuspendEnd : %u ns' % \
4549		− record[1])
4550		− print(' SuspendTime : %u ns' % \
4551		− fwData[0])
4552		− j += prechead[1]
4553		− if(output):
4554		− print('')
4555		− i += header[1]
4556		− fp.close()
4557		− return fwData
4558		−
4559		−# Function: statusCheck
4560		−# Description:
4561		−# Verify that the requested command and options will work, and
4562		−# print the results to the terminal
4563		−# Output:
4564		−# True if the test will work, False if not
4565		−def statusCheck(probecheck=False):
4566		− status = True
4567		−
4568		− print('Checking this system (%s)...' % platform.node())
4569		−
4570		− # check we have root access
4571		− res = sysvals.colorText('NO (No features of this tool will work!)')
4572		− if(rootCheck(False)):
4573		− res = 'YES'
4574		− print(' have root access: %s' % res)
4575		− if(res != 'YES'):
4576		− print(' Try running this script with sudo')
4577		− return False
4578		−
4579		− # check sysfs is mounted
4580		− res = sysvals.colorText('NO (No features of this tool will work!)')
4581		− if(os.path.exists(sysvals.powerfile)):
4582		− res = 'YES'
4583		− print(' is sysfs mounted: %s' % res)
4584		− if(res != 'YES'):
4585		− return False
4586		−
4587		− # check target mode is a valid mode
4588		− if sysvals.suspendmode != 'command':
4589		− res = sysvals.colorText('NO')
4590		− modes = getModes()
4591		− if(sysvals.suspendmode in modes):
4592		− res = 'YES'
4593		− else:
4594		− status = False
4595		− print(' is "%s" a valid power mode: %s' % (sysvals.suspendmode, res))
4596		− if(res == 'NO'):
4597		− print(' valid power modes are: %s' % modes)
4598		− print(' please choose one with -m')
4599		−
4600		− # check if ftrace is available
4601		− res = sysvals.colorText('NO')
4602		− ftgood = sysvals.verifyFtrace()
4603		− if(ftgood):
4604		− res = 'YES'
4605		− elif(sysvals.usecallgraph):
4606		− status = False
4607		− print(' is ftrace supported: %s' % res)
4608		−
4609		− # check if kprobes are available
4610		− res = sysvals.colorText('NO')
4611		− sysvals.usekprobes = sysvals.verifyKprobes()
4612		− if(sysvals.usekprobes):
4613		− res = 'YES'
4614		− else:
4615		− sysvals.usedevsrc = False
4616		− print(' are kprobes supported: %s' % res)
4617		−
4618		− # what data source are we using
4619		− res = 'DMESG'
4620		− if(ftgood):
4621		− sysvals.usetraceeventsonly = True
4622		− sysvals.usetraceevents = False
4623		− for e in sysvals.traceevents:
4624		− check = False
4625		− if(os.path.exists(sysvals.epath+e)):
4626		− check = True
4627		− if(not check):
4628		− sysvals.usetraceeventsonly = False
4629		− if(e == 'suspend_resume' and check):
4630		− sysvals.usetraceevents = True
4631		− if(sysvals.usetraceevents and sysvals.usetraceeventsonly):
4632		− res = 'FTRACE (all trace events found)'
4633		− elif(sysvals.usetraceevents):
4634		− res = 'DMESG and FTRACE (suspend_resume trace event found)'
4635		− print(' timeline data source: %s' % res)
4636		−
4637		− # check if rtcwake
4638		− res = sysvals.colorText('NO')
4639		− if(sysvals.rtcpath != ''):
4640		− res = 'YES'
4641		− elif(sysvals.rtcwake):
4642		− status = False
4643		− print(' is rtcwake supported: %s' % res)
4644		−
4645		− if not probecheck:
4646		− return status
4647		−
4648		− # verify kprobes
4649		− if sysvals.usekprobes:
4650		− for name in sysvals.tracefuncs:
4651		− sysvals.defaultKprobe(name, sysvals.tracefuncs[name])
4652		− if sysvals.usedevsrc:
4653		− for name in sysvals.dev_tracefuncs:
4654		− sysvals.defaultKprobe(name, sysvals.dev_tracefuncs[name])
4655		− sysvals.addKprobes(True)
4656		−
4657		− return status
4658		−
4659		−# Function: doError
4660		−# Description:
4661		−# generic error function for catastrphic failures
4662		−# Arguments:
4663		−# msg: the error message to print
4664		−# help: True if printHelp should be called after, False otherwise
4665		−def doError(msg, help=False):
4666		− if(help == True):
4667		− printHelp()
4668		− print('ERROR: %s\n') % msg
4669		− sys.exit()
4670		−
4671		−# Function: rootCheck
4672		−# Description:
4673		−# quick check to see if we have root access
4674		−def rootCheck(fatal):
4675		− if(os.access(sysvals.powerfile, os.W_OK)):
4676		− return True
4677		− if fatal:
4678		− doError('This command must be run as root')
4679		− return False
4680		−
4681		−# Function: getArgInt
4682		−# Description:
4683		−# pull out an integer argument from the command line with checks
4684		−def getArgInt(name, args, min, max, main=True):
4685		− if main:
4686		− try:
4687		− arg = args.next()
4688		− except:
4689		− doError(name+': no argument supplied', True)
4690		− else:
4691		− arg = args
4692		− try:
4693		− val = int(arg)
4694		− except:
4695		− doError(name+': non-integer value given', True)
4696		− if(val < min or val > max):
4697		− doError(name+': value should be between %d and %d' % (min, max), True)
4698		− return val
4699		−
4700		−# Function: getArgFloat
4701		−# Description:
4702		−# pull out a float argument from the command line with checks
4703		−def getArgFloat(name, args, min, max, main=True):
4704		− if main:
4705		− try:
4706		− arg = args.next()
4707		− except:
4708		− doError(name+': no argument supplied', True)
4709		− else:
4710		− arg = args
4711		− try:
4712		− val = float(arg)
4713		− except:
4714		− doError(name+': non-numerical value given', True)
4715		− if(val < min or val > max):
4716		− doError(name+': value should be between %f and %f' % (min, max), True)
4717		− return val
4718		−
4719		−def processData():
4720		− print('PROCESSING DATA')
4721		− if(sysvals.usetraceeventsonly):
4722		− testruns = parseTraceLog()
4723		− if sysvals.dmesgfile:
4724		− dmesgtext = loadKernelLog(True)
4725		− for data in testruns:
4726		− data.extractErrorInfo(dmesgtext)
4727		− else:
4728		− testruns = loadKernelLog()
4729		− for data in testruns:
4730		− parseKernelLog(data)
4731		− if(sysvals.ftracefile and (sysvals.usecallgraph or sysvals.usetraceevents)):
4732		− appendIncompleteTraceLog(testruns)
4733		− createHTML(testruns)
4734		−
4735		−# Function: rerunTest
4736		−# Description:
4737		−# generate an output from an existing set of ftrace/dmesg logs
4738		−def rerunTest():
4739		− if sysvals.ftracefile:
4740		− doesTraceLogHaveTraceEvents()
4741		− if not sysvals.dmesgfile and not sysvals.usetraceeventsonly:
4742		− doError('recreating this html output requires a dmesg file')
4743		− sysvals.setOutputFile()
4744		− vprint('Output file: %s' % sysvals.htmlfile)
4745		− if(os.path.exists(sysvals.htmlfile) and not os.access(sysvals.htmlfile, os.W_OK)):
4746		− doError('missing permission to write to %s' % sysvals.htmlfile)
4747		− processData()
4748		−
4749		−# Function: runTest
4750		−# Description:
4751		−# execute a suspend/resume, gather the logs, and generate the output
4752		−def runTest(subdir, testpath=''):
4753		− # prepare for the test
4754		− sysvals.initFtrace()
4755		− sysvals.initTestOutput(subdir, testpath)
4756		− vprint('Output files:\n\t%s\n\t%s\n\t%s' % \
4757		− (sysvals.dmesgfile, sysvals.ftracefile, sysvals.htmlfile))
4758		−
4759		− # execute the test
4760		− executeSuspend()
4761		− sysvals.cleanupFtrace()
4762		− processData()
4763		−
4764		− # if running as root, change output dir owner to sudo_user
4765		− if os.path.isdir(sysvals.testdir) and os.getuid() == 0 and \
4766		− 'SUDO_USER' in os.environ:
4767		− cmd = 'chown -R {0}:{0} {1} > /dev/null 2>&1'
4768		− call(cmd.format(os.environ['SUDO_USER'], sysvals.testdir), shell=True)
4769		−
4770		−# Function: runSummary
4771		−# Description:
4772		−# create a summary of tests in a sub-directory
4773		−def runSummary(subdir, output):
4774		− # get a list of ftrace output files
4775		− files = []
4776		− for dirname, dirnames, filenames in os.walk(subdir):
4777		− for filename in filenames:
4778		− if(re.match('.*_ftrace.txt', filename)):
4779		− files.append("%s/%s" % (dirname, filename))
4780		−
4781		− # process the files in order and get an array of data objects
4782		− testruns = []
4783		− for file in sorted(files):
4784		− if output:
4785		− print("Test found in %s" % os.path.dirname(file))
4786		− sysvals.ftracefile = file
4787		− sysvals.dmesgfile = file.replace('_ftrace.txt', '_dmesg.txt')
4788		− doesTraceLogHaveTraceEvents()
4789		− sysvals.usecallgraph = False
4790		− if not sysvals.usetraceeventsonly:
4791		− if(not os.path.exists(sysvals.dmesgfile)):
4792		− print("Skipping %s: not a valid test input" % file)
4793		− continue
4794		− else:
4795		− if output:
4796		− f = os.path.basename(sysvals.ftracefile)
4797		− d = os.path.basename(sysvals.dmesgfile)
4798		− print("\tInput files: %s and %s" % (f, d))
4799		− testdata = loadKernelLog()
4800		− data = testdata[0]
4801		− parseKernelLog(data)
4802		− testdata = [data]
4803		− appendIncompleteTraceLog(testdata)
4804		− else:
4805		− if output:
4806		− print("\tInput file: %s" % os.path.basename(sysvals.ftracefile))
4807		− testdata = parseTraceLog()
4808		− data = testdata[0]
4809		− data.normalizeTime(data.tSuspended)
4810		− link = file.replace(subdir+'/', '').replace('_ftrace.txt', '.html')
4811		− data.outfile = link
4812		− testruns.append(data)
4813		−
4814		− createHTMLSummarySimple(testruns, subdir+'/summary.html')
4815		−
4816		−# Function: checkArgBool
4817		−# Description:
4818		−# check if a boolean string value is true or false
4819		−def checkArgBool(value):
4820		− yes = ['1', 'true', 'yes', 'on']
4821		− if value.lower() in yes:
4822		− return True
4823		− return False
4824		−
4825		−# Function: configFromFile
4826		−# Description:
4827		−# Configure the script via the info in a config file
4828		−def configFromFile(file):
4829		− Config = ConfigParser.ConfigParser()
4830		−
4831		− Config.read(file)
4832		− sections = Config.sections()
4833		− overridekprobes = False
4834		− overridedevkprobes = False
4835		− if 'Settings' in sections:
4836		− for opt in Config.options('Settings'):
4837		− value = Config.get('Settings', opt).lower()
4838		− if(opt.lower() == 'verbose'):
4839		− sysvals.verbose = checkArgBool(value)
4840		− elif(opt.lower() == 'addlogs'):
4841		− sysvals.addlogs = checkArgBool(value)
4842		− elif(opt.lower() == 'dev'):
4843		− sysvals.usedevsrc = checkArgBool(value)
4844		− elif(opt.lower() == 'proc'):
4845		− sysvals.useprocmon = checkArgBool(value)
4846		− elif(opt.lower() == 'x2'):
4847		− if checkArgBool(value):
4848		− sysvals.execcount = 2
4849		− elif(opt.lower() == 'callgraph'):
4850		− sysvals.usecallgraph = checkArgBool(value)
4851		− elif(opt.lower() == 'override-timeline-functions'):
4852		− overridekprobes = checkArgBool(value)
4853		− elif(opt.lower() == 'override-dev-timeline-functions'):
4854		− overridedevkprobes = checkArgBool(value)
4855		− elif(opt.lower() == 'devicefilter'):
4856		− sysvals.setDeviceFilter(value)
4857		− elif(opt.lower() == 'expandcg'):
4858		− sysvals.cgexp = checkArgBool(value)
4859		− elif(opt.lower() == 'srgap'):
4860		− if checkArgBool(value):
4861		− sysvals.srgap = 5
4862		− elif(opt.lower() == 'mode'):
4863		− sysvals.suspendmode = value
4864		− elif(opt.lower() == 'command'):
4865		− sysvals.testcommand = value
4866		− elif(opt.lower() == 'x2delay'):
4867		− sysvals.x2delay = getArgInt('-x2delay', value, 0, 60000, False)
4868		− elif(opt.lower() == 'predelay'):
4869		− sysvals.predelay = getArgInt('-predelay', value, 0, 60000, False)
4870		− elif(opt.lower() == 'postdelay'):
4871		− sysvals.postdelay = getArgInt('-postdelay', value, 0, 60000, False)
4872		− elif(opt.lower() == 'rtcwake'):
4873		− sysvals.rtcwake = True
4874		− sysvals.rtcwaketime = getArgInt('-rtcwake', value, 0, 3600, False)
4875		− elif(opt.lower() == 'timeprec'):
4876		− sysvals.setPrecision(getArgInt('-timeprec', value, 0, 6, False))
4877		− elif(opt.lower() == 'mindev'):
4878		− sysvals.mindevlen = getArgFloat('-mindev', value, 0.0, 10000.0, False)
4879		− elif(opt.lower() == 'callloop-maxgap'):
4880		− sysvals.callloopmaxgap = getArgFloat('-callloop-maxgap', value, 0.0, 1.0, False)
4881		− elif(opt.lower() == 'callloop-maxlen'):
4882		− sysvals.callloopmaxgap = getArgFloat('-callloop-maxlen', value, 0.0, 1.0, False)
4883		− elif(opt.lower() == 'mincg'):
4884		− sysvals.mincglen = getArgFloat('-mincg', value, 0.0, 10000.0, False)
4885		− elif(opt.lower() == 'output-dir'):
4886		− sysvals.setOutputFolder(value)
4887		−
4888		− if sysvals.suspendmode == 'command' and not sysvals.testcommand:
4889		− doError('No command supplied for mode "command"')
4890		−
4891		− # compatibility errors
4892		− if sysvals.usedevsrc and sysvals.usecallgraph:
4893		− doError('-dev is not compatible with -f')
4894		− if sysvals.usecallgraph and sysvals.useprocmon:
4895		− doError('-proc is not compatible with -f')
4896		−
4897		− if overridekprobes:
4898		− sysvals.tracefuncs = dict()
4899		− if overridedevkprobes:
4900		− sysvals.dev_tracefuncs = dict()
4901		−
4902		− kprobes = dict()
4903		− kprobesec = 'dev_timeline_functions_'+platform.machine()
4904		− if kprobesec in sections:
4905		− for name in Config.options(kprobesec):
4906		− text = Config.get(kprobesec, name)
4907		− kprobes[name] = (text, True)
4908		− kprobesec = 'timeline_functions_'+platform.machine()
4909		− if kprobesec in sections:
4910		− for name in Config.options(kprobesec):
4911		− if name in kprobes:
4912		− doError('Duplicate timeline function found "%s"' % (name))
4913		− text = Config.get(kprobesec, name)
4914		− kprobes[name] = (text, False)
4915		−
4916		− for name in kprobes:
4917		− function = name
4918		− format = name
4919		− color = ''
4920		− args = dict()
4921		− text, dev = kprobes[name]
4922		− data = text.split()
4923		− i = 0
4924		− for val in data:
4925		− # bracketted strings are special formatting, read them separately
4926		− if val[0] == '[' and val[-1] == ']':
4927		− for prop in val[1:-1].split(','):
4928		− p = prop.split('=')
4929		− if p[0] == 'color':
4930		− try:
4931		− color = int(p[1], 16)
4932		− color = '#'+p[1]
4933		− except:
4934		− color = p[1]
4935		− continue
4936		− # first real arg should be the format string
4937		− if i == 0:
4938		− format = val
4939		− # all other args are actual function args
4940		− else:
4941		− d = val.split('=')
4942		− args[d[0]] = d[1]
4943		− i += 1
4944		− if not function or not format:
4945		− doError('Invalid kprobe: %s' % name)
4946		− for arg in re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', format):
4947		− if arg not in args:
4948		− doError('Kprobe "%s" is missing argument "%s"' % (name, arg))
4949		− if (dev and name in sysvals.dev_tracefuncs) or (not dev and name in sysvals.tracefuncs):
4950		− doError('Duplicate timeline function found "%s"' % (name))
4951		−
4952		− kp = {
4953		− 'name': name,
4954		− 'func': function,
4955		− 'format': format,
4956		− sysvals.archargs: args
4957		− }
4958		− if color:
4959		− kp['color'] = color
4960		− if dev:
4961		− sysvals.dev_tracefuncs[name] = kp
4962		− else:
4963		− sysvals.tracefuncs[name] = kp
4964		−
4965		−# Function: printHelp
4966		−# Description:
4967		−# print out the help text
4968		−def printHelp():
4969		− modes = getModes()
4970		−
4971		− print('')
4972		− print('AnalyzeSuspend v%s' % sysvals.version)
4973		− print('Usage: sudo analyze_suspend.py <options>')
4974		− print('')
4975		− print('Description:')
4976		− print(' This tool is designed to assist kernel and OS developers in optimizing')
4977		− print(' their linux stack\'s suspend/resume time. Using a kernel image built')
4978		− print(' with a few extra options enabled, the tool will execute a suspend and')
4979		− print(' capture dmesg and ftrace data until resume is complete. This data is')
4980		− print(' transformed into a device timeline and an optional callgraph to give')
4981		− print(' a detailed view of which devices/subsystems are taking the most')
4982		− print(' time in suspend/resume.')
4983		− print('')
4984		− print(' Generates output files in subdirectory: suspend-mmddyy-HHMMSS')
4985		− print(' HTML output: <hostname>_<mode>.html')
4986		− print(' raw dmesg output: <hostname>_<mode>_dmesg.txt')
4987		− print(' raw ftrace output: <hostname>_<mode>_ftrace.txt')
4988		− print('')
4989		− print('Options:')
4990		− print(' [general]')
4991		− print(' -h Print this help text')
4992		− print(' -v Print the current tool version')
4993		− print(' -config fn Pull arguments and config options from file fn')
4994		− print(' -verbose Print extra information during execution and analysis')
4995		− print(' -status Test to see if the system is enabled to run this tool')
4996		− print(' -modes List available suspend modes')
4997		− print(' -m mode Mode to initiate for suspend %s (default: %s)') % (modes, sysvals.suspendmode)
4998		− print(' -o subdir Override the output subdirectory')
4999		− print(' -rtcwake t Use rtcwake to autoresume after <t> seconds (default: disabled)')

236 more lines aren’t shown here.