Merge tag 'pm-4.8-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm

Pull power management updates from Rafael Wysocki: "Again, the majority of changes go into the cpufreq subsystem, but there are no big features this time. The cpufreq changes that stand out somewhat are the governor interface rework and improvements related to the handling of frequency tables. Apart from those, there are fixes and new device/CPU IDs in drivers, cleanups and an improvement of the new schedutil governor. Next, there are some changes in the hibernation core, including a fix for a nasty problem related to the MONITOR/MWAIT usage by CPU offline during resume from hibernation, a few core improvements related to memory management during resume, a couple of additional debug features and cleanups. Finally, we have some fixes and cleanups in the devfreq subsystem, generic power domains framework improvements related to system suspend/resume, support for some new chips in intel_idle and in the power capping RAPL driver, a new version of the AnalyzeSuspend utility and some assorted fixes and cleanups. Specifics: - Rework the cpufreq governor interface to make it more straightforward and modify the conservative governor to avoid using transition notifications (Rafael Wysocki). - Rework the handling of frequency tables by the cpufreq core to make it more efficient (Viresh Kumar). - Modify the schedutil governor to reduce the number of wakeups it causes to occur in cases when the CPU frequency doesn't need to be changed (Steve Muckle, Viresh Kumar). - Fix some minor issues and clean up code in the cpufreq core and governors (Rafael Wysocki, Viresh Kumar). - Add Intel Broxton support to the intel_pstate driver (Srinivas Pandruvada). - Fix problems related to the config TDP feature and to the validity of the MSR_HWP_INTERRUPT register in intel_pstate (Jan Kiszka, Srinivas Pandruvada). - Make intel_pstate update the cpu_frequency tracepoint even if the frequency doesn't change to avoid confusing powertop (Rafael Wysocki). - Clean up the usage of __init/__initdata in intel_pstate, mark some of its internal variables as __read_mostly and drop an unused structure element from it (Jisheng Zhang, Carsten Emde). - Clean up the usage of some duplicate MSR symbols in intel_pstate and turbostat (Srinivas Pandruvada). - Update/fix the powernv, s3c24xx and mvebu cpufreq drivers (Akshay Adiga, Viresh Kumar, Ben Dooks). - Fix a regression (introduced during the 4.5 cycle) in the pcc-cpufreq driver by reverting the problematic commit (Andreas Herrmann). - Add support for Intel Denverton to intel_idle, clean up Broxton support in it and make it explicitly non-modular (Jacob Pan, Jan Beulich, Paul Gortmaker). - Add support for Denverton and Ivy Bridge server to the Intel RAPL power capping driver and make it more careful about the handing of MSRs that may not be present (Jacob Pan, Xiaolong Wang). - Fix resume from hibernation on x86-64 by making the CPU offline during resume avoid using MONITOR/MWAIT in the "play dead" loop which may lead to an inadvertent "revival" of a "dead" CPU and a page fault leading to a kernel crash from it (Rafael Wysocki). - Make memory management during resume from hibernation more straightforward (Rafael Wysocki). - Add debug features that should help to detect problems related to hibernation and resume from it (Rafael Wysocki, Chen Yu). - Clean up hibernation core somewhat (Rafael Wysocki). - Prevent KASAN from instrumenting the hibernation core which leads to large numbers of false-positives from it (James Morse). - Prevent PM (hibernate and suspend) notifiers from being called during the cleanup phase if they have not been called during the corresponding preparation phase which is possible if one of the other notifiers returns an error at that time (Lianwei Wang). - Improve suspend-related debug printout in the tasks freezer and clean up suspend-related console handling (Roger Lu, Borislav Petkov). - Update the AnalyzeSuspend script in the kernel sources to version 4.2 (Todd Brandt). - Modify the generic power domains framework to make it handle system suspend/resume better (Ulf Hansson). - Make the runtime PM framework avoid resuming devices synchronously when user space changes the runtime PM settings for them and improve its error reporting (Rafael Wysocki, Linus Walleij). - Fix error paths in devfreq drivers (exynos, exynos-ppmu, exynos-bus) and in the core, make some devfreq code explicitly non-modular and change some of it into tristate (Bartlomiej Zolnierkiewicz, Peter Chen, Paul Gortmaker). - Add DT support to the generic PM clocks management code and make it export some more symbols (Jon Hunter, Paul Gortmaker). - Make the PCI PM core code slightly more robust against possible driver errors (Andy Shevchenko). - Make it possible to change DESTDIR and PREFIX in turbostat (Andy Shevchenko)" * tag 'pm-4.8-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm: (89 commits) Revert "cpufreq: pcc-cpufreq: update default value of cpuinfo_transition_latency" PM / hibernate: Introduce test_resume mode for hibernation cpufreq: export cpufreq_driver_resolve_freq() cpufreq: Disallow ->resolve_freq() for drivers providing ->target_index() PCI / PM: check all fields in pci_set_platform_pm() cpufreq: acpi-cpufreq: use cached frequency mapping when possible cpufreq: schedutil: map raw required frequency to driver frequency cpufreq: add cpufreq_driver_resolve_freq() cpufreq: intel_pstate: Check cpuid for MSR_HWP_INTERRUPT intel_pstate: Update cpu_frequency tracepoint every time cpufreq: intel_pstate: clean remnant struct element PM / tools: scripts: AnalyzeSuspend v4.2 x86 / hibernate: Use hlt_play_dead() when resuming from hibernation cpufreq: powernv: Replacing pstate_id with frequency table index intel_pstate: Fix MSR_CONFIG_TDP_x addressing in core_get_max_pstate() PM / hibernate: Image data protection during restoration PM / hibernate: Add missing braces in __register_nosave_region() PM / hibernate: Clean up comments in snapshot.c PM / hibernate: Clean up function headers in snapshot.c PM / hibernate: Add missing braces in hibernate_setup() ...

Linus Torvalds committed 10 years ago

Commit 6453dbd2 parents 27b7902 bc841e265 files · +4332 −2821Browse files

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

Unified · Split

scripts/analyze_suspend.py+2474−1167

@@ -19,6 +19,17 @@ · 18 unmodified lines
19	19	# Authors:
20	20	# Todd Brandt <todd.e.brandt@linux.intel.com>
21	21	#
	22	+# Links:
	23	+# Home Page
	24	+# https://01.org/suspendresume
	25	+# Source repo
	26	+# https://github.com/01org/suspendresume
	27	+# Documentation
	28	+# Getting Started
	29	+# https://01.org/suspendresume/documentation/getting-started
	30	+# Command List:
	31	+# https://01.org/suspendresume/documentation/command-list
	32	+#
22	33	# Description:
23	34	# This tool is designed to assist kernel and OS developers in optimizing
24	35	# their linux stack's suspend/resume time. Using a kernel image built
@@ -35,6 +46,8 @@ · 10 unmodified lines
35	46	# CONFIG_FTRACE=y
36	47	# CONFIG_FUNCTION_TRACER=y
37	48	# CONFIG_FUNCTION_GRAPH_TRACER=y
	49	+# CONFIG_KPROBES=y
	50	+# CONFIG_KPROBES_ON_FTRACE=y
38	51	#
39	52	# For kernel versions older than 3.15:
40	53	# The following additional kernel parameters are required:
@@ -52,6 +65,7 @@ import re · 11 unmodified lines
52	65	import platform
53	66	from datetime import datetime
54	67	import struct
	68	+import ConfigParser
55	69
56	70	# ----------------- CLASSES --------------------
57	71
@@ -60,8 +74,15 @@ import struct · 2 unmodified lines
60	74	# A global, single-instance container used to
61	75	# store system values and test parameters
62	76	class SystemValues:
63		− version = 3.0
	77	+ ansi = False
	78	+ version = '4.2'
64	79	verbose = False
	80	+ addlogs = False
	81	+ mindevlen = 0.001
	82	+ mincglen = 1.0
	83	+ srgap = 0
	84	+ cgexp = False
	85	+ outdir = ''
65	86	testdir = '.'
66	87	tpath = '/sys/kernel/debug/tracing/'
67	88	fpdtpath = '/sys/firmware/acpi/tables/FPDT'
@@ -71,26 +92,21 @@ class SystemValues: · 3 unmodified lines
71	92	'device_pm_callback_end',
72	93	'device_pm_callback_start'
73	94	]
74		− modename = {
75		− 'freeze': 'Suspend-To-Idle (S0)',
76		− 'standby': 'Power-On Suspend (S1)',
77		− 'mem': 'Suspend-to-RAM (S3)',
78		− 'disk': 'Suspend-to-disk (S4)'
79		− }
	95	+ testcommand = ''
80	96	mempath = '/dev/mem'
81	97	powerfile = '/sys/power/state'
82	98	suspendmode = 'mem'
83	99	hostname = 'localhost'
84	100	prefix = 'test'
85	101	teststamp = ''
	102	+ dmesgstart = 0.0
86	103	dmesgfile = ''
87	104	ftracefile = ''
88	105	htmlfile = ''
	106	+ embedded = False
89	107	rtcwake = False
90	108	rtcwaketime = 10
91	109	rtcpath = ''
92		− android = False
93		− adb = 'adb'
94	110	devicefilter = []
95	111	stamp = 0
96	112	execcount = 1
@@ -98,16 +114,90 @@ class SystemValues: · 1 unmodified line
98	114	usecallgraph = False
99	115	usetraceevents = False
100	116	usetraceeventsonly = False
	117	+ usetracemarkers = True
	118	+ usekprobes = True
	119	+ usedevsrc = False
101	120	notestrun = False
102		− altdevname = dict()
	121	+ devprops = dict()
103	122	postresumetime = 0
	123	+ devpropfmt = '# Device Properties: .*'
104	124	tracertypefmt = '# tracer: (?P<t>.*)'
105	125	firmwarefmt = '# fwsuspend (?P<s>[0-9]) fwresume (?P<r>[0-9])$'
106	126	postresumefmt = '# post resume time (?P<t>[0-9]*)$'
107	127	stampfmt = '# suspend-(?P<m>[0-9]{2})(?P<d>[0-9]{2})(?P<y>[0-9]{2})-'+\
108	128	'(?P<H>[0-9]{2})(?P<M>[0-9]{2})(?P<S>[0-9]{2})'+\
109	129	' (?P<host>.) (?P<mode>.) (?P<kernel>.*)$'
	130	+ kprobecolor = 'rgba(204,204,204,0.5)'
	131	+ synccolor = 'rgba(204,204,204,0.5)'
	132	+ debugfuncs = []
	133	+ tracefuncs = {
	134	+ 'sys_sync': dict(),
	135	+ 'pm_prepare_console': dict(),
	136	+ 'pm_notifier_call_chain': dict(),
	137	+ 'freeze_processes': dict(),
	138	+ 'freeze_kernel_threads': dict(),
	139	+ 'pm_restrict_gfp_mask': dict(),
	140	+ 'acpi_suspend_begin': dict(),
	141	+ 'suspend_console': dict(),
	142	+ 'acpi_pm_prepare': dict(),
	143	+ 'syscore_suspend': dict(),
	144	+ 'arch_enable_nonboot_cpus_end': dict(),
	145	+ 'syscore_resume': dict(),
	146	+ 'acpi_pm_finish': dict(),
	147	+ 'resume_console': dict(),
	148	+ 'acpi_pm_end': dict(),
	149	+ 'pm_restore_gfp_mask': dict(),
	150	+ 'thaw_processes': dict(),
	151	+ 'pm_restore_console': dict(),
	152	+ 'CPU_OFF': {
	153	+ 'func':'_cpu_down',
	154	+ 'args_x86_64': {'cpu':'%di:s32'},
	155	+ 'format': 'CPU_OFF[{cpu}]',
	156	+ 'mask': 'CPU_.*_DOWN'
	157	+ },
	158	+ 'CPU_ON': {
	159	+ 'func':'_cpu_up',
	160	+ 'args_x86_64': {'cpu':'%di:s32'},
	161	+ 'format': 'CPU_ON[{cpu}]',
	162	+ 'mask': 'CPU_.*_UP'
	163	+ },
	164	+ }
	165	+ dev_tracefuncs = {
	166	+ # general wait/delay/sleep
	167	+ 'msleep': { 'args_x86_64': {'time':'%di:s32'} },
	168	+ 'udelay': { 'func':'__const_udelay', 'args_x86_64': {'loops':'%di:s32'} },
	169	+ 'acpi_os_stall': dict(),
	170	+ # ACPI
	171	+ 'acpi_resume_power_resources': dict(),
	172	+ 'acpi_ps_parse_aml': dict(),
	173	+ # filesystem
	174	+ 'ext4_sync_fs': dict(),
	175	+ # ATA
	176	+ 'ata_eh_recover': { 'args_x86_64': {'port':'+36(%di):s32'} },
	177	+ # i915
	178	+ 'i915_gem_restore_gtt_mappings': dict(),
	179	+ 'intel_opregion_setup': dict(),
	180	+ 'intel_dp_detect': dict(),
	181	+ 'intel_hdmi_detect': dict(),
	182	+ 'intel_opregion_init': dict(),
	183	+ }
	184	+ kprobes_postresume = [
	185	+ {
	186	+ 'name': 'ataportrst',
	187	+ 'func': 'ata_eh_recover',
	188	+ 'args': {'port':'+36(%di):s32'},
	189	+ 'format': 'ata{port}_port_reset',
	190	+ 'mask': 'ata.*_port_reset'
	191	+ }
	192	+ ]
	193	+ kprobes = dict()
	194	+ timeformat = '%.3f'
110	195	def __init__(self):
	196	+ # if this is a phoronix test run, set some default options
	197	+ if('LOG_FILE' in os.environ and 'TEST_RESULTS_IDENTIFIER' in os.environ):
	198	+ self.embedded = True
	199	+ self.addlogs = True
	200	+ self.htmlfile = os.environ['LOG_FILE']
111	201	self.hostname = platform.node()
112	202	if(self.hostname == ''):
113	203	self.hostname = 'localhost'
@@ -118,6 +208,12 @@ class SystemValues: · 4 unmodified lines
118	208	if os.path.exists(rtc) and os.path.exists(rtc+'/date') and \
119	209	os.path.exists(rtc+'/time') and os.path.exists(rtc+'/wakealarm'):
120	210	self.rtcpath = rtc
	211	+ if (hasattr(sys.stdout, 'isatty') and sys.stdout.isatty()):
	212	+ self.ansi = True
	213	+ def setPrecision(self, num):
	214	+ if num < 0 or num > 6:
	215	+ return
	216	+ self.timeformat = '%.{0}f'.format(num)
121	217	def setOutputFile(self):
122	218	if((self.htmlfile == '') and (self.dmesgfile != '')):
123	219	m = re.match('(?P<name>.*)_dmesg\.txt$', self.dmesgfile)
@@ -129,32 +225,37 @@ class SystemValues: · 5 unmodified lines
129	225	self.htmlfile = m.group('name')+'.html'
130	226	if(self.htmlfile == ''):
131	227	self.htmlfile = 'output.html'
132		− def initTestOutput(self, subdir):
133		− if(not self.android):
134		− self.prefix = self.hostname
135		− v = open('/proc/version', 'r').read().strip()
136		− kver = string.split(v)[2]
137		− else:
138		− self.prefix = 'android'
139		− v = os.popen(self.adb+' shell cat /proc/version').read().strip()
140		− kver = string.split(v)[2]
141		− testtime = datetime.now().strftime('suspend-%m%d%y-%H%M%S')
	228	+ def initTestOutput(self, subdir, testpath=''):
	229	+ self.prefix = self.hostname
	230	+ v = open('/proc/version', 'r').read().strip()
	231	+ kver = string.split(v)[2]
	232	+ n = datetime.now()
	233	+ testtime = n.strftime('suspend-%m%d%y-%H%M%S')
	234	+ if not testpath:
	235	+ testpath = n.strftime('suspend-%y%m%d-%H%M%S')
142	236	if(subdir != "."):
143		− self.testdir = subdir+"/"+testtime
	237	+ self.testdir = subdir+"/"+testpath
144	238	else:
145		− self.testdir = testtime
	239	+ self.testdir = testpath
146	240	self.teststamp = \
147	241	'# '+testtime+' '+self.prefix+' '+self.suspendmode+' '+kver
	242	+ if(self.embedded):
	243	+ self.dmesgfile = \
	244	+ '/tmp/'+testtime+'_'+self.suspendmode+'_dmesg.txt'
	245	+ self.ftracefile = \
	246	+ '/tmp/'+testtime+'_'+self.suspendmode+'_ftrace.txt'
	247	+ return
148	248	self.dmesgfile = \
149	249	self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_dmesg.txt'
150	250	self.ftracefile = \
151	251	self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_ftrace.txt'
152	252	self.htmlfile = \
153	253	self.testdir+'/'+self.prefix+'_'+self.suspendmode+'.html'
154		− os.mkdir(self.testdir)
	254	+ if not os.path.isdir(self.testdir):
	255	+ os.mkdir(self.testdir)
155	256	def setDeviceFilter(self, devnames):
156	257	self.devicefilter = string.split(devnames)
157		− def rtcWakeAlarm(self):
	258	+ def rtcWakeAlarmOn(self):
158	259	os.system('echo 0 > '+self.rtcpath+'/wakealarm')
159	260	outD = open(self.rtcpath+'/date', 'r').read().strip()
160	261	outT = open(self.rtcpath+'/time', 'r').read().strip()
@@ -172,9 +273,361 @@ class SystemValues: · 11 unmodified lines
172	273	nowtime = int(datetime.now().strftime('%s'))
173	274	alarm = nowtime + self.rtcwaketime
174	275	os.system('echo %d > %s/wakealarm' % (alarm, self.rtcpath))
	276	+ def rtcWakeAlarmOff(self):
	277	+ os.system('echo 0 > %s/wakealarm' % self.rtcpath)
	278	+ def initdmesg(self):
	279	+ # get the latest time stamp from the dmesg log
	280	+ fp = os.popen('dmesg')
	281	+ ktime = '0'
	282	+ for line in fp:
	283	+ line = line.replace('\r\n', '')
	284	+ idx = line.find('[')
	285	+ if idx > 1:
	286	+ line = line[idx:]
	287	+ m = re.match('[ \t](\[ )(?P<ktime>[0-9\.])(\]) (?P<msg>.)', line)
	288	+ if(m):
	289	+ ktime = m.group('ktime')
	290	+ fp.close()
	291	+ self.dmesgstart = float(ktime)
	292	+ def getdmesg(self):
	293	+ # store all new dmesg lines since initdmesg was called
	294	+ fp = os.popen('dmesg')
	295	+ op = open(self.dmesgfile, 'a')
	296	+ for line in fp:
	297	+ line = line.replace('\r\n', '')
	298	+ idx = line.find('[')
	299	+ if idx > 1:
	300	+ line = line[idx:]
	301	+ m = re.match('[ \t](\[ )(?P<ktime>[0-9\.])(\]) (?P<msg>.)', line)
	302	+ if(not m):
	303	+ continue
	304	+ ktime = float(m.group('ktime'))
	305	+ if ktime > self.dmesgstart:
	306	+ op.write(line)
	307	+ fp.close()
	308	+ op.close()
	309	+ def addFtraceFilterFunctions(self, file):
	310	+ fp = open(file)
	311	+ list = fp.read().split('\n')
	312	+ fp.close()
	313	+ for i in list:
	314	+ if len(i) < 2:
	315	+ continue
	316	+ self.tracefuncs[i] = dict()
	317	+ def getFtraceFilterFunctions(self, current):
	318	+ rootCheck(True)
	319	+ if not current:
	320	+ os.system('cat '+self.tpath+'available_filter_functions')
	321	+ return
	322	+ fp = open(self.tpath+'available_filter_functions')
	323	+ master = fp.read().split('\n')
	324	+ fp.close()
	325	+ if len(self.debugfuncs) > 0:
	326	+ for i in self.debugfuncs:
	327	+ if i in master:
	328	+ print i
	329	+ else:
	330	+ print self.colorText(i)
	331	+ else:
	332	+ for i in self.tracefuncs:
	333	+ if 'func' in self.tracefuncs[i]:
	334	+ i = self.tracefuncs[i]['func']
	335	+ if i in master:
	336	+ print i
	337	+ else:
	338	+ print self.colorText(i)
	339	+ def setFtraceFilterFunctions(self, list):
	340	+ fp = open(self.tpath+'available_filter_functions')
	341	+ master = fp.read().split('\n')
	342	+ fp.close()
	343	+ flist = ''
	344	+ for i in list:
	345	+ if i not in master:
	346	+ continue
	347	+ if ' [' in i:
	348	+ flist += i.split(' ')[0]+'\n'
	349	+ else:
	350	+ flist += i+'\n'
	351	+ fp = open(self.tpath+'set_graph_function', 'w')
	352	+ fp.write(flist)
	353	+ fp.close()
	354	+ def kprobeMatch(self, name, target):
	355	+ if name not in self.kprobes:
	356	+ return False
	357	+ if re.match(self.kprobes[name]['mask'], target):
	358	+ return True
	359	+ return False
	360	+ def basicKprobe(self, name):
	361	+ self.kprobes[name] = {'name': name,'func': name,'args': dict(),'format': name,'mask': name}
	362	+ def defaultKprobe(self, name, kdata):
	363	+ k = kdata
	364	+ for field in ['name', 'format', 'mask', 'func']:
	365	+ if field not in k:
	366	+ k[field] = name
	367	+ archargs = 'args_'+platform.machine()
	368	+ if archargs in k:
	369	+ k['args'] = k[archargs]
	370	+ else:
	371	+ k['args'] = dict()
	372	+ k['format'] = name
	373	+ self.kprobes[name] = k
	374	+ def kprobeColor(self, name):
	375	+ if name not in self.kprobes or 'color' not in self.kprobes[name]:
	376	+ return ''
	377	+ return self.kprobes[name]['color']
	378	+ def kprobeDisplayName(self, name, dataraw):
	379	+ if name not in self.kprobes:
	380	+ self.basicKprobe(name)
	381	+ data = ''
	382	+ quote=0
	383	+ # first remvoe any spaces inside quotes, and the quotes
	384	+ for c in dataraw:
	385	+ if c == '"':
	386	+ quote = (quote + 1) % 2
	387	+ if quote and c == ' ':
	388	+ data += '_'
	389	+ elif c != '"':
	390	+ data += c
	391	+ fmt, args = self.kprobes[name]['format'], self.kprobes[name]['args']
	392	+ arglist = dict()
	393	+ # now process the args
	394	+ for arg in sorted(args):
	395	+ arglist[arg] = ''
	396	+ m = re.match('.* '+arg+'=(?P<arg>.*) ', data);
	397	+ if m:
	398	+ arglist[arg] = m.group('arg')
	399	+ else:
	400	+ m = re.match('.* '+arg+'=(?P<arg>.*)', data);
	401	+ if m:
	402	+ arglist[arg] = m.group('arg')
	403	+ out = fmt.format(**arglist)
	404	+ out = out.replace(' ', '_').replace('"', '')
	405	+ return out
	406	+ def kprobeText(self, kprobe):
	407	+ name, fmt, func, args = kprobe['name'], kprobe['format'], kprobe['func'], kprobe['args']
	408	+ if re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', func):
	409	+ doError('Kprobe "%s" has format info in the function name "%s"' % (name, func), False)
	410	+ for arg in re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', fmt):
	411	+ if arg not in args:
	412	+ doError('Kprobe "%s" is missing argument "%s"' % (name, arg), False)
	413	+ val = 'p:%s_cal %s' % (name, func)
	414	+ for i in sorted(args):
	415	+ val += ' %s=%s' % (i, args[i])
	416	+ val += '\nr:%s_ret %s $retval\n' % (name, func)
	417	+ return val
	418	+ def addKprobes(self):
	419	+ # first test each kprobe
	420	+ print('INITIALIZING KPROBES...')
	421	+ rejects = []
	422	+ for name in sorted(self.kprobes):
	423	+ if not self.testKprobe(self.kprobes[name]):
	424	+ rejects.append(name)
	425	+ # remove all failed ones from the list
	426	+ for name in rejects:
	427	+ vprint('Skipping KPROBE: %s' % name)
	428	+ self.kprobes.pop(name)
	429	+ self.fsetVal('', 'kprobe_events')
	430	+ kprobeevents = ''
	431	+ # set the kprobes all at once
	432	+ for kp in self.kprobes:
	433	+ val = self.kprobeText(self.kprobes[kp])
	434	+ vprint('Adding KPROBE: %s\n%s' % (kp, val.strip()))
	435	+ kprobeevents += self.kprobeText(self.kprobes[kp])
	436	+ self.fsetVal(kprobeevents, 'kprobe_events')
	437	+ # verify that the kprobes were set as ordered
	438	+ check = self.fgetVal('kprobe_events')
	439	+ linesout = len(kprobeevents.split('\n'))
	440	+ linesack = len(check.split('\n'))
	441	+ if linesack < linesout:
	442	+ # if not, try appending the kprobes 1 by 1
	443	+ for kp in self.kprobes:
	444	+ kprobeevents = self.kprobeText(self.kprobes[kp])
	445	+ self.fsetVal(kprobeevents, 'kprobe_events', 'a')
	446	+ self.fsetVal('1', 'events/kprobes/enable')
	447	+ def testKprobe(self, kprobe):
	448	+ kprobeevents = self.kprobeText(kprobe)
	449	+ if not kprobeevents:
	450	+ return False
	451	+ try:
	452	+ self.fsetVal(kprobeevents, 'kprobe_events')
	453	+ check = self.fgetVal('kprobe_events')
	454	+ except:
	455	+ return False
	456	+ linesout = len(kprobeevents.split('\n'))
	457	+ linesack = len(check.split('\n'))
	458	+ if linesack < linesout:
	459	+ return False
	460	+ return True
	461	+ def fsetVal(self, val, path, mode='w'):
	462	+ file = self.tpath+path
	463	+ if not os.path.exists(file):
	464	+ return False
	465	+ try:
	466	+ fp = open(file, mode)
	467	+ fp.write(val)
	468	+ fp.close()
	469	+ except:
	470	+ pass
	471	+ return True
	472	+ def fgetVal(self, path):
	473	+ file = self.tpath+path
	474	+ res = ''
	475	+ if not os.path.exists(file):
	476	+ return res
	477	+ try:
	478	+ fp = open(file, 'r')
	479	+ res = fp.read()
	480	+ fp.close()
	481	+ except:
	482	+ pass
	483	+ return res
	484	+ def cleanupFtrace(self):
	485	+ if(self.usecallgraph or self.usetraceevents):
	486	+ self.fsetVal('0', 'events/kprobes/enable')
	487	+ self.fsetVal('', 'kprobe_events')
	488	+ def setupAllKprobes(self):
	489	+ for name in self.tracefuncs:
	490	+ self.defaultKprobe(name, self.tracefuncs[name])
	491	+ for name in self.dev_tracefuncs:
	492	+ self.defaultKprobe(name, self.dev_tracefuncs[name])
	493	+ def isCallgraphFunc(self, name):
	494	+ if len(self.debugfuncs) < 1 and self.suspendmode == 'command':
	495	+ return True
	496	+ if name in self.debugfuncs:
	497	+ return True
	498	+ funclist = []
	499	+ for i in self.tracefuncs:
	500	+ if 'func' in self.tracefuncs[i]:
	501	+ funclist.append(self.tracefuncs[i]['func'])
	502	+ else:
	503	+ funclist.append(i)
	504	+ if name in funclist:
	505	+ return True
	506	+ return False
	507	+ def initFtrace(self, testing=False):
	508	+ tp = self.tpath
	509	+ print('INITIALIZING FTRACE...')
	510	+ # turn trace off
	511	+ self.fsetVal('0', 'tracing_on')
	512	+ self.cleanupFtrace()
	513	+ # set the trace clock to global
	514	+ self.fsetVal('global', 'trace_clock')
	515	+ # set trace buffer to a huge value
	516	+ self.fsetVal('nop', 'current_tracer')
	517	+ self.fsetVal('100000', 'buffer_size_kb')
	518	+ # go no further if this is just a status check
	519	+ if testing:
	520	+ return
	521	+ if self.usekprobes:
	522	+ # add tracefunc kprobes so long as were not using full callgraph
	523	+ if(not self.usecallgraph or len(self.debugfuncs) > 0):
	524	+ for name in self.tracefuncs:
	525	+ self.defaultKprobe(name, self.tracefuncs[name])
	526	+ if self.usedevsrc:
	527	+ for name in self.dev_tracefuncs:
	528	+ self.defaultKprobe(name, self.dev_tracefuncs[name])
	529	+ else:
	530	+ self.usedevsrc = False
	531	+ self.addKprobes()
	532	+ # initialize the callgraph trace, unless this is an x2 run
	533	+ if(self.usecallgraph):
	534	+ # set trace type
	535	+ self.fsetVal('function_graph', 'current_tracer')
	536	+ self.fsetVal('', 'set_ftrace_filter')
	537	+ # set trace format options
	538	+ self.fsetVal('print-parent', 'trace_options')
	539	+ self.fsetVal('funcgraph-abstime', 'trace_options')
	540	+ self.fsetVal('funcgraph-cpu', 'trace_options')
	541	+ self.fsetVal('funcgraph-duration', 'trace_options')
	542	+ self.fsetVal('funcgraph-proc', 'trace_options')
	543	+ self.fsetVal('funcgraph-tail', 'trace_options')
	544	+ self.fsetVal('nofuncgraph-overhead', 'trace_options')
	545	+ self.fsetVal('context-info', 'trace_options')
	546	+ self.fsetVal('graph-time', 'trace_options')
	547	+ self.fsetVal('0', 'max_graph_depth')
	548	+ if len(self.debugfuncs) > 0:
	549	+ self.setFtraceFilterFunctions(self.debugfuncs)
	550	+ elif self.suspendmode == 'command':
	551	+ self.fsetVal('', 'set_graph_function')
	552	+ else:
	553	+ cf = ['dpm_run_callback']
	554	+ if(self.usetraceeventsonly):
	555	+ cf += ['dpm_prepare', 'dpm_complete']
	556	+ for fn in self.tracefuncs:
	557	+ if 'func' in self.tracefuncs[fn]:
	558	+ cf.append(self.tracefuncs[fn]['func'])
	559	+ else:
	560	+ cf.append(fn)
	561	+ self.setFtraceFilterFunctions(cf)
	562	+ if(self.usetraceevents):
	563	+ # turn trace events on
	564	+ events = iter(self.traceevents)
	565	+ for e in events:
	566	+ self.fsetVal('1', 'events/power/'+e+'/enable')
	567	+ # clear the trace buffer
	568	+ self.fsetVal('', 'trace')
	569	+ def verifyFtrace(self):
	570	+ # files needed for any trace data
	571	+ files = ['buffer_size_kb', 'current_tracer', 'trace', 'trace_clock',
	572	+ 'trace_marker', 'trace_options', 'tracing_on']
	573	+ # files needed for callgraph trace data
	574	+ tp = self.tpath
	575	+ if(self.usecallgraph):
	576	+ files += [
	577	+ 'available_filter_functions',
	578	+ 'set_ftrace_filter',
	579	+ 'set_graph_function'
	580	+ ]
	581	+ for f in files:
	582	+ if(os.path.exists(tp+f) == False):
	583	+ return False
	584	+ return True
	585	+ def verifyKprobes(self):
	586	+ # files needed for kprobes to work
	587	+ files = ['kprobe_events', 'events']
	588	+ tp = self.tpath
	589	+ for f in files:
	590	+ if(os.path.exists(tp+f) == False):
	591	+ return False
	592	+ return True
	593	+ def colorText(self, str):
	594	+ if not self.ansi:
	595	+ return str
	596	+ return '\x1B[31;40m'+str+'\x1B[m'
175	597
176	598	sysvals = SystemValues()
177	599
	600	+# Class: DevProps
	601	+# Description:
	602	+# Simple class which holds property values collected
	603	+# for all the devices used in the timeline.
	604	+class DevProps:
	605	+ syspath = ''
	606	+ altname = ''
	607	+ async = True
	608	+ xtraclass = ''
	609	+ xtrainfo = ''
	610	+ def out(self, dev):
	611	+ return '%s,%s,%d;' % (dev, self.altname, self.async)
	612	+ def debug(self, dev):
	613	+ print '%s:\n\taltname = %s\n\t async = %s' % (dev, self.altname, self.async)
	614	+ def altName(self, dev):
	615	+ if not self.altname or self.altname == dev:
	616	+ return dev
	617	+ return '%s [%s]' % (self.altname, dev)
	618	+ def xtraClass(self):
	619	+ if self.xtraclass:
	620	+ return ' '+self.xtraclass
	621	+ if not self.async:
	622	+ return ' sync'
	623	+ return ''
	624	+ def xtraInfo(self):
	625	+ if self.xtraclass:
	626	+ return ' '+self.xtraclass
	627	+ if self.async:
	628	+ return ' async'
	629	+ return ' sync'
	630	+
178	631	# Class: DeviceNode
179	632	# Description:
180	633	# A container used to create a device hierachy, with a single root node
@@ -228,6 +681,7 @@ class Data: · 47 unmodified lines
228	681	html_device_id = 0
229	682	stamp = 0
230	683	outfile = ''
	684	+ dev_ubiquitous = ['msleep', 'udelay']
231	685	def __init__(self, num):
232	686	idchar = 'abcdefghijklmnopqrstuvwxyz'
233	687	self.testnumber = num
@@ -257,6 +711,9 @@ class Data: · 23 unmodified lines
257	711	'row': 0, 'color': '#FFFFCC', 'order': 9}
258	712	}
259	713	self.phases = self.sortedPhases()
	714	+ self.devicegroups = []
	715	+ for phase in self.phases:
	716	+ self.devicegroups.append([phase])
260	717	def getStart(self):
261	718	return self.dmesg[self.phases[0]]['start']
262	719	def setStart(self, time):
@@ -273,51 +730,61 @@ class Data: · 10 unmodified lines
273	730	for dev in list:
274	731	d = list[dev]
275	732	if(d['pid'] == pid and time >= d['start'] and
276		− time <= d['end']):
	733	+ time < d['end']):
277	734	return False
278	735	return True
279		− def addIntraDevTraceEvent(self, action, name, pid, time):
280		− if(action == 'mutex_lock_try'):
281		− color = 'red'
282		− elif(action == 'mutex_lock_pass'):
283		− color = 'green'
284		− elif(action == 'mutex_unlock'):
285		− color = 'blue'
286		− else:
287		− # create separate colors based on the name
288		− v1 = len(name)*10 % 256
289		− v2 = string.count(name, 'e')*100 % 256
290		− v3 = ord(name[0])*20 % 256
291		− color = '#%06X' % ((v10x10000) + (v20x100) + v3)
292		− for phase in self.phases:
	736	+ def targetDevice(self, phaselist, start, end, pid=-1):
	737	+ tgtdev = ''
	738	+ for phase in phaselist:
293	739	list = self.dmesg[phase]['list']
294		− for dev in list:
295		− d = list[dev]
296		− if(d['pid'] == pid and time >= d['start'] and
297		− time <= d['end']):
298		− e = TraceEvent(action, name, color, time)
299		− if('traceevents' not in d):
300		− d['traceevents'] = []
301		− d['traceevents'].append(e)
302		− return d
303		− break
304		− return 0
305		− def capIntraDevTraceEvent(self, action, name, pid, time):
306		− for phase in self.phases:
307		− list = self.dmesg[phase]['list']
308		− for dev in list:
309		− d = list[dev]
310		− if(d['pid'] == pid and time >= d['start'] and
311		− time <= d['end']):
312		− if('traceevents' not in d):
313		− return
314		− for e in d['traceevents']:
315		− if(e.action == action and
316		− e.name == name and not e.ready):
317		− e.length = time - e.time
318		− e.ready = True
319		− break
320		− return
	740	+ for devname in list:
	741	+ dev = list[devname]
	742	+ if(pid >= 0 and dev['pid'] != pid):
	743	+ continue
	744	+ devS = dev['start']
	745	+ devE = dev['end']
	746	+ if(start < devS or start >= devE or end <= devS or end > devE):
	747	+ continue
	748	+ tgtdev = dev
	749	+ break
	750	+ return tgtdev
	751	+ def addDeviceFunctionCall(self, displayname, kprobename, proc, pid, start, end, cdata, rdata):
	752	+ machstart = self.dmesg['suspend_machine']['start']
	753	+ machend = self.dmesg['resume_machine']['end']
	754	+ tgtdev = self.targetDevice(self.phases, start, end, pid)
	755	+ if not tgtdev and start >= machstart and end < machend:
	756	+ # device calls in machine phases should be serial
	757	+ tgtdev = self.targetDevice(['suspend_machine', 'resume_machine'], start, end)
	758	+ if not tgtdev:
	759	+ if 'scsi_eh' in proc:
	760	+ self.newActionGlobal(proc, start, end, pid)
	761	+ self.addDeviceFunctionCall(displayname, kprobename, proc, pid, start, end, cdata, rdata)
	762	+ else:
	763	+ vprint('IGNORE: %s[%s](%d) [%f - %f] \| %s \| %s \| %s' % (displayname, kprobename,
	764	+ pid, start, end, cdata, rdata, proc))
	765	+ return False
	766	+ # detail block fits within tgtdev
	767	+ if('src' not in tgtdev):
	768	+ tgtdev['src'] = []
	769	+ title = cdata+' '+rdata
	770	+ mstr = '$.$ (?P<args>.) \((?P<caller>.)\+. arg1=(?P<ret>.*)'
	771	+ m = re.match(mstr, title)
	772	+ if m:
	773	+ c = m.group('caller')
	774	+ a = m.group('args').strip()
	775	+ r = m.group('ret')
	776	+ if len(r) > 6:
	777	+ r = ''
	778	+ else:
	779	+ r = 'ret=%s ' % r
	780	+ l = '%0.3fms' % ((end - start) * 1000)
	781	+ if kprobename in self.dev_ubiquitous:
	782	+ title = '%s(%s) <- %s, %s(%s)' % (displayname, a, c, r, l)
	783	+ else:
	784	+ title = '%s(%s) %s(%s)' % (displayname, a, r, l)
	785	+ e = TraceEvent(title, kprobename, start, end - start)
	786	+ tgtdev['src'].append(e)
	787	+ return True
321	788	def trimTimeVal(self, t, t0, dT, left):
322	789	if left:
323	790	if(t > t0):
@@ -353,11 +820,11 @@ class Data: · 29 unmodified lines
353	820	cg.end = self.trimTimeVal(cg.end, t0, dT, left)
354	821	for line in cg.list:
355	822	line.time = self.trimTimeVal(line.time, t0, dT, left)
356		− if('traceevents' in d):
357		− for e in d['traceevents']:
	823	+ if('src' in d):
	824	+ for e in d['src']:
358	825	e.time = self.trimTimeVal(e.time, t0, dT, left)
359	826	def normalizeTime(self, tZero):
360		− # first trim out any standby or freeze clock time
	827	+ # trim out any standby or freeze clock time
361	828	if(self.tSuspended != self.tResumed):
362	829	if(self.tResumed > tZero):
363	830	self.trimTime(self.tSuspended, \
@@ -365,29 +832,6 @@ class Data: · 1 unmodified line
365	832	else:
366	833	self.trimTime(self.tSuspended, \
367	834	self.tResumed-self.tSuspended, False)
368		− # shift the timeline so that tZero is the new 0
369		− self.tSuspended -= tZero
370		− self.tResumed -= tZero
371		− self.start -= tZero
372		− self.end -= tZero
373		− for phase in self.phases:
374		− p = self.dmesg[phase]
375		− p['start'] -= tZero
376		− p['end'] -= tZero
377		− list = p['list']
378		− for name in list:
379		− d = list[name]
380		− d['start'] -= tZero
381		− d['end'] -= tZero
382		− if('ftrace' in d):
383		− cg = d['ftrace']
384		− cg.start -= tZero
385		− cg.end -= tZero
386		− for line in cg.list:
387		− line.time -= tZero
388		− if('traceevents' in d):
389		− for e in d['traceevents']:
390		− e.time -= tZero
391	835	def newPhaseWithSingleAction(self, phasename, devname, start, end, color):
392	836	for phase in self.phases:
393	837	self.dmesg[phase]['order'] += 1
@@ -417,6 +861,7 @@ class Data: · 23 unmodified lines
417	861	{'list': list, 'start': start, 'end': end,
418	862	'row': 0, 'color': color, 'order': order}
419	863	self.phases = self.sortedPhases()
	864	+ self.devicegroups.append([phasename])
420	865	def setPhase(self, phase, ktime, isbegin):
421	866	if(isbegin):
422	867	self.dmesg[phase]['start'] = ktime
@@ -442,7 +887,10 @@ class Data: · 19 unmodified lines
442	887	for devname in phaselist:
443	888	dev = phaselist[devname]
444	889	if(dev['end'] < 0):
445		− dev['end'] = end
	890	+ for p in self.phases:
	891	+ if self.dmesg[p]['end'] > dev['start']:
	892	+ dev['end'] = self.dmesg[p]['end']
	893	+ break
446	894	vprint('%s (%s): callback didnt return' % (devname, phase))
447	895	def deviceFilter(self, devicefilter):
448	896	# remove all by the relatives of the filter devnames
@@ -472,22 +920,58 @@ class Data: · 23 unmodified lines
472	920	# if any calls never returned, clip them at system resume end
473	921	for phase in self.phases:
474	922	self.fixupInitcalls(phase, self.getEnd())
475		− def newActionGlobal(self, name, start, end):
	923	+ def isInsideTimeline(self, start, end):
	924	+ if(self.start <= start and self.end > start):
	925	+ return True
	926	+ return False
	927	+ def phaseOverlap(self, phases):
	928	+ rmgroups = []
	929	+ newgroup = []
	930	+ for group in self.devicegroups:
	931	+ for phase in phases:
	932	+ if phase not in group:
	933	+ continue
	934	+ for p in group:
	935	+ if p not in newgroup:
	936	+ newgroup.append(p)
	937	+ if group not in rmgroups:
	938	+ rmgroups.append(group)
	939	+ for group in rmgroups:
	940	+ self.devicegroups.remove(group)
	941	+ self.devicegroups.append(newgroup)
	942	+ def newActionGlobal(self, name, start, end, pid=-1, color=''):
	943	+ # if event starts before timeline start, expand timeline
	944	+ if(start < self.start):
	945	+ self.setStart(start)
	946	+ # if event ends after timeline end, expand the timeline
	947	+ if(end > self.end):
	948	+ self.setEnd(end)
476	949	# which phase is this device callback or action "in"
477	950	targetphase = "none"
	951	+ htmlclass = ''
478	952	overlap = 0.0
	953	+ phases = []
479	954	for phase in self.phases:
480	955	pstart = self.dmesg[phase]['start']
481	956	pend = self.dmesg[phase]['end']
482	957	o = max(0, min(end, pend) - max(start, pstart))
483		− if(o > overlap):
	958	+ if o > 0:
	959	+ phases.append(phase)
	960	+ if o > overlap:
	961	+ if overlap > 0 and phase == 'post_resume':
	962	+ continue
484	963	targetphase = phase
485	964	overlap = o
	965	+ if pid == -2:
	966	+ htmlclass = ' bg'
	967	+ if len(phases) > 1:
	968	+ htmlclass = ' bg'
	969	+ self.phaseOverlap(phases)
486	970	if targetphase in self.phases:
487		− self.newAction(targetphase, name, -1, '', start, end, '')
488		− return True
	971	+ newname = self.newAction(targetphase, name, pid, '', start, end, '', htmlclass, color)
	972	+ return (targetphase, newname)
489	973	return False
490		− def newAction(self, phase, name, pid, parent, start, end, drv):
	974	+ def newAction(self, phase, name, pid, parent, start, end, drv, htmlclass='', color=''):
491	975	# new device callback for a specific phase
492	976	self.html_device_id += 1
493	977	devid = '%s%d' % (self.idstr, self.html_device_id)
@@ -495,8 +979,19 @@ class Data: · 1 unmodified line
495	979	length = -1.0
496	980	if(start >= 0 and end >= 0):
497	981	length = end - start
	982	+ if pid == -2:
	983	+ i = 2
	984	+ origname = name
	985	+ while(name in list):
	986	+ name = '%s[%d]' % (origname, i)
	987	+ i += 1
498	988	list[name] = {'start': start, 'end': end, 'pid': pid, 'par': parent,
499	989	'length': length, 'row': 0, 'id': devid, 'drv': drv }
	990	+ if htmlclass:
	991	+ list[name]['htmlclass'] = htmlclass
	992	+ if color:
	993	+ list[name]['color'] = color
	994	+ return name
500	995	def deviceIDs(self, devlist, phase):
501	996	idlist = []
502	997	list = self.dmesg[phase]['list']
@@ -536,10 +1031,21 @@ class Data: · 33 unmodified lines
536	1031	vprint(' %16s: %f - %f (%d devices)' % (phase, \
537	1032	self.dmesg[phase]['start'], self.dmesg[phase]['end'], dc))
538	1033	vprint(' test end: %f' % self.end)
	1034	+ def deviceChildrenAllPhases(self, devname):
	1035	+ devlist = []
	1036	+ for phase in self.phases:
	1037	+ list = self.deviceChildren(devname, phase)
	1038	+ for dev in list:
	1039	+ if dev not in devlist:
	1040	+ devlist.append(dev)
	1041	+ return devlist
539	1042	def masterTopology(self, name, list, depth):
540	1043	node = DeviceNode(name, depth)
541	1044	for cname in list:
542		− clist = self.deviceChildren(cname, 'resume')
	1045	+ # avoid recursions
	1046	+ if name == cname:
	1047	+ continue
	1048	+ clist = self.deviceChildrenAllPhases(cname)
543	1049	cnode = self.masterTopology(cname, clist, depth+1)
544	1050	node.children.append(cnode)
545	1051	return node
@@ -580,7 +1086,8 @@ class Data: · 34 unmodified lines
580	1086	list = self.dmesg[phase]['list']
581	1087	for dev in list:
582	1088	pdev = list[dev]['par']
583		− if(re.match('[0-9]-[0-9]\.[0-9][\.0-9]\:[\.0-9]*$', pdev)):
	1089	+ pid = list[dev]['pid']
	1090	+ if(pid < 0 or re.match('[0-9]-[0-9]\.[0-9][\.0-9]\:[\.0-9]*$', pdev)):
584	1091	continue
585	1092	if pdev and pdev not in real and pdev not in rootlist:
586	1093	rootlist.append(pdev)
@@ -589,22 +1096,33 @@ class Data: · 2 unmodified lines
589	1096	rootlist = self.rootDeviceList()
590	1097	master = self.masterTopology('', rootlist, 0)
591	1098	return self.printTopology(master)
	1099	+ def selectTimelineDevices(self, widfmt, tTotal, mindevlen):
	1100	+ # only select devices that will actually show up in html
	1101	+ self.tdevlist = dict()
	1102	+ for phase in self.dmesg:
	1103	+ devlist = []
	1104	+ list = self.dmesg[phase]['list']
	1105	+ for dev in list:
	1106	+ length = (list[dev]['end'] - list[dev]['start']) * 1000
	1107	+ width = widfmt % (((list[dev]['end']-list[dev]['start'])*100)/tTotal)
	1108	+ if width != '0.000000' and length >= mindevlen:
	1109	+ devlist.append(dev)
	1110	+ self.tdevlist[phase] = devlist
592	1111
593	1112	# Class: TraceEvent
594	1113	# Description:
595	1114	# A container for trace event data found in the ftrace file
596	1115	class TraceEvent:
597		− ready = False
598		− name = ''
	1116	+ text = ''
599	1117	time = 0.0
600		− color = '#FFFFFF'
601	1118	length = 0.0
602		− action = ''
603		− def __init__(self, a, n, c, t):
604		− self.action = a
605		− self.name = n
606		− self.color = c
	1119	+ title = ''
	1120	+ row = 0
	1121	+ def __init__(self, a, n, t, l):
	1122	+ self.title = a
	1123	+ self.text = n
607	1124	self.time = t
	1125	+ self.length = l
608	1126
609	1127	# Class: FTraceLine
610	1128	# Description:
@@ -623,11 +1141,14 @@ class FTraceLine: · 12 unmodified lines
623	1141	fcall = False
624	1142	freturn = False
625	1143	fevent = False
	1144	+ fkprobe = False
626	1145	depth = 0
627	1146	name = ''
628	1147	type = ''
629		− def __init__(self, t, m, d):
	1148	+ def __init__(self, t, m='', d=''):
630	1149	self.time = float(t)
	1150	+ if not m and not d:
	1151	+ return
631	1152	# is this a trace event
632	1153	if(d == 'traceevent' or re.match('^ \/\ (?P<msg>.) \\/ $', m)):
633	1154	if(d == 'traceevent'):
@@ -644,6 +1165,18 @@ class FTraceLine: · 10 unmodified lines
644	1165	self.type = emm.group('call')
645	1166	else:
646	1167	self.name = msg
	1168	+ km = re.match('^(?P<n>.*)_cal$', self.type)
	1169	+ if km:
	1170	+ self.fcall = True
	1171	+ self.fkprobe = True
	1172	+ self.type = km.group('n')
	1173	+ return
	1174	+ km = re.match('^(?P<n>.*)_ret$', self.type)
	1175	+ if km:
	1176	+ self.freturn = True
	1177	+ self.fkprobe = True
	1178	+ self.type = km.group('n')
	1179	+ return
647	1180	self.fevent = True
648	1181	return
649	1182	# convert the duration to seconds
@@ -662,7 +1195,7 @@ class FTraceLine: · 12 unmodified lines
662	1195	# includes comment with function name
663	1196	match = re.match('^} \/\ (?P<n>.) \\/$', m)
664	1197	if(match):
665		− self.name = match.group('n')
	1198	+ self.name = match.group('n').strip()
666	1199	# function call
667	1200	else:
668	1201	self.fcall = True
@@ -670,19 +1203,19 @@ class FTraceLine: · 1 unmodified line
670	1203	if(m[-1] == '{'):
671	1204	match = re.match('^(?P<n>.) \(.*', m)
672	1205	if(match):
673		− self.name = match.group('n')
	1206	+ self.name = match.group('n').strip()
674	1207	# function call with no children (leaf)
675	1208	elif(m[-1] == ';'):
676	1209	self.freturn = True
677	1210	match = re.match('^(?P<n>.) \(.*', m)
678	1211	if(match):
679		− self.name = match.group('n')
	1212	+ self.name = match.group('n').strip()
680	1213	# something else (possibly a trace marker)
681	1214	else:
682	1215	self.name = m
683	1216	def getDepth(self, str):
684	1217	return len(str)/2
685		− def debugPrint(self, dev):
	1218	+ def debugPrint(self, dev=''):
686	1219	if(self.freturn and self.fcall):
687	1220	print('%s -- %f (%02d): %s(); (%.3f us)' % (dev, self.time, \
688	1221	self.depth, self.name, self.length*1000000))
@@ -692,6 +1225,33 @@ class FTraceLine: · 3 unmodified lines
692	1225	else:
693	1226	print('%s -- %f (%02d): %s() { (%.3f us)' % (dev, self.time, \
694	1227	self.depth, self.name, self.length*1000000))
	1228	+ def startMarker(self):
	1229	+ global sysvals
	1230	+ # Is this the starting line of a suspend?
	1231	+ if not self.fevent:
	1232	+ return False
	1233	+ if sysvals.usetracemarkers:
	1234	+ if(self.name == 'SUSPEND START'):
	1235	+ return True
	1236	+ return False
	1237	+ else:
	1238	+ if(self.type == 'suspend_resume' and
	1239	+ re.match('suspend_enter\[.*\] begin', self.name)):
	1240	+ return True
	1241	+ return False
	1242	+ def endMarker(self):
	1243	+ # Is this the ending line of a resume?
	1244	+ if not self.fevent:
	1245	+ return False
	1246	+ if sysvals.usetracemarkers:
	1247	+ if(self.name == 'RESUME COMPLETE'):
	1248	+ return True
	1249	+ return False
	1250	+ else:
	1251	+ if(self.type == 'suspend_resume' and
	1252	+ re.match('thaw_processes\[.*\] end', self.name)):
	1253	+ return True
	1254	+ return False
695	1255
696	1256	# Class: FTraceCallGraph
697	1257	# Description:
@@ -705,54 +1265,124 @@ class FTraceCallGraph: · 7 unmodified lines
705	1265	list = []
706	1266	invalid = False
707	1267	depth = 0
708		− def __init__(self):
	1268	+ pid = 0
	1269	+ def __init__(self, pid):
709	1270	self.start = -1.0
710	1271	self.end = -1.0
711	1272	self.list = []
712	1273	self.depth = 0
713		− def setDepth(self, line):
	1274	+ self.pid = pid
	1275	+ def addLine(self, line, debug=False):
	1276	+ # if this is already invalid, just leave
	1277	+ if(self.invalid):
	1278	+ return False
	1279	+ # invalidate on too much data or bad depth
	1280	+ if(len(self.list) >= 1000000 or self.depth < 0):
	1281	+ self.invalidate(line)
	1282	+ return False
	1283	+ # compare current depth with this lines pre-call depth
	1284	+ prelinedep = line.depth
	1285	+ if(line.freturn and not line.fcall):
	1286	+ prelinedep += 1
	1287	+ last = 0
	1288	+ lasttime = line.time
	1289	+ virtualfname = 'execution_misalignment'
	1290	+ if len(self.list) > 0:
	1291	+ last = self.list[-1]
	1292	+ lasttime = last.time
	1293	+ # handle low misalignments by inserting returns
	1294	+ if prelinedep < self.depth:
	1295	+ if debug and last:
	1296	+ print '-------- task %d --------' % self.pid
	1297	+ last.debugPrint()
	1298	+ idx = 0
	1299	+ # add return calls to get the depth down
	1300	+ while prelinedep < self.depth:
	1301	+ if debug:
	1302	+ print 'MISALIGN LOW (add returns): C%d - eC%d' % (self.depth, prelinedep)
	1303	+ self.depth -= 1
	1304	+ if idx == 0 and last and last.fcall and not last.freturn:
	1305	+ # special case, turn last call into a leaf
	1306	+ last.depth = self.depth
	1307	+ last.freturn = True
	1308	+ last.length = line.time - last.time
	1309	+ if debug:
	1310	+ last.debugPrint()
	1311	+ else:
	1312	+ vline = FTraceLine(lasttime)
	1313	+ vline.depth = self.depth
	1314	+ vline.name = virtualfname
	1315	+ vline.freturn = True
	1316	+ self.list.append(vline)
	1317	+ if debug:
	1318	+ vline.debugPrint()
	1319	+ idx += 1
	1320	+ if debug:
	1321	+ line.debugPrint()
	1322	+ print ''
	1323	+ # handle high misalignments by inserting calls
	1324	+ elif prelinedep > self.depth:
	1325	+ if debug and last:
	1326	+ print '-------- task %d --------' % self.pid
	1327	+ last.debugPrint()
	1328	+ idx = 0
	1329	+ # add calls to get the depth up
	1330	+ while prelinedep > self.depth:
	1331	+ if debug:
	1332	+ print 'MISALIGN HIGH (add calls): C%d - eC%d' % (self.depth, prelinedep)
	1333	+ if idx == 0 and line.freturn and not line.fcall:
	1334	+ # special case, turn this return into a leaf
	1335	+ line.fcall = True
	1336	+ prelinedep -= 1
	1337	+ else:
	1338	+ vline = FTraceLine(lasttime)
	1339	+ vline.depth = self.depth
	1340	+ vline.name = virtualfname
	1341	+ vline.fcall = True
	1342	+ if debug:
	1343	+ vline.debugPrint()
	1344	+ self.list.append(vline)
	1345	+ self.depth += 1
	1346	+ if not last:
	1347	+ self.start = vline.time
	1348	+ idx += 1
	1349	+ if debug:
	1350	+ line.debugPrint()
	1351	+ print ''
	1352	+ # process the call and set the new depth
714	1353	if(line.fcall and not line.freturn):
715		− line.depth = self.depth
716	1354	self.depth += 1
717	1355	elif(line.freturn and not line.fcall):
718	1356	self.depth -= 1
719		− line.depth = self.depth
720		− else:
721		− line.depth = self.depth
722		− def addLine(self, line, match):
723		− if(not self.invalid):
724		− self.setDepth(line)
	1357	+ if len(self.list) < 1:
	1358	+ self.start = line.time
	1359	+ self.list.append(line)
725	1360	if(line.depth == 0 and line.freturn):
726	1361	if(self.start < 0):
727	1362	self.start = line.time
728	1363	self.end = line.time
729		− self.list.append(line)
	1364	+ if line.fcall:
	1365	+ self.end += line.length
	1366	+ if self.list[0].name == virtualfname:
	1367	+ self.invalid = True
730	1368	return True
731		− if(self.invalid):
732		− return False
733		− if(len(self.list) >= 1000000 or self.depth < 0):
734		− if(len(self.list) > 0):
735		− first = self.list[0]
736		− self.list = []
737		− self.list.append(first)
738		− self.invalid = True
739		− if(not match):
740		− return False
741		− id = 'task %s cpu %s' % (match.group('pid'), match.group('cpu'))
742		− window = '(%f - %f)' % (self.start, line.time)
743		− if(self.depth < 0):
744		− print('Too much data for '+id+\
745		− ' (buffer overflow), ignoring this callback')
746		− else:
747		− print('Too much data for '+id+\
748		− ' '+window+', ignoring this callback')
749		− return False
750		− self.list.append(line)
751		− if(self.start < 0):
752		− self.start = line.time
753	1369	return False
	1370	+ def invalidate(self, line):
	1371	+ if(len(self.list) > 0):
	1372	+ first = self.list[0]
	1373	+ self.list = []
	1374	+ self.list.append(first)
	1375	+ self.invalid = True
	1376	+ id = 'task %s' % (self.pid)
	1377	+ window = '(%f - %f)' % (self.start, line.time)
	1378	+ if(self.depth < 0):
	1379	+ vprint('Too much data for '+id+\
	1380	+ ' (buffer overflow), ignoring this callback')
	1381	+ else:
	1382	+ vprint('Too much data for '+id+\
	1383	+ ' '+window+', ignoring this callback')
754	1384	def slice(self, t0, tN):
755		− minicg = FTraceCallGraph()
	1385	+ minicg = FTraceCallGraph(0)
756	1386	count = -1
757	1387	firstdepth = 0
758	1388	for l in self.list:
@@ -764,13 +1394,26 @@ class FTraceCallGraph: · 5 unmodified lines
764	1394	firstdepth = l.depth
765	1395	count = 0
766	1396	l.depth -= firstdepth
767		− minicg.addLine(l, 0)
	1397	+ minicg.addLine(l)
768	1398	if((count == 0 and l.freturn and l.fcall) or
769	1399	(count > 0 and l.depth <= 0)):
770	1400	break
771	1401	count += 1
772	1402	return minicg
773		− def sanityCheck(self):
	1403	+ def repair(self, enddepth):
	1404	+ # bring the depth back to 0 with additional returns
	1405	+ fixed = False
	1406	+ last = self.list[-1]
	1407	+ for i in reversed(range(enddepth)):
	1408	+ t = FTraceLine(last.time)
	1409	+ t.depth = i
	1410	+ t.freturn = True
	1411	+ fixed = self.addLine(t)
	1412	+ if fixed:
	1413	+ self.end = last.time
	1414	+ return True
	1415	+ return False
	1416	+ def postProcess(self, debug=False):
774	1417	stack = dict()
775	1418	cnt = 0
776	1419	for l in self.list:
@@ -779,98 +1422,317 @@ class FTraceCallGraph: · 2 unmodified lines
779	1422	cnt += 1
780	1423	elif(l.freturn and not l.fcall):
781	1424	if(l.depth not in stack):
	1425	+ if debug:
	1426	+ print 'Post Process Error: Depth missing'
	1427	+ l.debugPrint()
782	1428	return False
	1429	+ # transfer total time from return line to call line
783	1430	stack[l.depth].length = l.length
784		− stack[l.depth] = 0
	1431	+ stack.pop(l.depth)
785	1432	l.length = 0
786	1433	cnt -= 1
787	1434	if(cnt == 0):
	1435	+ # trace caught the whole call tree
788	1436	return True
789		− return False
790		− def debugPrint(self, filename):
791		− if(filename == 'stdout'):
792		− print('[%f - %f]') % (self.start, self.end)
793		− for l in self.list:
794		− if(l.freturn and l.fcall):
795		− print('%f (%02d): %s(); (%.3f us)' % (l.time, \
796		− l.depth, l.name, l.length*1000000))
797		− elif(l.freturn):
798		− print('%f (%02d): %s} (%.3f us)' % (l.time, \
799		− l.depth, l.name, l.length*1000000))
800		− else:
801		− print('%f (%02d): %s() { (%.3f us)' % (l.time, \
802		− l.depth, l.name, l.length*1000000))
803		− print(' ')
804		− else:
805		− fp = open(filename, 'w')
806		− print(filename)
807		− for l in self.list:
808		− if(l.freturn and l.fcall):
809		− fp.write('%f (%02d): %s(); (%.3f us)\n' % (l.time, \
810		− l.depth, l.name, l.length*1000000))
811		− elif(l.freturn):
812		− fp.write('%f (%02d): %s} (%.3f us)\n' % (l.time, \
813		− l.depth, l.name, l.length*1000000))
814		− else:
815		− fp.write('%f (%02d): %s() { (%.3f us)\n' % (l.time, \
816		− l.depth, l.name, l.length*1000000))
817		− fp.close()
	1437	+ elif(cnt < 0):
	1438	+ if debug:
	1439	+ print 'Post Process Error: Depth is less than 0'
	1440	+ return False
	1441	+ # trace ended before call tree finished
	1442	+ return self.repair(cnt)
	1443	+ def deviceMatch(self, pid, data):
	1444	+ found = False
	1445	+ # add the callgraph data to the device hierarchy
	1446	+ borderphase = {
	1447	+ 'dpm_prepare': 'suspend_prepare',
	1448	+ 'dpm_complete': 'resume_complete'
	1449	+ }
	1450	+ if(self.list[0].name in borderphase):
	1451	+ p = borderphase[self.list[0].name]
	1452	+ list = data.dmesg[p]['list']
	1453	+ for devname in list:
	1454	+ dev = list[devname]
	1455	+ if(pid == dev['pid'] and
	1456	+ self.start <= dev['start'] and
	1457	+ self.end >= dev['end']):
	1458	+ dev['ftrace'] = self.slice(dev['start'], dev['end'])
	1459	+ found = True
	1460	+ return found
	1461	+ for p in data.phases:
	1462	+ if(data.dmesg[p]['start'] <= self.start and
	1463	+ self.start <= data.dmesg[p]['end']):
	1464	+ list = data.dmesg[p]['list']
	1465	+ for devname in list:
	1466	+ dev = list[devname]
	1467	+ if(pid == dev['pid'] and
	1468	+ self.start <= dev['start'] and
	1469	+ self.end >= dev['end']):
	1470	+ dev['ftrace'] = self
	1471	+ found = True
	1472	+ break
	1473	+ break
	1474	+ return found
	1475	+ def newActionFromFunction(self, data):
	1476	+ name = self.list[0].name
	1477	+ if name in ['dpm_run_callback', 'dpm_prepare', 'dpm_complete']:
	1478	+ return
	1479	+ fs = self.start
	1480	+ fe = self.end
	1481	+ if fs < data.start or fe > data.end:
	1482	+ return
	1483	+ phase = ''
	1484	+ for p in data.phases:
	1485	+ if(data.dmesg[p]['start'] <= self.start and
	1486	+ self.start < data.dmesg[p]['end']):
	1487	+ phase = p
	1488	+ break
	1489	+ if not phase:
	1490	+ return
	1491	+ out = data.newActionGlobal(name, fs, fe, -2)
	1492	+ if out:
	1493	+ phase, myname = out
	1494	+ data.dmesg[phase]['list'][myname]['ftrace'] = self
	1495	+ def debugPrint(self):
	1496	+ print('[%f - %f] %s (%d)') % (self.start, self.end, self.list[0].name, self.pid)
	1497	+ for l in self.list:
	1498	+ if(l.freturn and l.fcall):
	1499	+ print('%f (%02d): %s(); (%.3f us)' % (l.time, \
	1500	+ l.depth, l.name, l.length*1000000))
	1501	+ elif(l.freturn):
	1502	+ print('%f (%02d): %s} (%.3f us)' % (l.time, \
	1503	+ l.depth, l.name, l.length*1000000))
	1504	+ else:
	1505	+ print('%f (%02d): %s() { (%.3f us)' % (l.time, \
	1506	+ l.depth, l.name, l.length*1000000))
	1507	+ print(' ')
818	1508
819	1509	# Class: Timeline
820	1510	# Description:
821		−# A container for a suspend/resume html timeline. In older versions
822		−# of the script there were multiple timelines, but in the latest
823		−# there is only one.
	1511	+# A container for a device timeline which calculates
	1512	+# all the html properties to display it correctly
824	1513	class Timeline:
825	1514	html = {}
826		− scaleH = 0.0 # height of the row as a percent of the timeline height
827		− rowH = 0.0 # height of each row in percent of the timeline height
828		− row_height_pixels = 30
829		− maxrows = 0
830		− height = 0
831		− def __init__(self):
	1515	+ height = 0 # total timeline height
	1516	+ scaleH = 20 # timescale (top) row height
	1517	+ rowH = 30 # device row height
	1518	+ bodyH = 0 # body height
	1519	+ rows = 0 # total timeline rows
	1520	+ phases = []
	1521	+ rowmaxlines = dict()
	1522	+ rowcount = dict()
	1523	+ rowheight = dict()
	1524	+ def __init__(self, rowheight):
	1525	+ self.rowH = rowheight
832	1526	self.html = {
	1527	+ 'header': '',
833	1528	'timeline': '',
834	1529	'legend': '',
835		− 'scale': ''
836	1530	}
837		− def setRows(self, rows):
838		− self.maxrows = int(rows)
839		− self.scaleH = 100.0/float(self.maxrows)
840		− self.height = self.maxrows*self.row_height_pixels
841		− r = float(self.maxrows - 1)
842		− if(r < 1.0):
843		− r = 1.0
844		− self.rowH = (100.0 - self.scaleH)/r
	1531	+ # Function: getDeviceRows
	1532	+ # Description:
	1533	+ # determine how may rows the device funcs will take
	1534	+ # Arguments:
	1535	+ # rawlist: the list of devices/actions for a single phase
	1536	+ # Output:
	1537	+ # The total number of rows needed to display this phase of the timeline
	1538	+ def getDeviceRows(self, rawlist):
	1539	+ # clear all rows and set them to undefined
	1540	+ lendict = dict()
	1541	+ for item in rawlist:
	1542	+ item.row = -1
	1543	+ lendict[item] = item.length
	1544	+ list = []
	1545	+ for i in sorted(lendict, key=lendict.get, reverse=True):
	1546	+ list.append(i)
	1547	+ remaining = len(list)
	1548	+ rowdata = dict()
	1549	+ row = 1
	1550	+ # try to pack each row with as many ranges as possible
	1551	+ while(remaining > 0):
	1552	+ if(row not in rowdata):
	1553	+ rowdata[row] = []
	1554	+ for i in list:
	1555	+ if(i.row >= 0):
	1556	+ continue
	1557	+ s = i.time
	1558	+ e = i.time + i.length
	1559	+ valid = True
	1560	+ for ritem in rowdata[row]:
	1561	+ rs = ritem.time
	1562	+ re = ritem.time + ritem.length
	1563	+ if(not (((s <= rs) and (e <= rs)) or
	1564	+ ((s >= re) and (e >= re)))):
	1565	+ valid = False
	1566	+ break
	1567	+ if(valid):
	1568	+ rowdata[row].append(i)
	1569	+ i.row = row
	1570	+ remaining -= 1
	1571	+ row += 1
	1572	+ return row
	1573	+ # Function: getPhaseRows
	1574	+ # Description:
	1575	+ # Organize the timeline entries into the smallest
	1576	+ # number of rows possible, with no entry overlapping
	1577	+ # Arguments:
	1578	+ # list: the list of devices/actions for a single phase
	1579	+ # devlist: string list of device names to use
	1580	+ # Output:
	1581	+ # The total number of rows needed to display this phase of the timeline
	1582	+ def getPhaseRows(self, dmesg, devlist):
	1583	+ # clear all rows and set them to undefined
	1584	+ remaining = len(devlist)
	1585	+ rowdata = dict()
	1586	+ row = 0
	1587	+ lendict = dict()
	1588	+ myphases = []
	1589	+ for item in devlist:
	1590	+ if item[0] not in self.phases:
	1591	+ self.phases.append(item[0])
	1592	+ if item[0] not in myphases:
	1593	+ myphases.append(item[0])
	1594	+ self.rowmaxlines[item[0]] = dict()
	1595	+ self.rowheight[item[0]] = dict()
	1596	+ dev = dmesg[item[0]]['list'][item[1]]
	1597	+ dev['row'] = -1
	1598	+ lendict[item] = float(dev['end']) - float(dev['start'])
	1599	+ if 'src' in dev:
	1600	+ dev['devrows'] = self.getDeviceRows(dev['src'])
	1601	+ lenlist = []
	1602	+ for i in sorted(lendict, key=lendict.get, reverse=True):
	1603	+ lenlist.append(i)
	1604	+ orderedlist = []
	1605	+ for item in lenlist:
	1606	+ dev = dmesg[item[0]]['list'][item[1]]
	1607	+ if dev['pid'] == -2:
	1608	+ orderedlist.append(item)
	1609	+ for item in lenlist:
	1610	+ if item not in orderedlist:
	1611	+ orderedlist.append(item)
	1612	+ # try to pack each row with as many ranges as possible
	1613	+ while(remaining > 0):
	1614	+ rowheight = 1
	1615	+ if(row not in rowdata):
	1616	+ rowdata[row] = []
	1617	+ for item in orderedlist:
	1618	+ dev = dmesg[item[0]]['list'][item[1]]
	1619	+ if(dev['row'] < 0):
	1620	+ s = dev['start']
	1621	+ e = dev['end']
	1622	+ valid = True
	1623	+ for ritem in rowdata[row]:
	1624	+ rs = ritem['start']
	1625	+ re = ritem['end']
	1626	+ if(not (((s <= rs) and (e <= rs)) or
	1627	+ ((s >= re) and (e >= re)))):
	1628	+ valid = False
	1629	+ break
	1630	+ if(valid):
	1631	+ rowdata[row].append(dev)
	1632	+ dev['row'] = row
	1633	+ remaining -= 1
	1634	+ if 'devrows' in dev and dev['devrows'] > rowheight:
	1635	+ rowheight = dev['devrows']
	1636	+ for phase in myphases:
	1637	+ self.rowmaxlines[phase][row] = rowheight
	1638	+ self.rowheight[phase][row] = rowheight * self.rowH
	1639	+ row += 1
	1640	+ if(row > self.rows):
	1641	+ self.rows = int(row)
	1642	+ for phase in myphases:
	1643	+ self.rowcount[phase] = row
	1644	+ return row
	1645	+ def phaseRowHeight(self, phase, row):
	1646	+ return self.rowheight[phase][row]
	1647	+ def phaseRowTop(self, phase, row):
	1648	+ top = 0
	1649	+ for i in sorted(self.rowheight[phase]):
	1650	+ if i >= row:
	1651	+ break
	1652	+ top += self.rowheight[phase][i]
	1653	+ return top
	1654	+ # Function: calcTotalRows
	1655	+ # Description:
	1656	+ # Calculate the heights and offsets for the header and rows
	1657	+ def calcTotalRows(self):
	1658	+ maxrows = 0
	1659	+ standardphases = []
	1660	+ for phase in self.phases:
	1661	+ total = 0
	1662	+ for i in sorted(self.rowmaxlines[phase]):
	1663	+ total += self.rowmaxlines[phase][i]
	1664	+ if total > maxrows:
	1665	+ maxrows = total
	1666	+ if total == self.rowcount[phase]:
	1667	+ standardphases.append(phase)
	1668	+ self.height = self.scaleH + (maxrows*self.rowH)
	1669	+ self.bodyH = self.height - self.scaleH
	1670	+ for phase in standardphases:
	1671	+ for i in sorted(self.rowheight[phase]):
	1672	+ self.rowheight[phase][i] = self.bodyH/self.rowcount[phase]
	1673	+ # Function: createTimeScale
	1674	+ # Description:
	1675	+ # Create the timescale for a timeline block
	1676	+ # Arguments:
	1677	+ # m0: start time (mode begin)
	1678	+ # mMax: end time (mode end)
	1679	+ # tTotal: total timeline time
	1680	+ # mode: suspend or resume
	1681	+ # Output:
	1682	+ # The html code needed to display the time scale
	1683	+ def createTimeScale(self, m0, mMax, tTotal, mode):
	1684	+ timescale = '<div class="t" style="right:{0}%">{1}</div>\n'
	1685	+ rline = '<div class="t" style="left:0;border-left:1px solid black;border-right:0;">Resume</div>\n'
	1686	+ output = '<div class="timescale">\n'
	1687	+ # set scale for timeline
	1688	+ mTotal = mMax - m0
	1689	+ tS = 0.1
	1690	+ if(tTotal <= 0):
	1691	+ return output+'</div>\n'
	1692	+ if(tTotal > 4):
	1693	+ tS = 1
	1694	+ divTotal = int(mTotal/tS) + 1
	1695	+ divEdge = (mTotal - tS(divTotal-1))100/mTotal
	1696	+ for i in range(divTotal):
	1697	+ htmlline = ''
	1698	+ if(mode == 'resume'):
	1699	+ pos = '%0.3f' % (100 - ((float(i)tS100)/mTotal))
	1700	+ val = '%0.fms' % (float(i)tS1000)
	1701	+ htmlline = timescale.format(pos, val)
	1702	+ if(i == 0):
	1703	+ htmlline = rline
	1704	+ else:
	1705	+ pos = '%0.3f' % (100 - ((float(i)tS100)/mTotal) - divEdge)
	1706	+ val = '%0.fms' % (float(i-divTotal+1)tS1000)
	1707	+ if(i == divTotal - 1):
	1708	+ val = 'Suspend'
	1709	+ htmlline = timescale.format(pos, val)
	1710	+ output += htmlline
	1711	+ output += '</div>\n'
	1712	+ return output
845	1713
846		−# Class: TestRun
	1714	+# Class: TestProps
847	1715	# Description:
848		−# A container for a suspend/resume test run. This is necessary as
849		−# there could be more than one, and they need to be separate.
850		−class TestRun:
	1716	+# A list of values describing the properties of these test runs
	1717	+class TestProps:
	1718	+ stamp = ''
	1719	+ tracertype = ''
	1720	+ S0i3 = False
	1721	+ fwdata = []
851	1722	ftrace_line_fmt_fg = \
852	1723	'^ (?P<time>[0-9\.]) \\| (?P<cpu>[0-9]*)\)'+\
853	1724	' (?P<proc>.)-(?P<pid>[0-9]) \\|'+\
854		− '[ +!](?P<dur>[0-9\.]) .\\| (?P<msg>.)'
	1725	+ '[ +!#\@$](?P<dur>[0-9\.]) .\\| (?P<msg>.*)'
855	1726	ftrace_line_fmt_nop = \
856	1727	' (?P<proc>.)-(?P<pid>[0-9]) \[(?P<cpu>[0-9])\] '+\
857	1728	'(?P<flags>.{4}) (?P<time>[0-9\.]): *'+\
858	1729	'(?P<msg>.*)'
859	1730	ftrace_line_fmt = ftrace_line_fmt_nop
860	1731	cgformat = False
861		− ftemp = dict()
862		− ttemp = dict()
863		− inthepipe = False
864		− tracertype = ''
865	1732	data = 0
866		− def __init__(self, dataobj):
867		− self.data = dataobj
868		− self.ftemp = dict()
869		− self.ttemp = dict()
870		− def isReady(self):
871		− if(tracertype == '' or not data):
872		− return False
873		− return True
	1733	+ ktemp = dict()
	1734	+ def __init__(self):
	1735	+ self.ktemp = dict()
874	1736	def setTracerType(self, tracer):
875	1737	self.tracertype = tracer
876	1738	if(tracer == 'function_graph'):
@@ -881,6 +1743,19 @@ class TestRun: · 4 unmodified lines
881	1743	else:
882	1744	doError('Invalid tracer format: [%s]' % tracer, False)
883	1745
	1746	+# Class: TestRun
	1747	+# Description:
	1748	+# A container for a suspend/resume test run. This is necessary as
	1749	+# there could be more than one, and they need to be separate.
	1750	+class TestRun:
	1751	+ ftemp = dict()
	1752	+ ttemp = dict()
	1753	+ data = 0
	1754	+ def __init__(self, dataobj):
	1755	+ self.data = dataobj
	1756	+ self.ftemp = dict()
	1757	+ self.ttemp = dict()
	1758	+
884	1759	# ----------------- FUNCTIONS --------------------
885	1760
886	1761	# Function: vprint
@@ -893,104 +1768,16 @@ def vprint(msg): · 6 unmodified lines
893	1768	if(sysvals.verbose):
894	1769	print(msg)
895	1770
896		−# Function: initFtrace
897		−# Description:
898		−# Configure ftrace to use trace events and/or a callgraph
899		−def initFtrace():
900		− global sysvals
901		−
902		− tp = sysvals.tpath
903		− cf = 'dpm_run_callback'
904		− if(sysvals.usetraceeventsonly):
905		− cf = '-e dpm_prepare -e dpm_complete -e dpm_run_callback'
906		− if(sysvals.usecallgraph or sysvals.usetraceevents):
907		− print('INITIALIZING FTRACE...')
908		− # turn trace off
909		− os.system('echo 0 > '+tp+'tracing_on')
910		− # set the trace clock to global
911		− os.system('echo global > '+tp+'trace_clock')
912		− # set trace buffer to a huge value
913		− os.system('echo nop > '+tp+'current_tracer')
914		− os.system('echo 100000 > '+tp+'buffer_size_kb')
915		− # initialize the callgraph trace, unless this is an x2 run
916		− if(sysvals.usecallgraph and sysvals.execcount == 1):
917		− # set trace type
918		− os.system('echo function_graph > '+tp+'current_tracer')
919		− os.system('echo "" > '+tp+'set_ftrace_filter')
920		− # set trace format options
921		− os.system('echo funcgraph-abstime > '+tp+'trace_options')
922		− os.system('echo funcgraph-proc > '+tp+'trace_options')
923		− # focus only on device suspend and resume
924		− os.system('cat '+tp+'available_filter_functions \| grep '+\
925		− cf+' > '+tp+'set_graph_function')
926		− if(sysvals.usetraceevents):
927		− # turn trace events on
928		− events = iter(sysvals.traceevents)
929		− for e in events:
930		− os.system('echo 1 > '+sysvals.epath+e+'/enable')
931		− # clear the trace buffer
932		− os.system('echo "" > '+tp+'trace')
933		−
934		−# Function: initFtraceAndroid
935		−# Description:
936		−# Configure ftrace to capture trace events
937		−def initFtraceAndroid():
938		− global sysvals
939		−
940		− tp = sysvals.tpath
941		− if(sysvals.usetraceevents):
942		− print('INITIALIZING FTRACE...')
943		− # turn trace off
944		− os.system(sysvals.adb+" shell 'echo 0 > "+tp+"tracing_on'")
945		− # set the trace clock to global
946		− os.system(sysvals.adb+" shell 'echo global > "+tp+"trace_clock'")
947		− # set trace buffer to a huge value
948		− os.system(sysvals.adb+" shell 'echo nop > "+tp+"current_tracer'")
949		− os.system(sysvals.adb+" shell 'echo 10000 > "+tp+"buffer_size_kb'")
950		− # turn trace events on
951		− events = iter(sysvals.traceevents)
952		− for e in events:
953		− os.system(sysvals.adb+" shell 'echo 1 > "+\
954		− sysvals.epath+e+"/enable'")
955		− # clear the trace buffer
956		− os.system(sysvals.adb+" shell 'echo \"\" > "+tp+"trace'")
957		−
958		−# Function: verifyFtrace
959		−# Description:
960		−# Check that ftrace is working on the system
961		−# Output:
962		−# True or False
963		−def verifyFtrace():
964		− global sysvals
965		− # files needed for any trace data
966		− files = ['buffer_size_kb', 'current_tracer', 'trace', 'trace_clock',
967		− 'trace_marker', 'trace_options', 'tracing_on']
968		− # files needed for callgraph trace data
969		− tp = sysvals.tpath
970		− if(sysvals.usecallgraph):
971		− files += [
972		− 'available_filter_functions',
973		− 'set_ftrace_filter',
974		− 'set_graph_function'
975		− ]
976		− for f in files:
977		− if(sysvals.android):
978		− out = os.popen(sysvals.adb+' shell ls '+tp+f).read().strip()
979		− if(out != tp+f):
980		− return False
981		− else:
982		− if(os.path.exists(tp+f) == False):
983		− return False
984		− return True
985		−
986	1771	# Function: parseStamp
987	1772	# Description:
988	1773	# Pull in the stamp comment line from the data file(s),
989	1774	# create the stamp, and add it to the global sysvals object
990	1775	# Arguments:
991	1776	# m: the valid re.match output for the stamp line
992		−def parseStamp(m, data):
	1777	+def parseStamp(line, data):
993	1778	global sysvals
	1779	+
	1780	+ m = re.match(sysvals.stampfmt, line)
994	1781	data.stamp = {'time': '', 'host': '', 'mode': ''}
995	1782	dt = datetime(int(m.group('y'))+2000, int(m.group('m')),
996	1783	int(m.group('d')), int(m.group('H')), int(m.group('M')),
@@ -999,6 +1786,7 @@ def parseStamp(m, data): · 2 unmodified lines
999	1786	data.stamp['host'] = m.group('host')
1000	1787	data.stamp['mode'] = m.group('mode')
1001	1788	data.stamp['kernel'] = m.group('kernel')
	1789	+ sysvals.hostname = data.stamp['host']
1002	1790	sysvals.suspendmode = data.stamp['mode']
1003	1791	if not sysvals.stamp:
1004	1792	sysvals.stamp = data.stamp
@@ -1031,14 +1819,35 @@ def diffStamp(stamp1, stamp2): · 26 unmodified lines
1031	1819	def doesTraceLogHaveTraceEvents():
1032	1820	global sysvals
1033	1821
	1822	+ # check for kprobes
	1823	+ sysvals.usekprobes = False
	1824	+ out = os.system('grep -q "_cal: (" '+sysvals.ftracefile)
	1825	+ if(out == 0):
	1826	+ sysvals.usekprobes = True
	1827	+ # check for callgraph data on trace event blocks
	1828	+ out = os.system('grep -q "_cpu_down()" '+sysvals.ftracefile)
	1829	+ if(out == 0):
	1830	+ sysvals.usekprobes = True
	1831	+ out = os.popen('head -1 '+sysvals.ftracefile).read().replace('\n', '')
	1832	+ m = re.match(sysvals.stampfmt, out)
	1833	+ if m and m.group('mode') == 'command':
	1834	+ sysvals.usetraceeventsonly = True
	1835	+ sysvals.usetraceevents = True
	1836	+ return
	1837	+ # figure out what level of trace events are supported
1034	1838	sysvals.usetraceeventsonly = True
1035	1839	sysvals.usetraceevents = False
1036	1840	for e in sysvals.traceevents:
1037		− out = os.popen('cat '+sysvals.ftracefile+' \| grep "'+e+': "').read()
1038		− if(not out):
	1841	+ out = os.system('grep -q "'+e+': " '+sysvals.ftracefile)
	1842	+ if(out != 0):
1039	1843	sysvals.usetraceeventsonly = False
1040		− if(e == 'suspend_resume' and out):
	1844	+ if(e == 'suspend_resume' and out == 0):
1041	1845	sysvals.usetraceevents = True
	1846	+ # determine is this log is properly formatted
	1847	+ for e in ['SUSPEND START', 'RESUME COMPLETE']:
	1848	+ out = os.system('grep -q "'+e+'" '+sysvals.ftracefile)
	1849	+ if(out != 0):
	1850	+ sysvals.usetracemarkers = False
1042	1851
1043	1852	# Function: appendIncompleteTraceLog
1044	1853	# Description:
@@ -1055,44 +1864,42 @@ def appendIncompleteTraceLog(testruns): · 10 unmodified lines
1055	1864
1056	1865	# create TestRun vessels for ftrace parsing
1057	1866	testcnt = len(testruns)
1058		− testidx = -1
	1867	+ testidx = 0
1059	1868	testrun = []
1060	1869	for data in testruns:
1061	1870	testrun.append(TestRun(data))
1062	1871
1063	1872	# extract the callgraph and traceevent data
1064	1873	vprint('Analyzing the ftrace data...')
	1874	+ tp = TestProps()
1065	1875	tf = open(sysvals.ftracefile, 'r')
	1876	+ data = 0
1066	1877	for line in tf:
1067	1878	# remove any latent carriage returns
1068	1879	line = line.replace('\r\n', '')
1069		− # grab the time stamp first (signifies the start of the test run)
	1880	+ # grab the time stamp
1070	1881	m = re.match(sysvals.stampfmt, line)
1071	1882	if(m):
1072		− testidx += 1
1073		− parseStamp(m, testrun[testidx].data)
1074		− continue
1075		− # pull out any firmware data
1076		− if(re.match(sysvals.firmwarefmt, line)):
1077		− continue
1078		− # if we havent found a test time stamp yet keep spinning til we do
1079		− if(testidx < 0):
	1883	+ tp.stamp = line
1080	1884	continue
1081	1885	# determine the trace data type (required for further parsing)
1082	1886	m = re.match(sysvals.tracertypefmt, line)
1083	1887	if(m):
1084		− tracer = m.group('t')
1085		− testrun[testidx].setTracerType(tracer)
	1888	+ tp.setTracerType(m.group('t'))
	1889	+ continue
	1890	+ # device properties line
	1891	+ if(re.match(sysvals.devpropfmt, line)):
	1892	+ devProps(line)
1086	1893	continue
1087		− # parse only valid lines, if this isnt one move on
1088		− m = re.match(testrun[testidx].ftrace_line_fmt, line)
	1894	+ # parse only valid lines, if this is not one move on
	1895	+ m = re.match(tp.ftrace_line_fmt, line)
1089	1896	if(not m):
1090	1897	continue
1091	1898	# gather the basic message data from the line
1092	1899	m_time = m.group('time')
1093	1900	m_pid = m.group('pid')
1094	1901	m_msg = m.group('msg')
1095		− if(testrun[testidx].cgformat):
	1902	+ if(tp.cgformat):
1096	1903	m_param3 = m.group('dur')
1097	1904	else:
1098	1905	m_param3 = 'traceevent'
@@ -1104,119 +1911,114 @@ def appendIncompleteTraceLog(testruns): · 5 unmodified lines
1104	1911	# the line should be a call, return, or event
1105	1912	if(not t.fcall and not t.freturn and not t.fevent):
1106	1913	continue
1107		− # only parse the ftrace data during suspend/resume
1108		− data = testrun[testidx].data
1109		− if(not testrun[testidx].inthepipe):
1110		− # look for the suspend start marker
1111		− if(t.fevent):
1112		− if(t.name == 'SUSPEND START'):
1113		− testrun[testidx].inthepipe = True
1114		− data.setStart(t.time)
	1914	+ # look for the suspend start marker
	1915	+ if(t.startMarker()):
	1916	+ data = testrun[testidx].data
	1917	+ parseStamp(tp.stamp, data)
	1918	+ data.setStart(t.time)
	1919	+ continue
	1920	+ if(not data):
	1921	+ continue
	1922	+ # find the end of resume
	1923	+ if(t.endMarker()):
	1924	+ data.setEnd(t.time)
	1925	+ testidx += 1
	1926	+ if(testidx >= testcnt):
	1927	+ break
	1928	+ continue
	1929	+ # trace event processing
	1930	+ if(t.fevent):
	1931	+ # general trace events have two types, begin and end
	1932	+ if(re.match('(?P<name>.*) begin$', t.name)):
	1933	+ isbegin = True
	1934	+ elif(re.match('(?P<name>.*) end$', t.name)):
	1935	+ isbegin = False
	1936	+ else:
1115	1937	continue
1116		− else:
1117		− # trace event processing
1118		− if(t.fevent):
1119		− if(t.name == 'RESUME COMPLETE'):
1120		− testrun[testidx].inthepipe = False
1121		− data.setEnd(t.time)
1122		− if(testidx == testcnt - 1):
1123		− break
1124		− continue
1125		− # general trace events have two types, begin and end
1126		− if(re.match('(?P<name>.*) begin$', t.name)):
1127		− isbegin = True
1128		− elif(re.match('(?P<name>.*) end$', t.name)):
1129		− isbegin = False
	1938	+ m = re.match('(?P<name>.)\[(?P<val>[0-9])\] .*', t.name)
	1939	+ if(m):
	1940	+ val = m.group('val')
	1941	+ if val == '0':
	1942	+ name = m.group('name')
1130	1943	else:
1131		− continue
1132		− m = re.match('(?P<name>.)\[(?P<val>[0-9])\] .*', t.name)
1133		− if(m):
1134		− val = m.group('val')
1135		− if val == '0':
1136		− name = m.group('name')
1137		− else:
1138		− name = m.group('name')+'['+val+']'
	1944	+ name = m.group('name')+'['+val+']'
	1945	+ else:
	1946	+ m = re.match('(?P<name>.) .', t.name)
	1947	+ name = m.group('name')
	1948	+ # special processing for trace events
	1949	+ if re.match('dpm_prepare\[.*', name):
	1950	+ continue
	1951	+ elif re.match('machine_suspend.*', name):
	1952	+ continue
	1953	+ elif re.match('suspend_enter\[.*', name):
	1954	+ if(not isbegin):
	1955	+ data.dmesg['suspend_prepare']['end'] = t.time
	1956	+ continue
	1957	+ elif re.match('dpm_suspend\[.*', name):
	1958	+ if(not isbegin):
	1959	+ data.dmesg['suspend']['end'] = t.time
	1960	+ continue
	1961	+ elif re.match('dpm_suspend_late\[.*', name):
	1962	+ if(isbegin):
	1963	+ data.dmesg['suspend_late']['start'] = t.time
1139	1964	else:
1140		− m = re.match('(?P<name>.) .', t.name)
1141		− name = m.group('name')
1142		− # special processing for trace events
1143		− if re.match('dpm_prepare\[.*', name):
1144		− continue
1145		− elif re.match('machine_suspend.*', name):
1146		− continue
1147		− elif re.match('suspend_enter\[.*', name):
1148		− if(not isbegin):
1149		− data.dmesg['suspend_prepare']['end'] = t.time
1150		− continue
1151		− elif re.match('dpm_suspend\[.*', name):
1152		− if(not isbegin):
1153		− data.dmesg['suspend']['end'] = t.time
1154		− continue
1155		− elif re.match('dpm_suspend_late\[.*', name):
1156		− if(isbegin):
1157		− data.dmesg['suspend_late']['start'] = t.time
1158		− else:
1159		− data.dmesg['suspend_late']['end'] = t.time
1160		− continue
1161		− elif re.match('dpm_suspend_noirq\[.*', name):
1162		− if(isbegin):
1163		− data.dmesg['suspend_noirq']['start'] = t.time
1164		− else:
1165		− data.dmesg['suspend_noirq']['end'] = t.time
1166		− continue
1167		− elif re.match('dpm_resume_noirq\[.*', name):
1168		− if(isbegin):
1169		− data.dmesg['resume_machine']['end'] = t.time
1170		− data.dmesg['resume_noirq']['start'] = t.time
1171		− else:
1172		− data.dmesg['resume_noirq']['end'] = t.time
1173		− continue
1174		− elif re.match('dpm_resume_early\[.*', name):
1175		− if(isbegin):
1176		− data.dmesg['resume_early']['start'] = t.time
1177		− else:
1178		− data.dmesg['resume_early']['end'] = t.time
1179		− continue
1180		− elif re.match('dpm_resume\[.*', name):
1181		− if(isbegin):
1182		− data.dmesg['resume']['start'] = t.time
1183		− else:
1184		− data.dmesg['resume']['end'] = t.time
1185		− continue
1186		− elif re.match('dpm_complete\[.*', name):
1187		− if(isbegin):
1188		− data.dmesg['resume_complete']['start'] = t.time
1189		− else:
1190		− data.dmesg['resume_complete']['end'] = t.time
1191		− continue
1192		− # is this trace event outside of the devices calls
1193		− if(data.isTraceEventOutsideDeviceCalls(pid, t.time)):
1194		− # global events (outside device calls) are simply graphed
1195		− if(isbegin):
1196		− # store each trace event in ttemp
1197		− if(name not in testrun[testidx].ttemp):
1198		− testrun[testidx].ttemp[name] = []
1199		− testrun[testidx].ttemp[name].append(\
1200		− {'begin': t.time, 'end': t.time})
1201		− else:
1202		− # finish off matching trace event in ttemp
1203		− if(name in testrun[testidx].ttemp):
1204		− testrun[testidx].ttemp[name][-1]['end'] = t.time
	1965	+ data.dmesg['suspend_late']['end'] = t.time
	1966	+ continue
	1967	+ elif re.match('dpm_suspend_noirq\[.*', name):
	1968	+ if(isbegin):
	1969	+ data.dmesg['suspend_noirq']['start'] = t.time
1205	1970	else:
1206		− if(isbegin):
1207		− data.addIntraDevTraceEvent('', name, pid, t.time)
1208		− else:
1209		− data.capIntraDevTraceEvent('', name, pid, t.time)
1210		− # call/return processing
1211		− elif sysvals.usecallgraph:
1212		− # create a callgraph object for the data
1213		− if(pid not in testrun[testidx].ftemp):
1214		− testrun[testidx].ftemp[pid] = []
1215		− testrun[testidx].ftemp[pid].append(FTraceCallGraph())
1216		− # when the call is finished, see which device matches it
1217		− cg = testrun[testidx].ftemp[pid][-1]
1218		− if(cg.addLine(t, m)):
1219		− testrun[testidx].ftemp[pid].append(FTraceCallGraph())
	1971	+ data.dmesg['suspend_noirq']['end'] = t.time
	1972	+ continue
	1973	+ elif re.match('dpm_resume_noirq\[.*', name):
	1974	+ if(isbegin):
	1975	+ data.dmesg['resume_machine']['end'] = t.time
	1976	+ data.dmesg['resume_noirq']['start'] = t.time
	1977	+ else:
	1978	+ data.dmesg['resume_noirq']['end'] = t.time
	1979	+ continue
	1980	+ elif re.match('dpm_resume_early\[.*', name):
	1981	+ if(isbegin):
	1982	+ data.dmesg['resume_early']['start'] = t.time
	1983	+ else:
	1984	+ data.dmesg['resume_early']['end'] = t.time
	1985	+ continue
	1986	+ elif re.match('dpm_resume\[.*', name):
	1987	+ if(isbegin):
	1988	+ data.dmesg['resume']['start'] = t.time
	1989	+ else:
	1990	+ data.dmesg['resume']['end'] = t.time
	1991	+ continue
	1992	+ elif re.match('dpm_complete\[.*', name):
	1993	+ if(isbegin):
	1994	+ data.dmesg['resume_complete']['start'] = t.time
	1995	+ else:
	1996	+ data.dmesg['resume_complete']['end'] = t.time
	1997	+ continue
	1998	+ # skip trace events inside devices calls
	1999	+ if(not data.isTraceEventOutsideDeviceCalls(pid, t.time)):
	2000	+ continue
	2001	+ # global events (outside device calls) are simply graphed
	2002	+ if(isbegin):
	2003	+ # store each trace event in ttemp
	2004	+ if(name not in testrun[testidx].ttemp):
	2005	+ testrun[testidx].ttemp[name] = []
	2006	+ testrun[testidx].ttemp[name].append(\
	2007	+ {'begin': t.time, 'end': t.time})
	2008	+ else:
	2009	+ # finish off matching trace event in ttemp
	2010	+ if(name in testrun[testidx].ttemp):
	2011	+ testrun[testidx].ttemp[name][-1]['end'] = t.time
	2012	+ # call/return processing
	2013	+ elif sysvals.usecallgraph:
	2014	+ # create a callgraph object for the data
	2015	+ if(pid not in testrun[testidx].ftemp):
	2016	+ testrun[testidx].ftemp[pid] = []
	2017	+ testrun[testidx].ftemp[pid].append(FTraceCallGraph(pid))
	2018	+ # when the call is finished, see which device matches it
	2019	+ cg = testrun[testidx].ftemp[pid][-1]
	2020	+ if(cg.addLine(t)):
	2021	+ testrun[testidx].ftemp[pid].append(FTraceCallGraph(pid))
1220	2022	tf.close()
1221	2023
1222	2024	for test in testrun:
@@ -1224,20 +2026,14 @@ def appendIncompleteTraceLog(testruns): · 1 unmodified line
1224	2026	if(sysvals.usetraceevents):
1225	2027	for name in test.ttemp:
1226	2028	for event in test.ttemp[name]:
1227		− begin = event['begin']
1228		− end = event['end']
1229		− # if event starts before timeline start, expand timeline
1230		− if(begin < test.data.start):
1231		− test.data.setStart(begin)
1232		− # if event ends after timeline end, expand the timeline
1233		− if(end > test.data.end):
1234		− test.data.setEnd(end)
1235		− test.data.newActionGlobal(name, begin, end)
	2029	+ test.data.newActionGlobal(name, event['begin'], event['end'])
1236	2030
1237	2031	# add the callgraph data to the device hierarchy
1238	2032	for pid in test.ftemp:
1239	2033	for cg in test.ftemp[pid]:
1240		− if(not cg.sanityCheck()):
	2034	+ if len(cg.list) < 1 or cg.invalid:
	2035	+ continue
	2036	+ if(not cg.postProcess()):
1241	2037	id = 'task %s cpu %s' % (pid, m.group('cpu'))
1242	2038	vprint('Sanity check failed for '+\
1243	2039	id+', ignoring this callback')
@@ -1259,14 +2055,6 @@ def appendIncompleteTraceLog(testruns): · 15 unmodified lines
1259	2055	if(sysvals.verbose):
1260	2056	test.data.printDetails()
1261	2057
1262		−
1263		− # add the time in between the tests as a new phase so we can see it
1264		− if(len(testruns) > 1):
1265		− t1e = testruns[0].getEnd()
1266		− t2s = testruns[-1].getStart()
1267		− testruns[-1].newPhaseWithSingleAction('user mode', \
1268		− 'user mode', t1e, t2s, '#FF9966')
1269		−
1270	2058	# Function: parseTraceLog
1271	2059	# Description:
1272	2060	# Analyze an ftrace log output file generated from this app during
@@ -1280,9 +2068,16 @@ def parseTraceLog(): · 7 unmodified lines
1280	2068
1281	2069	vprint('Analyzing the ftrace data...')
1282	2070	if(os.path.exists(sysvals.ftracefile) == False):
1283		− doError('%s doesnt exist' % sysvals.ftracefile, False)
	2071	+ doError('%s does not exist' % sysvals.ftracefile, False)
	2072	+
	2073	+ sysvals.setupAllKprobes()
	2074	+ tracewatch = ['suspend_enter']
	2075	+ if sysvals.usekprobes:
	2076	+ tracewatch += ['sync_filesystems', 'freeze_processes', 'syscore_suspend',
	2077	+ 'syscore_resume', 'resume_console', 'thaw_processes', 'CPU_ON', 'CPU_OFF']
1284	2078
1285	2079	# extract the callgraph and traceevent data
	2080	+ tp = TestProps()
1286	2081	testruns = []
1287	2082	testdata = []
1288	2083	testrun = 0
@@ -1295,27 +2090,17 @@ def parseTraceLog(): · 6 unmodified lines
1295	2090	# stamp line: each stamp means a new test run
1296	2091	m = re.match(sysvals.stampfmt, line)
1297	2092	if(m):
1298		− data = Data(len(testdata))
1299		− testdata.append(data)
1300		− testrun = TestRun(data)
1301		− testruns.append(testrun)
1302		− parseStamp(m, data)
1303		− continue
1304		− if(not data):
	2093	+ tp.stamp = line
1305	2094	continue
1306	2095	# firmware line: pull out any firmware data
1307	2096	m = re.match(sysvals.firmwarefmt, line)
1308	2097	if(m):
1309		− data.fwSuspend = int(m.group('s'))
1310		− data.fwResume = int(m.group('r'))
1311		− if(data.fwSuspend > 0 or data.fwResume > 0):
1312		− data.fwValid = True
	2098	+ tp.fwdata.append((int(m.group('s')), int(m.group('r'))))
1313	2099	continue
1314	2100	# tracer type line: determine the trace data type
1315	2101	m = re.match(sysvals.tracertypefmt, line)
1316	2102	if(m):
1317		− tracer = m.group('t')
1318		− testrun.setTracerType(tracer)
	2103	+ tp.setTracerType(m.group('t'))
1319	2104	continue
1320	2105	# post resume time line: did this test run include post-resume data
1321	2106	m = re.match(sysvals.postresumefmt, line)
@@ -1324,15 +2109,20 @@ def parseTraceLog(): · 2 unmodified lines
1324	2109	if(t > 0):
1325	2110	sysvals.postresumetime = t
1326	2111	continue
	2112	+ # device properties line
	2113	+ if(re.match(sysvals.devpropfmt, line)):
	2114	+ devProps(line)
	2115	+ continue
1327	2116	# ftrace line: parse only valid lines
1328		− m = re.match(testrun.ftrace_line_fmt, line)
	2117	+ m = re.match(tp.ftrace_line_fmt, line)
1329	2118	if(not m):
1330	2119	continue
1331	2120	# gather the basic message data from the line
1332	2121	m_time = m.group('time')
	2122	+ m_proc = m.group('proc')
1333	2123	m_pid = m.group('pid')
1334	2124	m_msg = m.group('msg')
1335		− if(testrun.cgformat):
	2125	+ if(tp.cgformat):
1336	2126	m_param3 = m.group('dur')
1337	2127	else:
1338	2128	m_param3 = 'traceevent'
@@ -1344,24 +2134,38 @@ def parseTraceLog(): · 5 unmodified lines
1344	2134	# the line should be a call, return, or event
1345	2135	if(not t.fcall and not t.freturn and not t.fevent):
1346	2136	continue
1347		− # only parse the ftrace data during suspend/resume
1348		− if(not testrun.inthepipe):
1349		− # look for the suspend start marker
1350		− if(t.fevent):
1351		− if(t.name == 'SUSPEND START'):
1352		− testrun.inthepipe = True
1353		− data.setStart(t.time)
	2137	+ # find the start of suspend
	2138	+ if(t.startMarker()):
	2139	+ phase = 'suspend_prepare'
	2140	+ data = Data(len(testdata))
	2141	+ testdata.append(data)
	2142	+ testrun = TestRun(data)
	2143	+ testruns.append(testrun)
	2144	+ parseStamp(tp.stamp, data)
	2145	+ if len(tp.fwdata) > data.testnumber:
	2146	+ data.fwSuspend, data.fwResume = tp.fwdata[data.testnumber]
	2147	+ if(data.fwSuspend > 0 or data.fwResume > 0):
	2148	+ data.fwValid = True
	2149	+ data.setStart(t.time)
	2150	+ continue
	2151	+ if(not data):
	2152	+ continue
	2153	+ # find the end of resume
	2154	+ if(t.endMarker()):
	2155	+ if(sysvals.usetracemarkers and sysvals.postresumetime > 0):
	2156	+ phase = 'post_resume'
	2157	+ data.newPhase(phase, t.time, t.time, '#F0F0F0', -1)
	2158	+ data.setEnd(t.time)
	2159	+ if(not sysvals.usetracemarkers):
	2160	+ # no trace markers? then quit and be sure to finish recording
	2161	+ # the event we used to trigger resume end
	2162	+ if(len(testrun.ttemp['thaw_processes']) > 0):
	2163	+ # if an entry exists, assume this is its end
	2164	+ testrun.ttemp['thaw_processes'][-1]['end'] = t.time
	2165	+ break
1354	2166	continue
1355	2167	# trace event processing
1356	2168	if(t.fevent):
1357		− if(t.name == 'RESUME COMPLETE'):
1358		− if(sysvals.postresumetime > 0):
1359		− phase = 'post_resume'
1360		− data.newPhase(phase, t.time, t.time, '#FF9966', -1)
1361		− else:
1362		− testrun.inthepipe = False
1363		− data.setEnd(t.time)
1364		− continue
1365	2169	if(phase == 'post_resume'):
1366	2170	data.setEnd(t.time)
1367	2171	if(t.type == 'suspend_resume'):
@@ -1383,8 +2187,7 @@ def parseTraceLog(): · 15 unmodified lines
1383	2187	m = re.match('(?P<name>.) .', t.name)
1384	2188	name = m.group('name')
1385	2189	# ignore these events
1386		− if(re.match('acpi_suspend\[.*', t.name) or
1387		− re.match('suspend_enter\[.*', name)):
	2190	+ if(name.split('[')[0] in tracewatch):
1388	2191	continue
1389	2192	# -- phase changes --
1390	2193	# suspend_prepare start
@@ -1418,7 +2221,7 @@ def parseTraceLog(): · 27 unmodified lines
1418	2221	data.dmesg[phase]['end'] = t.time
1419	2222	data.tSuspended = t.time
1420	2223	else:
1421		− if(sysvals.suspendmode in ['mem', 'disk']):
	2224	+ if(sysvals.suspendmode in ['mem', 'disk'] and not tp.S0i3):
1422	2225	data.dmesg['suspend_machine']['end'] = t.time
1423	2226	data.tSuspended = t.time
1424	2227	phase = 'resume_machine'
@@ -1426,6 +2229,15 @@ def parseTraceLog(): · 1 unmodified line
1426	2229	data.tResumed = t.time
1427	2230	data.tLow = data.tResumed - data.tSuspended
1428	2231	continue
	2232	+ # acpi_suspend
	2233	+ elif(re.match('acpi_suspend\[.*', t.name)):
	2234	+ # acpi_suspend[0] S0i3
	2235	+ if(re.match('acpi_suspend\[0\] begin', t.name)):
	2236	+ if(sysvals.suspendmode == 'mem'):
	2237	+ tp.S0i3 = True
	2238	+ data.dmesg['suspend_machine']['end'] = t.time
	2239	+ data.tSuspended = t.time
	2240	+ continue
1429	2241	# resume_noirq start
1430	2242	elif(re.match('dpm_resume_noirq\[.*', t.name)):
1431	2243	phase = 'resume_noirq'
@@ -1449,30 +2261,25 @@ def parseTraceLog(): · 17 unmodified lines
1449	2261	if(isbegin):
1450	2262	data.dmesg[phase]['start'] = t.time
1451	2263	continue
1452		−
1453		− # is this trace event outside of the devices calls
1454		− if(data.isTraceEventOutsideDeviceCalls(pid, t.time)):
1455		− # global events (outside device calls) are simply graphed
1456		− if(name not in testrun.ttemp):
1457		− testrun.ttemp[name] = []
1458		− if(isbegin):
1459		− # create a new list entry
1460		− testrun.ttemp[name].append(\
1461		− {'begin': t.time, 'end': t.time})
1462		− else:
1463		− if(len(testrun.ttemp[name]) > 0):
1464		− # if an antry exists, assume this is its end
1465		− testrun.ttemp[name][-1]['end'] = t.time
1466		− elif(phase == 'post_resume'):
1467		− # post resume events can just have ends
1468		− testrun.ttemp[name].append({
1469		− 'begin': data.dmesg[phase]['start'],
1470		− 'end': t.time})
	2264	+ # skip trace events inside devices calls
	2265	+ if(not data.isTraceEventOutsideDeviceCalls(pid, t.time)):
	2266	+ continue
	2267	+ # global events (outside device calls) are graphed
	2268	+ if(name not in testrun.ttemp):
	2269	+ testrun.ttemp[name] = []
	2270	+ if(isbegin):
	2271	+ # create a new list entry
	2272	+ testrun.ttemp[name].append(\
	2273	+ {'begin': t.time, 'end': t.time, 'pid': pid})
1471	2274	else:
1472		− if(isbegin):
1473		− data.addIntraDevTraceEvent('', name, pid, t.time)
1474		− else:
1475		− data.capIntraDevTraceEvent('', name, pid, t.time)
	2275	+ if(len(testrun.ttemp[name]) > 0):
	2276	+ # if an entry exists, assume this is its end
	2277	+ testrun.ttemp[name][-1]['end'] = t.time
	2278	+ elif(phase == 'post_resume'):
	2279	+ # post resume events can just have ends
	2280	+ testrun.ttemp[name].append({
	2281	+ 'begin': data.dmesg[phase]['start'],
	2282	+ 'end': t.time})
1476	2283	# device callback start
1477	2284	elif(t.type == 'device_pm_callback_start'):
1478	2285	m = re.match('(?P<drv>.) (?P<d>.), parent: (?P<p>.), .*',\
@@ -1495,75 +2302,127 @@ def parseTraceLog(): · 16 unmodified lines
1495	2302	dev = list[n]
1496	2303	dev['length'] = t.time - dev['start']
1497	2304	dev['end'] = t.time
	2305	+ # kprobe event processing
	2306	+ elif(t.fkprobe):
	2307	+ kprobename = t.type
	2308	+ kprobedata = t.name
	2309	+ key = (kprobename, pid)
	2310	+ # displayname is generated from kprobe data
	2311	+ displayname = ''
	2312	+ if(t.fcall):
	2313	+ displayname = sysvals.kprobeDisplayName(kprobename, kprobedata)
	2314	+ if not displayname:
	2315	+ continue
	2316	+ if(key not in tp.ktemp):
	2317	+ tp.ktemp[key] = []
	2318	+ tp.ktemp[key].append({
	2319	+ 'pid': pid,
	2320	+ 'begin': t.time,
	2321	+ 'end': t.time,
	2322	+ 'name': displayname,
	2323	+ 'cdata': kprobedata,
	2324	+ 'proc': m_proc,
	2325	+ })
	2326	+ elif(t.freturn):
	2327	+ if(key not in tp.ktemp) or len(tp.ktemp[key]) < 1:
	2328	+ continue
	2329	+ e = tp.ktemp[key][-1]
	2330	+ if e['begin'] < 0.0 or t.time - e['begin'] < 0.000001:
	2331	+ tp.ktemp[key].pop()
	2332	+ else:
	2333	+ e['end'] = t.time
	2334	+ e['rdata'] = kprobedata
1498	2335	# callgraph processing
1499	2336	elif sysvals.usecallgraph:
1500		− # this shouldn't happen, but JIC, ignore callgraph data post-res
1501		− if(phase == 'post_resume'):
1502		− continue
1503	2337	# create a callgraph object for the data
1504		− if(pid not in testrun.ftemp):
1505		− testrun.ftemp[pid] = []
1506		− testrun.ftemp[pid].append(FTraceCallGraph())
	2338	+ key = (m_proc, pid)
	2339	+ if(key not in testrun.ftemp):
	2340	+ testrun.ftemp[key] = []
	2341	+ testrun.ftemp[key].append(FTraceCallGraph(pid))
1507	2342	# when the call is finished, see which device matches it
1508		− cg = testrun.ftemp[pid][-1]
1509		− if(cg.addLine(t, m)):
1510		− testrun.ftemp[pid].append(FTraceCallGraph())
	2343	+ cg = testrun.ftemp[key][-1]
	2344	+ if(cg.addLine(t)):
	2345	+ testrun.ftemp[key].append(FTraceCallGraph(pid))
1511	2346	tf.close()
1512	2347
	2348	+ if sysvals.suspendmode == 'command':
	2349	+ for test in testruns:
	2350	+ for p in test.data.phases:
	2351	+ if p == 'resume_complete':
	2352	+ test.data.dmesg[p]['start'] = test.data.start
	2353	+ test.data.dmesg[p]['end'] = test.data.end
	2354	+ else:
	2355	+ test.data.dmesg[p]['start'] = test.data.start
	2356	+ test.data.dmesg[p]['end'] = test.data.start
	2357	+ test.data.tSuspended = test.data.start
	2358	+ test.data.tResumed = test.data.start
	2359	+ test.data.tLow = 0
	2360	+ test.data.fwValid = False
	2361	+
1513	2362	for test in testruns:
1514	2363	# add the traceevent data to the device hierarchy
1515	2364	if(sysvals.usetraceevents):
	2365	+ # add actual trace funcs
1516	2366	for name in test.ttemp:
1517	2367	for event in test.ttemp[name]:
1518		− begin = event['begin']
1519		− end = event['end']
1520		− # if event starts before timeline start, expand timeline
1521		− if(begin < test.data.start):
1522		− test.data.setStart(begin)
1523		− # if event ends after timeline end, expand the timeline
1524		− if(end > test.data.end):
1525		− test.data.setEnd(end)
1526		− test.data.newActionGlobal(name, begin, end)
1527		−
1528		− # add the callgraph data to the device hierarchy
1529		− borderphase = {
1530		− 'dpm_prepare': 'suspend_prepare',
1531		− 'dpm_complete': 'resume_complete'
1532		− }
1533		− for pid in test.ftemp:
1534		− for cg in test.ftemp[pid]:
1535		− if len(cg.list) < 2:
	2368	+ test.data.newActionGlobal(name, event['begin'], event['end'], event['pid'])
	2369	+ # add the kprobe based virtual tracefuncs as actual devices
	2370	+ for key in tp.ktemp:
	2371	+ name, pid = key
	2372	+ if name not in sysvals.tracefuncs:
1536	2373	continue
1537		− if(not cg.sanityCheck()):
1538		− id = 'task %s cpu %s' % (pid, m.group('cpu'))
1539		− vprint('Sanity check failed for '+\
1540		− id+', ignoring this callback')
1541		− continue
1542		− callstart = cg.start
1543		− callend = cg.end
1544		− if(cg.list[0].name in borderphase):
1545		− p = borderphase[cg.list[0].name]
1546		− list = test.data.dmesg[p]['list']
1547		− for devname in list:
1548		− dev = list[devname]
1549		− if(pid == dev['pid'] and
1550		− callstart <= dev['start'] and
1551		− callend >= dev['end']):
1552		− dev['ftrace'] = cg.slice(dev['start'], dev['end'])
1553		− continue
1554		− if(cg.list[0].name != 'dpm_run_callback'):
	2374	+ for e in tp.ktemp[key]:
	2375	+ kb, ke = e['begin'], e['end']
	2376	+ if kb == ke or not test.data.isInsideTimeline(kb, ke):
	2377	+ continue
	2378	+ test.data.newActionGlobal(e['name'], kb, ke, pid)
	2379	+ # add config base kprobes and dev kprobes
	2380	+ for key in tp.ktemp:
	2381	+ name, pid = key
	2382	+ if name in sysvals.tracefuncs:
1555	2383	continue
1556		− for p in test.data.phases:
1557		− if(test.data.dmesg[p]['start'] <= callstart and
1558		− callstart <= test.data.dmesg[p]['end']):
1559		− list = test.data.dmesg[p]['list']
1560		− for devname in list:
1561		− dev = list[devname]
1562		− if(pid == dev['pid'] and
1563		− callstart <= dev['start'] and
1564		− callend >= dev['end']):
1565		− dev['ftrace'] = cg
1566		− break
	2384	+ for e in tp.ktemp[key]:
	2385	+ kb, ke = e['begin'], e['end']
	2386	+ if kb == ke or not test.data.isInsideTimeline(kb, ke):
	2387	+ continue
	2388	+ color = sysvals.kprobeColor(e['name'])
	2389	+ if name not in sysvals.dev_tracefuncs:
	2390	+ # config base kprobe
	2391	+ test.data.newActionGlobal(e['name'], kb, ke, -2, color)
	2392	+ elif sysvals.usedevsrc:
	2393	+ # dev kprobe
	2394	+ data.addDeviceFunctionCall(e['name'], name, e['proc'], pid, kb,
	2395	+ ke, e['cdata'], e['rdata'])
	2396	+ if sysvals.usecallgraph:
	2397	+ # add the callgraph data to the device hierarchy
	2398	+ sortlist = dict()
	2399	+ for key in test.ftemp:
	2400	+ proc, pid = key
	2401	+ for cg in test.ftemp[key]:
	2402	+ if len(cg.list) < 1 or cg.invalid:
	2403	+ continue
	2404	+ if(not cg.postProcess()):
	2405	+ id = 'task %s' % (pid)
	2406	+ vprint('Sanity check failed for '+\
	2407	+ id+', ignoring this callback')
	2408	+ continue
	2409	+ # match cg data to devices
	2410	+ if sysvals.suspendmode == 'command' or not cg.deviceMatch(pid, test.data):
	2411	+ sortkey = '%f%f%d' % (cg.start, cg.end, pid)
	2412	+ sortlist[sortkey] = cg
	2413	+ # create blocks for orphan cg data
	2414	+ for sortkey in sorted(sortlist):
	2415	+ cg = sortlist[sortkey]
	2416	+ name = cg.list[0].name
	2417	+ if sysvals.isCallgraphFunc(name):
	2418	+ vprint('Callgraph found for task %d: %.3fms, %s' % (cg.pid, (cg.end - cg.start)*1000, name))
	2419	+ cg.newActionFromFunction(test.data)
	2420	+
	2421	+ if sysvals.suspendmode == 'command':
	2422	+ if(sysvals.verbose):
	2423	+ for data in testdata:
	2424	+ data.printDetails()
	2425	+ return testdata
1567	2426
1568	2427	# fill in any missing phases
1569	2428	for data in testdata:
@@ -1587,14 +2446,52 @@ def parseTraceLog(): · 17 unmodified lines
1587	2446	if(sysvals.verbose):
1588	2447	data.printDetails()
1589	2448
1590		− # add the time in between the tests as a new phase so we can see it
1591		− if(len(testdata) > 1):
1592		− t1e = testdata[0].getEnd()
1593		− t2s = testdata[-1].getStart()
1594		− testdata[-1].newPhaseWithSingleAction('user mode', \
1595		− 'user mode', t1e, t2s, '#FF9966')
1596	2449	return testdata
1597	2450
	2451	+# Function: loadRawKernelLog
	2452	+# Description:
	2453	+# Load a raw kernel log that wasn't created by this tool, it might be
	2454	+# possible to extract a valid suspend/resume log
	2455	+def loadRawKernelLog(dmesgfile):
	2456	+ global sysvals
	2457	+
	2458	+ stamp = {'time': '', 'host': '', 'mode': 'mem', 'kernel': ''}
	2459	+ stamp['time'] = datetime.now().strftime('%B %d %Y, %I:%M:%S %p')
	2460	+ stamp['host'] = sysvals.hostname
	2461	+
	2462	+ testruns = []
	2463	+ data = 0
	2464	+ lf = open(dmesgfile, 'r')
	2465	+ for line in lf:
	2466	+ line = line.replace('\r\n', '')
	2467	+ idx = line.find('[')
	2468	+ if idx > 1:
	2469	+ line = line[idx:]
	2470	+ m = re.match('[ \t](\[ )(?P<ktime>[0-9\.])(\]) (?P<msg>.)', line)
	2471	+ if(not m):
	2472	+ continue
	2473	+ msg = m.group("msg")
	2474	+ m = re.match('PM: Syncing filesystems.*', msg)
	2475	+ if(m):
	2476	+ if(data):
	2477	+ testruns.append(data)
	2478	+ data = Data(len(testruns))
	2479	+ data.stamp = stamp
	2480	+ if(data):
	2481	+ m = re.match('.* (?P<k>[0-9]\.[0-9]{2}\.[0-9]-.) .*', msg)
	2482	+ if(m):
	2483	+ stamp['kernel'] = m.group('k')
	2484	+ m = re.match('PM: Preparing system for (?P<m>.*) sleep', msg)
	2485	+ if(m):
	2486	+ stamp['mode'] = m.group('m')
	2487	+ data.dmesgtext.append(line)
	2488	+ if(data):
	2489	+ testruns.append(data)
	2490	+ sysvals.stamp = stamp
	2491	+ sysvals.suspendmode = stamp['mode']
	2492	+ lf.close()
	2493	+ return testruns
	2494	+
1598	2495	# Function: loadKernelLog
1599	2496	# Description:
1600	2497	# [deprecated for kernel 3.15.0 or newer]
@@ -1607,9 +2504,10 @@ def loadKernelLog(): · 6 unmodified lines
1607	2504
1608	2505	vprint('Analyzing the dmesg data...')
1609	2506	if(os.path.exists(sysvals.dmesgfile) == False):
1610		− doError('%s doesnt exist' % sysvals.dmesgfile, False)
	2507	+ doError('%s does not exist' % sysvals.dmesgfile, False)
1611	2508
1612		− # there can be multiple test runs in a single file delineated by stamps
	2509	+ # there can be multiple test runs in a single file
	2510	+ tp = TestProps()
1613	2511	testruns = []
1614	2512	data = 0
1615	2513	lf = open(sysvals.dmesgfile, 'r')
@@ -1620,35 +2518,43 @@ def loadKernelLog(): · 4 unmodified lines
1620	2518	line = line[idx:]
1621	2519	m = re.match(sysvals.stampfmt, line)
1622	2520	if(m):
1623		− if(data):
1624		− testruns.append(data)
1625		− data = Data(len(testruns))
1626		− parseStamp(m, data)
1627		− continue
1628		− if(not data):
	2521	+ tp.stamp = line
1629	2522	continue
1630	2523	m = re.match(sysvals.firmwarefmt, line)
1631	2524	if(m):
1632		− data.fwSuspend = int(m.group('s'))
1633		− data.fwResume = int(m.group('r'))
1634		− if(data.fwSuspend > 0 or data.fwResume > 0):
1635		− data.fwValid = True
	2525	+ tp.fwdata.append((int(m.group('s')), int(m.group('r'))))
1636	2526	continue
1637	2527	m = re.match('[ \t](\[ )(?P<ktime>[0-9\.])(\]) (?P<msg>.)', line)
1638		− if(m):
1639		− data.dmesgtext.append(line)
1640		− if(re.match('ACPI: resume from mwait', m.group('msg'))):
1641		− print('NOTE: This suspend appears to be freeze rather than'+\
1642		− ' %s, it will be treated as such' % sysvals.suspendmode)
1643		− sysvals.suspendmode = 'freeze'
1644		− else:
1645		− vprint('ignoring dmesg line: %s' % line.replace('\n', ''))
1646		− testruns.append(data)
	2528	+ if(not m):
	2529	+ continue
	2530	+ msg = m.group("msg")
	2531	+ if(re.match('PM: Syncing filesystems.*', msg)):
	2532	+ if(data):
	2533	+ testruns.append(data)
	2534	+ data = Data(len(testruns))
	2535	+ parseStamp(tp.stamp, data)
	2536	+ if len(tp.fwdata) > data.testnumber:
	2537	+ data.fwSuspend, data.fwResume = tp.fwdata[data.testnumber]
	2538	+ if(data.fwSuspend > 0 or data.fwResume > 0):
	2539	+ data.fwValid = True
	2540	+ if(re.match('ACPI: resume from mwait', msg)):
	2541	+ print('NOTE: This suspend appears to be freeze rather than'+\
	2542	+ ' %s, it will be treated as such' % sysvals.suspendmode)
	2543	+ sysvals.suspendmode = 'freeze'
	2544	+ if(not data):
	2545	+ continue
	2546	+ data.dmesgtext.append(line)
	2547	+ if(data):
	2548	+ testruns.append(data)
1647	2549	lf.close()
1648	2550
1649		− if(not data):
1650		− print('ERROR: analyze_suspend header missing from dmesg log')
1651		− sys.exit()
	2551	+ if(len(testruns) < 1):
	2552	+ # bad log, but see if you can extract something meaningful anyway
	2553	+ testruns = loadRawKernelLog(sysvals.dmesgfile)
	2554	+
	2555	+ if(len(testruns) < 1):
	2556	+ doError(' dmesg log is completely unreadable: %s' \
	2557	+ % sysvals.dmesgfile, False)
1652	2558
1653	2559	# fix lines with same timestamp/function with the call and return swapped
1654	2560	for data in testruns:
@@ -1865,7 +2771,8 @@ def parseKernelLog(data): · 210 unmodified lines
1865	2771	actions[a] = []
1866	2772	actions[a].append({'begin': ktime, 'end': ktime})
1867	2773	if(re.match(at[a]['emsg'], msg)):
1868		− actions[a][-1]['end'] = ktime
	2774	+ if(a in actions):
	2775	+ actions[a][-1]['end'] = ktime
1869	2776	# now look for CPU on/off events
1870	2777	if(re.match('Disabling non-boot CPUs .*', msg)):
1871	2778	# start of first cpu suspend
@@ -1912,15 +2819,7 @@ def parseKernelLog(data): · 40 unmodified lines
1912	2819	# fill in any actions we've found
1913	2820	for name in actions:
1914	2821	for event in actions[name]:
1915		− begin = event['begin']
1916		− end = event['end']
1917		− # if event starts before timeline start, expand timeline
1918		− if(begin < data.start):
1919		− data.setStart(begin)
1920		− # if event ends after timeline end, expand the timeline
1921		− if(end > data.end):
1922		− data.setEnd(end)
1923		− data.newActionGlobal(name, begin, end)
	2822	+ data.newActionGlobal(name, event['begin'], event['end'])
1924	2823
1925	2824	if(sysvals.verbose):
1926	2825	data.printDetails()
@@ -1929,92 +2828,6 @@ def parseKernelLog(data): · 2 unmodified lines
1929	2828	data.fixupInitcallsThatDidntReturn()
1930	2829	return True
1931	2830
1932		−# Function: setTimelineRows
1933		−# Description:
1934		−# Organize the timeline entries into the smallest
1935		−# number of rows possible, with no entry overlapping
1936		−# Arguments:
1937		−# list: the list of devices/actions for a single phase
1938		−# sortedkeys: cronologically sorted key list to use
1939		−# Output:
1940		−# The total number of rows needed to display this phase of the timeline
1941		−def setTimelineRows(list, sortedkeys):
1942		−
1943		− # clear all rows and set them to undefined
1944		− remaining = len(list)
1945		− rowdata = dict()
1946		− row = 0
1947		− for item in list:
1948		− list[item]['row'] = -1
1949		−
1950		− # try to pack each row with as many ranges as possible
1951		− while(remaining > 0):
1952		− if(row not in rowdata):
1953		− rowdata[row] = []
1954		− for item in sortedkeys:
1955		− if(list[item]['row'] < 0):
1956		− s = list[item]['start']
1957		− e = list[item]['end']
1958		− valid = True
1959		− for ritem in rowdata[row]:
1960		− rs = ritem['start']
1961		− re = ritem['end']
1962		− if(not (((s <= rs) and (e <= rs)) or
1963		− ((s >= re) and (e >= re)))):
1964		− valid = False
1965		− break
1966		− if(valid):
1967		− rowdata[row].append(list[item])
1968		− list[item]['row'] = row
1969		− remaining -= 1
1970		− row += 1
1971		− return row
1972		−
1973		−# Function: createTimeScale
1974		−# Description:
1975		−# Create the timescale header for the html timeline
1976		−# Arguments:
1977		−# t0: start time (suspend begin)
1978		−# tMax: end time (resume end)
1979		−# tSuspend: time when suspend occurs, i.e. the zero time
1980		−# Output:
1981		−# The html code needed to display the time scale
1982		−def createTimeScale(t0, tMax, tSuspended):
1983		− timescale = '<div class="t" style="right:{0}%">{1}</div>\n'
1984		− output = '<div id="timescale">\n'
1985		−
1986		− # set scale for timeline
1987		− tTotal = tMax - t0
1988		− tS = 0.1
1989		− if(tTotal <= 0):
1990		− return output
1991		− if(tTotal > 4):
1992		− tS = 1
1993		− if(tSuspended < 0):
1994		− for i in range(int(tTotal/tS)+1):
1995		− pos = '%0.3f' % (100 - ((float(i)tS100)/tTotal))
1996		− if(i > 0):
1997		− val = '%0.fms' % (float(i)tS1000)
1998		− else:
1999		− val = ''
2000		− output += timescale.format(pos, val)
2001		− else:
2002		− tSuspend = tSuspended - t0
2003		− divTotal = int(tTotal/tS) + 1
2004		− divSuspend = int(tSuspend/tS)
2005		− s0 = (tSuspend - tSdivSuspend)100/tTotal
2006		− for i in range(divTotal):
2007		− pos = '%0.3f' % (100 - ((float(i)tS100)/tTotal) - s0)
2008		− if((i == 0) and (s0 < 3)):
2009		− val = ''
2010		− elif(i == divSuspend):
2011		− val = 'S/R'
2012		− else:
2013		− val = '%0.fms' % (float(i-divSuspend)tS1000)
2014		− output += timescale.format(pos, val)
2015		− output += '</div>\n'
2016		− return output
2017		−
2018	2831	# Function: createHTMLSummarySimple
2019	2832	# Description:
2020	2833	# Create summary html file for a series of tests
@@ -2146,6 +2959,32 @@ def createHTMLSummarySimple(testruns, htmlfile): · 125 unmodified lines
2146	2959	hf.write('</body>\n</html>\n')
2147	2960	hf.close()
2148	2961
	2962	+def htmlTitle():
	2963	+ global sysvals
	2964	+ modename = {
	2965	+ 'freeze': 'Freeze (S0)',
	2966	+ 'standby': 'Standby (S1)',
	2967	+ 'mem': 'Suspend (S3)',
	2968	+ 'disk': 'Hibernate (S4)'
	2969	+ }
	2970	+ kernel = sysvals.stamp['kernel']
	2971	+ host = sysvals.hostname[0].upper()+sysvals.hostname[1:]
	2972	+ mode = sysvals.suspendmode
	2973	+ if sysvals.suspendmode in modename:
	2974	+ mode = modename[sysvals.suspendmode]
	2975	+ return host+' '+mode+' '+kernel
	2976	+
	2977	+def ordinal(value):
	2978	+ suffix = 'th'
	2979	+ if value < 10 or value > 19:
	2980	+ if value % 10 == 1:
	2981	+ suffix = 'st'
	2982	+ elif value % 10 == 2:
	2983	+ suffix = 'nd'
	2984	+ elif value % 10 == 3:
	2985	+ suffix = 'rd'
	2986	+ return '%d%s' % (value, suffix)
	2987	+
2149	2988	# Function: createHTML
2150	2989	# Description:
2151	2990	# Create the output html file from the resident test data
@@ -2156,6 +2995,10 @@ def createHTMLSummarySimple(testruns, htmlfile): · 4 unmodified lines
2156	2995	def createHTML(testruns):
2157	2996	global sysvals
2158	2997
	2998	+ if len(testruns) < 1:
	2999	+ print('ERROR: Not enough test data to build a timeline')
	3000	+ return
	3001	+
2159	3002	for data in testruns:
2160	3003	data.normalizeTime(testruns[-1].tSuspended)
2161	3004
@@ -2163,16 +3006,18 @@ def createHTML(testruns): · 1 unmodified line
2163	3006	if len(testruns) > 1:
2164	3007	x2changes = ['1', 'relative']
2165	3008	# html function templates
	3009	+ headline_version = '<div class="version"><a href="https://01.org/suspendresume">AnalyzeSuspend v%s</a></div>' % sysvals.version
2166	3010	headline_stamp = '<div class="stamp">{0} {1} {2} {3}</div>\n'
2167	3011	html_devlist1 = '<button id="devlist1" class="devlist" style="float:left;">Device Detail%s</button>' % x2changes[0]
2168	3012	html_zoombox = '<center><button id="zoomin">ZOOM IN</button><button id="zoomout">ZOOM OUT</button><button id="zoomdef">ZOOM 1:1</button></center>\n'
2169	3013	html_devlist2 = '<button id="devlist2" class="devlist" style="float:right;">Device Detail2</button>\n'
2170	3014	html_timeline = '<div id="dmesgzoombox" class="zoombox">\n<div id="{0}" class="timeline" style="height:{1}px">\n'
2171		− html_device = '<div id="{0}" title="{1}" class="thread" style="left:{2}%;top:{3}%;height:{4}%;width:{5}%;">{6}</div>\n'
2172		− html_traceevent = '<div title="{0}" class="traceevent" style="left:{1}%;top:{2}%;height:{3}%;width:{4}%;border:1px solid {5};background-color:{5}">{6}</div>\n'
2173		− html_phase = '<div class="phase" style="left:{0}%;width:{1}%;top:{2}%;height:{3}%;background-color:{4}">{5}</div>\n'
	3015	+ html_tblock = '<div id="block{0}" class="tblock" style="left:{1}%;width:{2}%;">\n'
	3016	+ 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'
	3017	+ html_traceevent = '<div title="{0}" class="traceevent" style="left:{1}%;top:{2}px;height:{3}px;width:{4}%;line-height:{3}px;">{5}</div>\n'
	3018	+ html_phase = '<div class="phase" style="left:{0}%;width:{1}%;top:{2}px;height:{3}px;background-color:{4}">{5}</div>\n'
2174	3019	html_phaselet = '<div id="{0}" class="phaselet" style="left:{1}%;width:{2}%;background-color:{3}"></div>\n'
2175		− html_legend = '<div class="square" style="left:{0}%;background-color:{1}"> {2}</div>\n'
	3020	+ html_legend = '<div id="p{3}" class="square" style="left:{0}%;background-color:{1}"> {2}</div>\n'
2176	3021	html_timetotal = '<table class="time1">\n<tr>'\
2177	3022	'<td class="green">{2} Suspend Time: <b>{0} ms</b></td>'\
2178	3023	'<td class="yellow">{2} Resume Time: <b>{1} ms</b></td>'\
@@ -2182,6 +3027,10 @@ def createHTML(testruns): · 3 unmodified lines
2182	3027	'<td class="gray">'+sysvals.suspendmode+' time: <b>{1} ms</b></td>'\
2183	3028	'<td class="yellow">{3} Resume Time: <b>{2} ms</b></td>'\
2184	3029	'</tr>\n</table>\n'
	3030	+ html_timetotal3 = '<table class="time1">\n<tr>'\
	3031	+ '<td class="green">Execution Time: <b>{0} ms</b></td>'\
	3032	+ '<td class="yellow">Command: <b>{1}</b></td>'\
	3033	+ '</tr>\n</table>\n'
2185	3034	html_timegroups = '<table class="time2">\n<tr>'\
2186	3035	'<td class="green">{4}Kernel Suspend: {0} ms</td>'\
2187	3036	'<td class="purple">{4}Firmware Suspend: {1} ms</td>'\
@@ -2189,12 +3038,21 @@ def createHTML(testruns): · 1 unmodified line
2189	3038	'<td class="yellow">{4}Kernel Resume: {3} ms</td>'\
2190	3039	'</tr>\n</table>\n'
2191	3040
	3041	+ # html format variables
	3042	+ rowheight = 30
	3043	+ devtextS = '14px'
	3044	+ devtextH = '30px'
	3045	+ hoverZ = 'z-index:10;'
	3046	+
	3047	+ if sysvals.usedevsrc:
	3048	+ hoverZ = ''
	3049	+
2192	3050	# device timeline
2193	3051	vprint('Creating Device Timeline...')
2194		− devtl = Timeline()
	3052	+
	3053	+ devtl = Timeline(rowheight)
2195	3054
2196	3055	# Generate the header for this timeline
2197		− textnum = ['First', 'Second']
2198	3056	for data in testruns:
2199	3057	tTotal = data.end - data.start
2200	3058	tEnd = data.dmesg['resume_complete']['end']
@@ -2203,7 +3061,17 @@ def createHTML(testruns): · 2 unmodified lines
2203	3061	sys.exit()
2204	3062	if(data.tLow > 0):
2205	3063	low_time = '%.0f'%(data.tLow*1000)
2206		− if data.fwValid:
	3064	+ if sysvals.suspendmode == 'command':
	3065	+ run_time = '%.0f'%((data.end-data.start)*1000)
	3066	+ if sysvals.testcommand:
	3067	+ testdesc = sysvals.testcommand
	3068	+ else:
	3069	+ testdesc = 'unknown'
	3070	+ if(len(testruns) > 1):
	3071	+ testdesc = ordinal(data.testnumber+1)+' '+testdesc
	3072	+ thtml = html_timetotal3.format(run_time, testdesc)
	3073	+ devtl.html['header'] += thtml
	3074	+ elif data.fwValid:
2207	3075	suspend_time = '%.0f'%((data.tSuspended-data.start)*1000 + \
2208	3076	(data.fwSuspend/1000000.0))
2209	3077	resume_time = '%.0f'%((tEnd-data.tSuspended)*1000 + \
@@ -2211,7 +3079,7 @@ def createHTML(testruns): · 1 unmodified line
2211	3079	testdesc1 = 'Total'
2212	3080	testdesc2 = ''
2213	3081	if(len(testruns) > 1):
2214		− testdesc1 = testdesc2 = textnum[data.testnumber]
	3082	+ testdesc1 = testdesc2 = ordinal(data.testnumber+1)
2215	3083	testdesc2 += ' '
2216	3084	if(data.tLow == 0):
2217	3085	thtml = html_timetotal.format(suspend_time, \
@@ -2219,28 +3087,28 @@ def createHTML(testruns): · 1 unmodified line
2219	3087	else:
2220	3088	thtml = html_timetotal2.format(suspend_time, low_time, \
2221	3089	resume_time, testdesc1)
2222		− devtl.html['timeline'] += thtml
	3090	+ devtl.html['header'] += thtml
2223	3091	sktime = '%.3f'%((data.dmesg['suspend_machine']['end'] - \
2224	3092	data.getStart())*1000)
2225	3093	sftime = '%.3f'%(data.fwSuspend / 1000000.0)
2226	3094	rftime = '%.3f'%(data.fwResume / 1000000.0)
2227		− rktime = '%.3f'%((data.getEnd() - \
	3095	+ rktime = '%.3f'%((data.dmesg['resume_complete']['end'] - \
2228	3096	data.dmesg['resume_machine']['start'])*1000)
2229		− devtl.html['timeline'] += html_timegroups.format(sktime, \
	3097	+ devtl.html['header'] += html_timegroups.format(sktime, \
2230	3098	sftime, rftime, rktime, testdesc2)
2231	3099	else:
2232	3100	suspend_time = '%.0f'%((data.tSuspended-data.start)*1000)
2233	3101	resume_time = '%.0f'%((tEnd-data.tSuspended)*1000)
2234	3102	testdesc = 'Kernel'
2235	3103	if(len(testruns) > 1):
2236		− testdesc = textnum[data.testnumber]+' '+testdesc
	3104	+ testdesc = ordinal(data.testnumber+1)+' '+testdesc
2237	3105	if(data.tLow == 0):
2238	3106	thtml = html_timetotal.format(suspend_time, \
2239	3107	resume_time, testdesc)
2240	3108	else:
2241	3109	thtml = html_timetotal2.format(suspend_time, low_time, \
2242	3110	resume_time, testdesc)
2243		− devtl.html['timeline'] += thtml
	3111	+ devtl.html['header'] += thtml
2244	3112
2245	3113	# time scale for potentially multiple datasets
2246	3114	t0 = testruns[0].start
@@ -2249,153 +3117,241 @@ def createHTML(testruns): · 2 unmodified lines
2249	3117	tTotal = tMax - t0
2250	3118
2251	3119	# determine the maximum number of rows we need to draw
2252		− timelinerows = 0
2253	3120	for data in testruns:
2254		− for phase in data.dmesg:
2255		− list = data.dmesg[phase]['list']
2256		− rows = setTimelineRows(list, list)
2257		− data.dmesg[phase]['row'] = rows
2258		− if(rows > timelinerows):
2259		− timelinerows = rows
2260		−
2261		− # calculate the timeline height and create bounding box, add buttons
2262		− devtl.setRows(timelinerows + 1)
2263		− devtl.html['timeline'] += html_devlist1
2264		− if len(testruns) > 1:
2265		− devtl.html['timeline'] += html_devlist2
	3121	+ data.selectTimelineDevices('%f', tTotal, sysvals.mindevlen)
	3122	+ for group in data.devicegroups:
	3123	+ devlist = []
	3124	+ for phase in group:
	3125	+ for devname in data.tdevlist[phase]:
	3126	+ devlist.append((phase,devname))
	3127	+ devtl.getPhaseRows(data.dmesg, devlist)
	3128	+ devtl.calcTotalRows()
	3129	+
	3130	+ # create bounding box, add buttons
	3131	+ if sysvals.suspendmode != 'command':
	3132	+ devtl.html['timeline'] += html_devlist1
	3133	+ if len(testruns) > 1:
	3134	+ devtl.html['timeline'] += html_devlist2
2266	3135	devtl.html['timeline'] += html_zoombox
2267	3136	devtl.html['timeline'] += html_timeline.format('dmesg', devtl.height)
2268	3137
2269		− # draw the colored boxes for each of the phases
2270		− for data in testruns:
2271		− for b in data.dmesg:
2272		− phase = data.dmesg[b]
2273		− length = phase['end']-phase['start']
2274		− left = '%.3f' % (((phase['start']-t0)*100.0)/tTotal)
2275		− width = '%.3f' % ((length*100.0)/tTotal)
2276		− devtl.html['timeline'] += html_phase.format(left, width, \
2277		− '%.3f'%devtl.scaleH, '%.3f'%(100-devtl.scaleH), \
2278		− data.dmesg[b]['color'], '')
	3138	+ # draw the full timeline
	3139	+ phases = {'suspend':[],'resume':[]}
	3140	+ for phase in data.dmesg:
	3141	+ if 'resume' in phase:
	3142	+ phases['resume'].append(phase)
	3143	+ else:
	3144	+ phases['suspend'].append(phase)
2279	3145
2280		− # draw the time scale, try to make the number of labels readable
2281		− devtl.html['scale'] = createTimeScale(t0, tMax, tSuspended)
2282		− devtl.html['timeline'] += devtl.html['scale']
2283		− for data in testruns:
2284		− for b in data.dmesg:
2285		− phaselist = data.dmesg[b]['list']
2286		− for d in phaselist:
2287		− name = d
2288		− drv = ''
2289		− dev = phaselist[d]
2290		− if(d in sysvals.altdevname):
2291		− name = sysvals.altdevname[d]
2292		− if('drv' in dev and dev['drv']):
2293		− drv = ' {%s}' % dev['drv']
2294		− height = (100.0 - devtl.scaleH)/data.dmesg[b]['row']
2295		− top = '%.3f' % ((dev['row']*height) + devtl.scaleH)
2296		− left = '%.3f' % (((dev['start']-t0)*100)/tTotal)
2297		− width = '%.3f' % (((dev['end']-dev['start'])*100)/tTotal)
2298		− length = ' (%0.3f ms) ' % ((dev['end']-dev['start'])*1000)
2299		− color = 'rgba(204,204,204,0.5)'
2300		− devtl.html['timeline'] += html_device.format(dev['id'], \
2301		− d+drv+length+b, left, top, '%.3f'%height, width, name+drv)
2302		−
2303		− # draw any trace events found
	3146	+ # draw each test run chronologically
2304	3147	for data in testruns:
2305		− for b in data.dmesg:
2306		− phaselist = data.dmesg[b]['list']
2307		− for name in phaselist:
2308		− dev = phaselist[name]
2309		− if('traceevents' in dev):
2310		− vprint('Debug trace events found for device %s' % name)
2311		− vprint('%20s %20s %10s %8s' % ('action', \
	3148	+ # if nore than one test, draw a block to represent user mode
	3149	+ if(data.testnumber > 0):
	3150	+ m0 = testruns[data.testnumber-1].end
	3151	+ mMax = testruns[data.testnumber].start
	3152	+ mTotal = mMax - m0
	3153	+ name = 'usermode%d' % data.testnumber
	3154	+ top = '%d' % devtl.scaleH
	3155	+ left = '%f' % (((m0-t0)*100.0)/tTotal)
	3156	+ width = '%f' % ((mTotal*100.0)/tTotal)
	3157	+ title = 'user mode (%0.3f ms) ' % (mTotal*1000)
	3158	+ devtl.html['timeline'] += html_device.format(name, \
	3159	+ title, left, top, '%d'%devtl.bodyH, width, '', '', '')
	3160	+ # now draw the actual timeline blocks
	3161	+ for dir in phases:
	3162	+ # draw suspend and resume blocks separately
	3163	+ bname = '%s%d' % (dir[0], data.testnumber)
	3164	+ if dir == 'suspend':
	3165	+ m0 = testruns[data.testnumber].start
	3166	+ mMax = testruns[data.testnumber].tSuspended
	3167	+ mTotal = mMax - m0
	3168	+ left = '%f' % (((m0-t0)*100.0)/tTotal)
	3169	+ else:
	3170	+ m0 = testruns[data.testnumber].tSuspended
	3171	+ mMax = testruns[data.testnumber].end
	3172	+ mTotal = mMax - m0
	3173	+ left = '%f' % ((((m0-t0)*100.0)+sysvals.srgap/2)/tTotal)
	3174	+ # if a timeline block is 0 length, skip altogether
	3175	+ if mTotal == 0:
	3176	+ continue
	3177	+ width = '%f' % (((mTotal*100.0)-sysvals.srgap/2)/tTotal)
	3178	+ devtl.html['timeline'] += html_tblock.format(bname, left, width)
	3179	+ for b in sorted(phases[dir]):
	3180	+ # draw the phase color background
	3181	+ phase = data.dmesg[b]
	3182	+ length = phase['end']-phase['start']
	3183	+ left = '%f' % (((phase['start']-m0)*100.0)/mTotal)
	3184	+ width = '%f' % ((length*100.0)/mTotal)
	3185	+ devtl.html['timeline'] += html_phase.format(left, width, \
	3186	+ '%.3f'%devtl.scaleH, '%.3f'%devtl.bodyH, \
	3187	+ data.dmesg[b]['color'], '')
	3188	+ # draw the devices for this phase
	3189	+ phaselist = data.dmesg[b]['list']
	3190	+ for d in data.tdevlist[b]:
	3191	+ name = d
	3192	+ drv = ''
	3193	+ dev = phaselist[d]
	3194	+ xtraclass = ''
	3195	+ xtrainfo = ''
	3196	+ xtrastyle = ''
	3197	+ if 'htmlclass' in dev:
	3198	+ xtraclass = dev['htmlclass']
	3199	+ xtrainfo = dev['htmlclass']
	3200	+ if 'color' in dev:
	3201	+ xtrastyle = 'background-color:%s;' % dev['color']
	3202	+ if(d in sysvals.devprops):
	3203	+ name = sysvals.devprops[d].altName(d)
	3204	+ xtraclass = sysvals.devprops[d].xtraClass()
	3205	+ xtrainfo = sysvals.devprops[d].xtraInfo()
	3206	+ if('drv' in dev and dev['drv']):
	3207	+ drv = ' {%s}' % dev['drv']
	3208	+ rowheight = devtl.phaseRowHeight(b, dev['row'])
	3209	+ rowtop = devtl.phaseRowTop(b, dev['row'])
	3210	+ top = '%.3f' % (rowtop + devtl.scaleH)
	3211	+ left = '%f' % (((dev['start']-m0)*100)/mTotal)
	3212	+ width = '%f' % (((dev['end']-dev['start'])*100)/mTotal)
	3213	+ length = ' (%0.3f ms) ' % ((dev['end']-dev['start'])*1000)
	3214	+ if sysvals.suspendmode == 'command':
	3215	+ title = name+drv+xtrainfo+length+'cmdexec'
	3216	+ else:
	3217	+ title = name+drv+xtrainfo+length+b
	3218	+ devtl.html['timeline'] += html_device.format(dev['id'], \
	3219	+ title, left, top, '%.3f'%rowheight, width, \
	3220	+ d+drv, xtraclass, xtrastyle)
	3221	+ if('src' not in dev):
	3222	+ continue
	3223	+ # draw any trace events for this device
	3224	+ vprint('Debug trace events found for device %s' % d)
	3225	+ vprint('%20s %20s %10s %8s' % ('title', \
2312	3226	'name', 'time(ms)', 'length(ms)'))
2313		− for e in dev['traceevents']:
2314		− vprint('%20s %20s %10.3f %8.3f' % (e.action, \
2315		− e.name, e.time1000, e.length1000))
2316		− height = (100.0 - devtl.scaleH)/data.dmesg[b]['row']
2317		− top = '%.3f' % ((dev['row']*height) + devtl.scaleH)
2318		− left = '%.3f' % (((e.time-t0)*100)/tTotal)
2319		− width = '%.3f' % (e.length*100/tTotal)
	3227	+ for e in dev['src']:
	3228	+ vprint('%20s %20s %10.3f %8.3f' % (e.title, \
	3229	+ e.text, e.time1000, e.length1000))
	3230	+ height = devtl.rowH
	3231	+ top = '%.3f' % (rowtop + devtl.scaleH + (e.row*devtl.rowH))
	3232	+ left = '%f' % (((e.time-m0)*100)/mTotal)
	3233	+ width = '%f' % (e.length*100/mTotal)
2320	3234	color = 'rgba(204,204,204,0.5)'
2321	3235	devtl.html['timeline'] += \
2322		− html_traceevent.format(e.action+' '+e.name, \
	3236	+ html_traceevent.format(e.title, \
2323	3237	left, top, '%.3f'%height, \
2324		− width, e.color, '')
	3238	+ width, e.text)
	3239	+ # draw the time scale, try to make the number of labels readable
	3240	+ devtl.html['timeline'] += devtl.createTimeScale(m0, mMax, tTotal, dir)
	3241	+ devtl.html['timeline'] += '</div>\n'
2325	3242
2326	3243	# timeline is finished
2327	3244	devtl.html['timeline'] += '</div>\n</div>\n'
2328	3245
2329	3246	# draw a legend which describes the phases by color
2330		− data = testruns[-1]
2331		− devtl.html['legend'] = '<div class="legend">\n'
2332		− pdelta = 100.0/len(data.phases)
2333		− pmargin = pdelta / 4.0
2334		− for phase in data.phases:
2335		− order = '%.2f' % ((data.dmesg[phase]['order'] * pdelta) + pmargin)
2336		− name = string.replace(phase, '_', '  ')
2337		− devtl.html['legend'] += html_legend.format(order, \
2338		− data.dmesg[phase]['color'], name)
2339		− devtl.html['legend'] += '</div>\n'
	3247	+ if sysvals.suspendmode != 'command':
	3248	+ data = testruns[-1]
	3249	+ devtl.html['legend'] = '<div class="legend">\n'
	3250	+ pdelta = 100.0/len(data.phases)
	3251	+ pmargin = pdelta / 4.0
	3252	+ for phase in data.phases:
	3253	+ tmp = phase.split('_')
	3254	+ id = tmp[0][0]
	3255	+ if(len(tmp) > 1):
	3256	+ id += tmp[1][0]
	3257	+ order = '%.2f' % ((data.dmesg[phase]['order'] * pdelta) + pmargin)
	3258	+ name = string.replace(phase, '_', '  ')
	3259	+ devtl.html['legend'] += html_legend.format(order, \
	3260	+ data.dmesg[phase]['color'], name, id)
	3261	+ devtl.html['legend'] += '</div>\n'
2340	3262
2341	3263	hf = open(sysvals.htmlfile, 'w')
2342		− thread_height = 0
	3264	+
	3265	+ if not sysvals.cgexp:
	3266	+ cgchk = 'checked'
	3267	+ cgnchk = 'not(:checked)'
	3268	+ else:
	3269	+ cgchk = 'not(:checked)'
	3270	+ cgnchk = 'checked'
2343	3271
2344	3272	# write the html header first (html head, css code, up to body start)
2345	3273	html_header = '<!DOCTYPE html>\n<html>\n<head>\n\
2346	3274	<meta http-equiv="content-type" content="text/html; charset=UTF-8">\n\
2347		− <title>AnalyzeSuspend</title>\n\
	3275	+ <title>'+htmlTitle()+'</title>\n\
2348	3276	<style type=\'text/css\'>\n\
2349		− body {overflow-y: scroll;}\n\
2350		− .stamp {width: 100%;text-align:center;background-color:gray;line-height:30px;color:white;font: 25px Arial;}\n\
2351		− .callgraph {margin-top: 30px;box-shadow: 5px 5px 20px black;}\n\
2352		− .callgraph article * {padding-left: 28px;}\n\
2353		− h1 {color:black;font: bold 30px Times;}\n\
2354		− t0 {color:black;font: bold 30px Times;}\n\
2355		− t1 {color:black;font: 30px Times;}\n\
2356		− t2 {color:black;font: 25px Times;}\n\
2357		− t3 {color:black;font: 20px Times;white-space:nowrap;}\n\
2358		− t4 {color:black;font: bold 30px Times;line-height:60px;white-space:nowrap;}\n\
	3277	+ body {overflow-y:scroll;}\n\
	3278	+ .stamp {width:100%;text-align:center;background-color:gray;line-height:30px;color:white;font:25px Arial;}\n\
	3279	+ .callgraph {margin-top:30px;box-shadow:5px 5px 20px black;}\n\
	3280	+ .callgraph article * {padding-left:28px;}\n\
	3281	+ h1 {color:black;font:bold 30px Times;}\n\
	3282	+ t0 {color:black;font:bold 30px Times;}\n\
	3283	+ t1 {color:black;font:30px Times;}\n\
	3284	+ t2 {color:black;font:25px Times;}\n\
	3285	+ t3 {color:black;font:20px Times;white-space:nowrap;}\n\
	3286	+ t4 {color:black;font:bold 30px Times;line-height:60px;white-space:nowrap;}\n\
	3287	+ cS {color:blue;font:bold 11px Times;}\n\
	3288	+ cR {color:red;font:bold 11px Times;}\n\
2359	3289	table {width:100%;}\n\
2360	3290	.gray {background-color:rgba(80,80,80,0.1);}\n\
2361	3291	.green {background-color:rgba(204,255,204,0.4);}\n\
2362	3292	.purple {background-color:rgba(128,0,128,0.2);}\n\
2363	3293	.yellow {background-color:rgba(255,255,204,0.4);}\n\
2364		− .time1 {font: 22px Arial;border:1px solid;}\n\
2365		− .time2 {font: 15px Arial;border-bottom:1px solid;border-left:1px solid;border-right:1px solid;}\n\
2366		− td {text-align: center;}\n\
	3294	+ .time1 {font:22px Arial;border:1px solid;}\n\
	3295	+ .time2 {font:15px Arial;border-bottom:1px solid;border-left:1px solid;border-right:1px solid;}\n\
	3296	+ td {text-align:center;}\n\
2367	3297	r {color:#500000;font:15px Tahoma;}\n\
2368	3298	n {color:#505050;font:15px Tahoma;}\n\
2369		− .tdhl {color: red;}\n\
2370		− .hide {display: none;}\n\
2371		− .pf {display: none;}\n\
2372		− .pf:checked + 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\
2373		− .pf:not(:checked) ~ 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\
2374		− .pf:checked ~ *:not(:nth-child(2)) {display: none;}\n\
2375		− .zoombox {position: relative; width: 100%; overflow-x: scroll;}\n\
2376		− .timeline {position: relative; font-size: 14px;cursor: pointer;width: 100%; overflow: hidden; background-color:#dddddd;}\n\
2377		− .thread {position: absolute; height: '+'%.3f'%thread_height+'%; overflow: hidden; line-height: 30px; border:1px solid;text-align:center;white-space:nowrap;background-color:rgba(204,204,204,0.5);}\n\
2378		− .thread:hover {background-color:white;border:1px solid red;z-index:10;}\n\
2379		− .hover {background-color:white;border:1px solid red;z-index:10;}\n\
2380		− .traceevent {position: absolute;opacity: 0.3;height: '+'%.3f'%thread_height+'%;width:0;overflow:hidden;line-height:30px;text-align:center;white-space:nowrap;}\n\
2381		− .phase {position: absolute;overflow: hidden;border:0px;text-align:center;}\n\
	3299	+ .tdhl {color:red;}\n\
	3300	+ .hide {display:none;}\n\
	3301	+ .pf {display:none;}\n\
	3302	+ .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\
	3303	+ .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\
	3304	+ .pf:'+cgchk+' ~ *:not(:nth-child(2)) {display:none;}\n\
	3305	+ .zoombox {position:relative;width:100%;overflow-x:scroll;}\n\
	3306	+ .timeline {position:relative;font-size:14px;cursor:pointer;width:100%; overflow:hidden;background:linear-gradient(#cccccc, white);}\n\
	3307	+ .thread {position:absolute;height:0%;overflow:hidden;line-height:'+devtextH+';font-size:'+devtextS+';border:1px solid;text-align:center;white-space:nowrap;background-color:rgba(204,204,204,0.5);}\n\
	3308	+ .thread.sync {background-color:'+sysvals.synccolor+';}\n\
	3309	+ .thread.bg {background-color:'+sysvals.kprobecolor+';}\n\
	3310	+ .thread:hover {background-color:white;border:1px solid red;'+hoverZ+'}\n\
	3311	+ .hover {background-color:white;border:1px solid red;'+hoverZ+'}\n\
	3312	+ .hover.sync {background-color:white;}\n\
	3313	+ .hover.bg {background-color:white;}\n\
	3314	+ .traceevent {position:absolute;font-size:10px;overflow:hidden;color:black;text-align:center;white-space:nowrap;border-radius:5px;border:1px solid black;background:linear-gradient(to bottom right,rgba(204,204,204,1),rgba(150,150,150,1));}\n\
	3315	+ .traceevent:hover {background:white;}\n\
	3316	+ .phase {position:absolute;overflow:hidden;border:0px;text-align:center;}\n\
2382	3317	.phaselet {position:absolute;overflow:hidden;border:0px;text-align:center;height:100px;font-size:24px;}\n\
2383		− .t {position:absolute;top:0%;height:100%;border-right:1px solid black;}\n\
2384		− .legend {position: relative; width: 100%; height: 40px; text-align: center;margin-bottom:20px}\n\
2385		− .legend .square {position:absolute;top:10px; width: 0px;height: 20px;border:1px solid;padding-left:20px;}\n\
	3318	+ .t {z-index:2;position:absolute;pointer-events:none;top:0%;height:100%;border-right:1px solid black;}\n\
	3319	+ .legend {position:relative; width:100%; height:40px; text-align:center;margin-bottom:20px}\n\
	3320	+ .legend .square {position:absolute;cursor:pointer;top:10px; width:0px;height:20px;border:1px solid;padding-left:20px;}\n\
2386	3321	button {height:40px;width:200px;margin-bottom:20px;margin-top:20px;font-size:24px;}\n\
	3322	+ .logbtn {position:relative;float:right;height:25px;width:50px;margin-top:3px;margin-bottom:0;font-size:10px;text-align:center;}\n\
2387	3323	.devlist {position:'+x2changes[1]+';width:190px;}\n\
2388		− #devicedetail {height:100px;box-shadow: 5px 5px 20px black;}\n\
	3324	+ a:link {color:white;text-decoration:none;}\n\
	3325	+ a:visited {color:white;}\n\
	3326	+ a:hover {color:white;}\n\
	3327	+ a:active {color:white;}\n\
	3328	+ .version {position:relative;float:left;color:white;font-size:10px;line-height:30px;margin-left:10px;}\n\
	3329	+ #devicedetail {height:100px;box-shadow:5px 5px 20px black;}\n\
	3330	+ .tblock {position:absolute;height:100%;}\n\
	3331	+ .bg {z-index:1;}\n\
2389	3332	</style>\n</head>\n<body>\n'
2390		− hf.write(html_header)
	3333	+
	3334	+ # no header or css if its embedded
	3335	+ if(sysvals.embedded):
	3336	+ hf.write('pass True tSus %.3f tRes %.3f tLow %.3f fwvalid %s tSus %.3f tRes %.3f\n' %
	3337	+ (data.tSuspended-data.start, data.end-data.tSuspended, data.tLow, data.fwValid, \
	3338	+ data.fwSuspend/1000000, data.fwResume/1000000))
	3339	+ else:
	3340	+ hf.write(html_header)
2391	3341
2392	3342	# write the test title and general info header
2393	3343	if(sysvals.stamp['time'] != ""):
	3344	+ hf.write(headline_version)
	3345	+ if sysvals.addlogs and sysvals.dmesgfile:
	3346	+ hf.write('<button id="showdmesg" class="logbtn">dmesg</button>')
	3347	+ if sysvals.addlogs and sysvals.ftracefile:
	3348	+ hf.write('<button id="showftrace" class="logbtn">ftrace</button>')
2394	3349	hf.write(headline_stamp.format(sysvals.stamp['host'],
2395	3350	sysvals.stamp['kernel'], sysvals.stamp['mode'], \
2396	3351	sysvals.stamp['time']))
2397	3352
2398	3353	# write the device timeline
	3354	+ hf.write(devtl.html['header'])
2399	3355	hf.write(devtl.html['timeline'])
2400	3356	hf.write(devtl.html['legend'])
2401	3357	hf.write('<div id="devicedetailtitle"></div>\n')
@@ -2410,12 +3366,15 @@ def createHTML(testruns): · 8 unmodified lines
2410	3366	width = '%.3f' % ((length*100.0)/tTotal)
2411	3367	hf.write(html_phaselet.format(b, left, width, \
2412	3368	data.dmesg[b]['color']))
	3369	+ if sysvals.suspendmode == 'command':
	3370	+ hf.write(html_phaselet.format('cmdexec', '0', '0', \
	3371	+ data.dmesg['resume_complete']['color']))
2413	3372	hf.write('</div>\n')
2414	3373	hf.write('</div>\n')
2415	3374
2416	3375	# write the ftrace data (callgraph)
2417	3376	data = testruns[-1]
2418		− if(sysvals.usecallgraph):
	3377	+ if(sysvals.usecallgraph and not sysvals.embedded):
2419	3378	hf.write('<section id="callgraphs" class="callgraph">\n')
2420	3379	# write out the ftrace data converted to html
2421	3380	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'
@@ -2428,22 +3387,29 @@ def createHTML(testruns): · 6 unmodified lines
2428	3387	for devname in data.sortedDevices(p):
2429	3388	if('ftrace' not in list[devname]):
2430	3389	continue
2431		− name = devname
2432		− if(devname in sysvals.altdevname):
2433		− name = sysvals.altdevname[devname]
2434	3390	devid = list[devname]['id']
2435	3391	cg = list[devname]['ftrace']
2436		− flen = '<r>(%.3f ms @ %.3f to %.3f)</r>' % \
2437		− ((cg.end - cg.start)1000, cg.start1000, cg.end*1000)
	3392	+ clen = (cg.end - cg.start) * 1000
	3393	+ if clen < sysvals.mincglen:
	3394	+ continue
	3395	+ fmt = '<r>(%.3f ms @ '+sysvals.timeformat+' to '+sysvals.timeformat+')</r>'
	3396	+ flen = fmt % (clen, cg.start, cg.end)
	3397	+ name = devname
	3398	+ if(devname in sysvals.devprops):
	3399	+ name = sysvals.devprops[devname].altName(devname)
	3400	+ if sysvals.suspendmode == 'command':
	3401	+ ftitle = name
	3402	+ else:
	3403	+ ftitle = name+' '+p
2438	3404	hf.write(html_func_top.format(devid, data.dmesg[p]['color'], \
2439		− num, name+' '+p, flen))
	3405	+ num, ftitle, flen))
2440	3406	num += 1
2441	3407	for line in cg.list:
2442	3408	if(line.length < 0.000000001):
2443	3409	flen = ''
2444	3410	else:
2445		− flen = '<n>(%.3f ms @ %.3f)</n>' % (line.length*1000, \
2446		− line.time*1000)
	3411	+ fmt = '<n>(%.3f ms @ '+sysvals.timeformat+')</n>'
	3412	+ flen = fmt % (line.length*1000, line.time)
2447	3413	if(line.freturn and line.fcall):
2448	3414	hf.write(html_func_leaf.format(line.name, flen))
2449	3415	elif(line.freturn):
@@ -2453,9 +3419,40 @@ def createHTML(testruns): · 3 unmodified lines
2453	3419	num += 1
2454	3420	hf.write(html_func_end)
2455	3421	hf.write('\n\n </section>\n')
2456		− # write the footer and close
2457		− addScriptCode(hf, testruns)
2458		− hf.write('</body>\n</html>\n')
	3422	+
	3423	+ # add the dmesg log as a hidden div
	3424	+ if sysvals.addlogs and sysvals.dmesgfile:
	3425	+ hf.write('<div id="dmesglog" style="display:none;">\n')
	3426	+ lf = open(sysvals.dmesgfile, 'r')
	3427	+ for line in lf:
	3428	+ hf.write(line)
	3429	+ lf.close()
	3430	+ hf.write('</div>\n')
	3431	+ # add the ftrace log as a hidden div
	3432	+ if sysvals.addlogs and sysvals.ftracefile:
	3433	+ hf.write('<div id="ftracelog" style="display:none;">\n')
	3434	+ lf = open(sysvals.ftracefile, 'r')
	3435	+ for line in lf:
	3436	+ hf.write(line)
	3437	+ lf.close()
	3438	+ hf.write('</div>\n')
	3439	+
	3440	+ if(not sysvals.embedded):
	3441	+ # write the footer and close
	3442	+ addScriptCode(hf, testruns)
	3443	+ hf.write('</body>\n</html>\n')
	3444	+ else:
	3445	+ # embedded out will be loaded in a page, skip the js
	3446	+ t0 = (testruns[0].start - testruns[-1].tSuspended) * 1000
	3447	+ tMax = (testruns[-1].end - testruns[-1].tSuspended) * 1000
	3448	+ # add js code in a div entry for later evaluation
	3449	+ detail = 'var bounds = [%f,%f];\n' % (t0, tMax)
	3450	+ detail += 'var devtable = [\n'
	3451	+ for data in testruns:
	3452	+ topo = data.deviceTopology()
	3453	+ detail += '\t"%s",\n' % (topo)
	3454	+ detail += '];\n'
	3455	+ hf.write('<div id=customcode style=display:none>\n'+detail+'</div>\n')
2459	3456	hf.close()
2460	3457	return True
2461	3458
@@ -2466,8 +3463,8 @@ def createHTML(testruns): · 4 unmodified lines
2466	3463	# hf: the open html file pointer
2467	3464	# testruns: array of Data objects from parseKernelLog or parseTraceLog
2468	3465	def addScriptCode(hf, testruns):
2469		− t0 = (testruns[0].start - testruns[-1].tSuspended) * 1000
2470		− tMax = (testruns[-1].end - testruns[-1].tSuspended) * 1000
	3466	+ t0 = testruns[0].start * 1000
	3467	+ tMax = testruns[-1].end * 1000
2471	3468	# create an array in javascript memory with the device details
2472	3469	detail = ' var devtable = [];\n'
2473	3470	for data in testruns:
@@ -2477,8 +3474,43 @@ def addScriptCode(hf, testruns): · 3 unmodified lines
2477	3474	# add the code which will manipulate the data in the browser
2478	3475	script_code = \
2479	3476	'<script type="text/javascript">\n'+detail+\
	3477	+ ' var resolution = -1;\n'\
	3478	+ ' function redrawTimescale(t0, tMax, tS) {\n'\
	3479	+ ' var rline = \'<div class="t" style="left:0;border-left:1px solid black;border-right:0;"><cR><-R</cR></div>\';\n'\
	3480	+ ' var tTotal = tMax - t0;\n'\
	3481	+ ' var list = document.getElementsByClassName("tblock");\n'\
	3482	+ ' for (var i = 0; i < list.length; i++) {\n'\
	3483	+ ' var timescale = list[i].getElementsByClassName("timescale")[0];\n'\
	3484	+ ' var m0 = t0 + (tTotal*parseFloat(list[i].style.left)/100);\n'\
	3485	+ ' var mTotal = tTotal*parseFloat(list[i].style.width)/100;\n'\
	3486	+ ' var mMax = m0 + mTotal;\n'\
	3487	+ ' var html = "";\n'\
	3488	+ ' var divTotal = Math.floor(mTotal/tS) + 1;\n'\
	3489	+ ' if(divTotal > 1000) continue;\n'\
	3490	+ ' var divEdge = (mTotal - tS(divTotal-1))100/mTotal;\n'\
	3491	+ ' var pos = 0.0, val = 0.0;\n'\
	3492	+ ' for (var j = 0; j < divTotal; j++) {\n'\
	3493	+ ' var htmlline = "";\n'\
	3494	+ ' if(list[i].id[5] == "r") {\n'\
	3495	+ ' pos = 100 - (((j)tS100)/mTotal);\n'\
	3496	+ ' val = (j)*tS;\n'\
	3497	+ ' htmlline = \'<div class="t" style="right:\'+pos+\'%">\'+val+\'ms</div>\';\n'\
	3498	+ ' if(j == 0)\n'\
	3499	+ ' htmlline = rline;\n'\
	3500	+ ' } else {\n'\
	3501	+ ' pos = 100 - (((j)tS100)/mTotal) - divEdge;\n'\
	3502	+ ' val = (j-divTotal+1)*tS;\n'\
	3503	+ ' if(j == divTotal - 1)\n'\
	3504	+ ' htmlline = \'<div class="t" style="right:\'+pos+\'%"><cS>S-></cS></div>\';\n'\
	3505	+ ' else\n'\
	3506	+ ' htmlline = \'<div class="t" style="right:\'+pos+\'%">\'+val+\'ms</div>\';\n'\
	3507	+ ' }\n'\
	3508	+ ' html += htmlline;\n'\
	3509	+ ' }\n'\
	3510	+ ' timescale.innerHTML = html;\n'\
	3511	+ ' }\n'\
	3512	+ ' }\n'\
2480	3513	' function zoomTimeline() {\n'\
2481		− ' var timescale = document.getElementById("timescale");\n'\
2482	3514	' var dmesg = document.getElementById("dmesg");\n'\
2483	3515	' var zoombox = document.getElementById("dmesgzoombox");\n'\
2484	3516	' var val = parseFloat(dmesg.style.width);\n'\
@@ -2486,7 +3518,7 @@ def addScriptCode(hf, testruns): · 1 unmodified line
2486	3518	' var sh = window.outerWidth / 2;\n'\
2487	3519	' if(this.id == "zoomin") {\n'\
2488	3520	' newval = val * 1.2;\n'\
2489		− ' if(newval > 40000) newval = 40000;\n'\
	3521	+ ' if(newval > 910034) newval = 910034;\n'\
2490	3522	' dmesg.style.width = newval+"%";\n'\
2491	3523	' zoombox.scrollLeft = ((zoombox.scrollLeft + sh) * newval / val) - sh;\n'\
2492	3524	' } else if (this.id == "zoomout") {\n'\
@@ -2498,19 +3530,17 @@ def addScriptCode(hf, testruns): · 5 unmodified lines
2498	3530	' zoombox.scrollLeft = 0;\n'\
2499	3531	' dmesg.style.width = "100%";\n'\
2500	3532	' }\n'\
2501		− ' var html = "";\n'\
	3533	+ ' var tS = [10000, 5000, 2000, 1000, 500, 200, 100, 50, 20, 10, 5, 2, 1];\n'\
2502	3534	' var t0 = bounds[0];\n'\
2503	3535	' var tMax = bounds[1];\n'\
2504	3536	' var tTotal = tMax - t0;\n'\
2505	3537	' var wTotal = tTotal * 100.0 / newval;\n'\
2506		− ' for(var tS = 1000; (wTotal / tS) < 3; tS /= 10);\n'\
2507		− ' if(tS < 1) tS = 1;\n'\
2508		− ' for(var s = ((t0 / tS)\|0) * tS; s < tMax; s += tS) {\n'\
2509		− ' var pos = (tMax - s) * 100.0 / tTotal;\n'\
2510		− ' var name = (s == 0)?"S/R":(s+"ms");\n'\
2511		− ' html += "<div class=\\"t\\" style=\\"right:"+pos+"%\\">"+name+"</div>";\n'\
2512		− ' }\n'\
2513		− ' timescale.innerHTML = html;\n'\
	3538	+ ' var idx = 7*window.innerWidth/1100;\n'\
	3539	+ ' for(var i = 0; (i < tS.length)&&((wTotal / tS[i]) < idx); i++);\n'\
	3540	+ ' if(i >= tS.length) i = tS.length - 1;\n'\
	3541	+ ' if(tS[i] == resolution) return;\n'\
	3542	+ ' resolution = tS[i];\n'\
	3543	+ ' redrawTimescale(t0, tMax, tS[i]);\n'\
2514	3544	' }\n'\
2515	3545	' function deviceHover() {\n'\
2516	3546	' var name = this.title.slice(0, this.title.indexOf(" ("));\n'\
@@ -2523,12 +3553,13 @@ def addScriptCode(hf, testruns): · 6 unmodified lines
2523	3553	' cpu = parseInt(name.slice(8));\n'\
2524	3554	' for (var i = 0; i < dev.length; i++) {\n'\
2525	3555	' dname = dev[i].title.slice(0, dev[i].title.indexOf(" ("));\n'\
	3556	+ ' var cname = dev[i].className.slice(dev[i].className.indexOf("thread"));\n'\
2526	3557	' if((cpu >= 0 && dname.match("CPU_O[NF]\\\["+cpu+"\\\]")) \|\|\n'\
2527	3558	' (name == dname))\n'\
2528	3559	' {\n'\
2529		− ' dev[i].className = "thread hover";\n'\
	3560	+ ' dev[i].className = "hover "+cname;\n'\
2530	3561	' } else {\n'\
2531		− ' dev[i].className = "thread";\n'\
	3562	+ ' dev[i].className = cname;\n'\
2532	3563	' }\n'\
2533	3564	' }\n'\
2534	3565	' }\n'\
@@ -2536,7 +3567,7 @@ def addScriptCode(hf, testruns): · 1 unmodified line
2536	3567	' var dmesg = document.getElementById("dmesg");\n'\
2537	3568	' var dev = dmesg.getElementsByClassName("thread");\n'\
2538	3569	' for (var i = 0; i < dev.length; i++) {\n'\
2539		− ' dev[i].className = "thread";\n'\
	3570	+ ' dev[i].className = dev[i].className.slice(dev[i].className.indexOf("thread"));\n'\
2540	3571	' }\n'\
2541	3572	' }\n'\
2542	3573	' function deviceTitle(title, total, cpu) {\n'\
@@ -2547,7 +3578,7 @@ def addScriptCode(hf, testruns): · 4 unmodified lines
2547	3578	' total[2] = (total[2]+total[4])/2;\n'\
2548	3579	' }\n'\
2549	3580	' var devtitle = document.getElementById("devicedetailtitle");\n'\
2550		− ' var name = title.slice(0, title.indexOf(" "));\n'\
	3581	+ ' var name = title.slice(0, title.indexOf(" ("));\n'\
2551	3582	' if(cpu >= 0) name = "CPU"+cpu;\n'\
2552	3583	' var driver = "";\n'\
2553	3584	' var tS = "<t2>(</t2>";\n'\
@@ -2579,6 +3610,8 @@ def addScriptCode(hf, testruns): · 25 unmodified lines
2579	3610	' var dev = dmesg.getElementsByClassName("thread");\n'\
2580	3611	' var idlist = [];\n'\
2581	3612	' var pdata = [[]];\n'\
	3613	+ ' if(document.getElementById("devicedetail1"))\n'\
	3614	+ ' pdata = [[], []];\n'\
2582	3615	' var pd = pdata[0];\n'\
2583	3616	' var total = [0.0, 0.0, 0.0];\n'\
2584	3617	' for (var i = 0; i < dev.length; i++) {\n'\
@@ -2634,6 +3667,7 @@ def addScriptCode(hf, testruns): · 49 unmodified lines
2634	3667	' var cglist = document.getElementById("callgraphs");\n'\
2635	3668	' if(!cglist) return;\n'\
2636	3669	' var cg = cglist.getElementsByClassName("atop");\n'\
	3670	+ ' if(cg.length < 10) return;\n'\
2637	3671	' for (var i = 0; i < cg.length; i++) {\n'\
2638	3672	' if(idlist.indexOf(cg[i].id) >= 0) {\n'\
2639	3673	' cg[i].style.display = "block";\n'\
@@ -2658,15 +3692,32 @@ def addScriptCode(hf, testruns): · 18 unmodified lines
2658	3692	' dt = devtable[1];\n'\
2659	3693	' win.document.write(html+dt);\n'\
2660	3694	' }\n'\
	3695	+ ' function logWindow(e) {\n'\
	3696	+ ' var name = e.target.id.slice(4);\n'\
	3697	+ ' var win = window.open();\n'\
	3698	+ ' var log = document.getElementById(name+"log");\n'\
	3699	+ ' var title = "<title>"+document.title.split(" ")[0]+" "+name+" log</title>";\n'\
	3700	+ ' win.document.write(title+"<pre>"+log.innerHTML+"</pre>");\n'\
	3701	+ ' win.document.close();\n'\
	3702	+ ' }\n'\
	3703	+ ' function onClickPhase(e) {\n'\
	3704	+ ' }\n'\
	3705	+ ' window.addEventListener("resize", function () {zoomTimeline();});\n'\
2661	3706	' window.addEventListener("load", function () {\n'\
2662	3707	' var dmesg = document.getElementById("dmesg");\n'\
2663	3708	' dmesg.style.width = "100%"\n'\
2664	3709	' document.getElementById("zoomin").onclick = zoomTimeline;\n'\
2665	3710	' document.getElementById("zoomout").onclick = zoomTimeline;\n'\
2666	3711	' document.getElementById("zoomdef").onclick = zoomTimeline;\n'\
2667		− ' var devlist = document.getElementsByClassName("devlist");\n'\
2668		− ' for (var i = 0; i < devlist.length; i++)\n'\
2669		− ' devlist[i].onclick = devListWindow;\n'\
	3712	+ ' var list = document.getElementsByClassName("square");\n'\
	3713	+ ' for (var i = 0; i < list.length; i++)\n'\
	3714	+ ' list[i].onclick = onClickPhase;\n'\
	3715	+ ' var list = document.getElementsByClassName("logbtn");\n'\
	3716	+ ' for (var i = 0; i < list.length; i++)\n'\
	3717	+ ' list[i].onclick = logWindow;\n'\
	3718	+ ' list = document.getElementsByClassName("devlist");\n'\
	3719	+ ' for (var i = 0; i < list.length; i++)\n'\
	3720	+ ' list[i].onclick = devListWindow;\n'\
2670	3721	' var dev = dmesg.getElementsByClassName("thread");\n'\
2671	3722	' for (var i = 0; i < dev.length; i++) {\n'\
2672	3723	' dev[i].onclick = deviceDetail;\n'\
@@ -2685,141 +3736,87 @@ def addScriptCode(hf, testruns): · 12 unmodified lines
2685	3736	def executeSuspend():
2686	3737	global sysvals
2687	3738
2688		− detectUSB(False)
2689	3739	t0 = time.time()*1000
2690	3740	tp = sysvals.tpath
	3741	+ fwdata = []
	3742	+ # mark the start point in the kernel ring buffer just as we start
	3743	+ sysvals.initdmesg()
	3744	+ # start ftrace
	3745	+ if(sysvals.usecallgraph or sysvals.usetraceevents):
	3746	+ print('START TRACING')
	3747	+ sysvals.fsetVal('1', 'tracing_on')
2691	3748	# execute however many s/r runs requested
2692	3749	for count in range(1,sysvals.execcount+1):
2693		− # clear the kernel ring buffer just as we start
2694		− os.system('dmesg -C')
2695		− # enable callgraph ftrace only for the second run
2696		− if(sysvals.usecallgraph and count == 2):
2697		− # set trace type
2698		− os.system('echo function_graph > '+tp+'current_tracer')
2699		− os.system('echo "" > '+tp+'set_ftrace_filter')
2700		− # set trace format options
2701		− os.system('echo funcgraph-abstime > '+tp+'trace_options')
2702		− os.system('echo funcgraph-proc > '+tp+'trace_options')
2703		− # focus only on device suspend and resume
2704		− os.system('cat '+tp+'available_filter_functions \| '+\
2705		− 'grep dpm_run_callback > '+tp+'set_graph_function')
2706	3750	# if this is test2 and there's a delay, start here
2707	3751	if(count > 1 and sysvals.x2delay > 0):
2708	3752	tN = time.time()*1000
2709	3753	while (tN - t0) < sysvals.x2delay:
2710	3754	tN = time.time()*1000
2711	3755	time.sleep(0.001)
2712		− # start ftrace
2713		− if(sysvals.usecallgraph or sysvals.usetraceevents):
2714		− print('START TRACING')
2715		− os.system('echo 1 > '+tp+'tracing_on')
2716	3756	# initiate suspend
2717	3757	if(sysvals.usecallgraph or sysvals.usetraceevents):
2718		− os.system('echo SUSPEND START > '+tp+'trace_marker')
2719		− if(sysvals.rtcwake):
2720		− print('SUSPEND START')
2721		− print('will autoresume in %d seconds' % sysvals.rtcwaketime)
2722		− sysvals.rtcWakeAlarm()
	3758	+ sysvals.fsetVal('SUSPEND START', 'trace_marker')
	3759	+ if sysvals.suspendmode == 'command':
	3760	+ print('COMMAND START')
	3761	+ if(sysvals.rtcwake):
	3762	+ print('will issue an rtcwake in %d seconds' % sysvals.rtcwaketime)
	3763	+ sysvals.rtcWakeAlarmOn()
	3764	+ os.system(sysvals.testcommand)
2723	3765	else:
2724		− print('SUSPEND START (press a key to resume)')
2725		− pf = open(sysvals.powerfile, 'w')
2726		− pf.write(sysvals.suspendmode)
2727		− # execution will pause here
2728		− pf.close()
	3766	+ if(sysvals.rtcwake):
	3767	+ print('SUSPEND START')
	3768	+ print('will autoresume in %d seconds' % sysvals.rtcwaketime)
	3769	+ sysvals.rtcWakeAlarmOn()
	3770	+ else:
	3771	+ print('SUSPEND START (press a key to resume)')
	3772	+ pf = open(sysvals.powerfile, 'w')
	3773	+ pf.write(sysvals.suspendmode)
	3774	+ # execution will pause here
	3775	+ try:
	3776	+ pf.close()
	3777	+ except:
	3778	+ pass
2729	3779	t0 = time.time()*1000
	3780	+ if(sysvals.rtcwake):
	3781	+ sysvals.rtcWakeAlarmOff()
2730	3782	# return from suspend
2731	3783	print('RESUME COMPLETE')
2732	3784	if(sysvals.usecallgraph or sysvals.usetraceevents):
2733		− os.system('echo RESUME COMPLETE > '+tp+'trace_marker')
2734		− # see if there's firmware timing data to be had
2735		− t = sysvals.postresumetime
2736		− if(t > 0):
2737		− print('Waiting %d seconds for POST-RESUME trace events...' % t)
2738		− time.sleep(t)
2739		− # stop ftrace
2740		− if(sysvals.usecallgraph or sysvals.usetraceevents):
2741		− os.system('echo 0 > '+tp+'tracing_on')
2742		− print('CAPTURING TRACE')
2743		− writeDatafileHeader(sysvals.ftracefile)
2744		− os.system('cat '+tp+'trace >> '+sysvals.ftracefile)
2745		− os.system('echo "" > '+tp+'trace')
2746		− # grab a copy of the dmesg output
2747		− print('CAPTURING DMESG')
2748		− writeDatafileHeader(sysvals.dmesgfile)
2749		− os.system('dmesg -c >> '+sysvals.dmesgfile)
2750		−
2751		−def writeDatafileHeader(filename):
	3785	+ sysvals.fsetVal('RESUME COMPLETE', 'trace_marker')
	3786	+ if(sysvals.suspendmode == 'mem'):
	3787	+ fwdata.append(getFPDT(False))
	3788	+ # look for post resume events after the last test run
	3789	+ t = sysvals.postresumetime
	3790	+ if(t > 0):
	3791	+ print('Waiting %d seconds for POST-RESUME trace events...' % t)
	3792	+ time.sleep(t)
	3793	+ # stop ftrace
	3794	+ if(sysvals.usecallgraph or sysvals.usetraceevents):
	3795	+ sysvals.fsetVal('0', 'tracing_on')
	3796	+ print('CAPTURING TRACE')
	3797	+ writeDatafileHeader(sysvals.ftracefile, fwdata)
	3798	+ os.system('cat '+tp+'trace >> '+sysvals.ftracefile)
	3799	+ sysvals.fsetVal('', 'trace')
	3800	+ devProps()
	3801	+ # grab a copy of the dmesg output
	3802	+ print('CAPTURING DMESG')
	3803	+ writeDatafileHeader(sysvals.dmesgfile, fwdata)
	3804	+ sysvals.getdmesg()
	3805	+
	3806	+def writeDatafileHeader(filename, fwdata):
2752	3807	global sysvals
2753	3808
2754		− fw = getFPDT(False)
2755	3809	prt = sysvals.postresumetime
2756	3810	fp = open(filename, 'a')
2757	3811	fp.write(sysvals.teststamp+'\n')
2758		− if(fw):
2759		− fp.write('# fwsuspend %u fwresume %u\n' % (fw[0], fw[1]))
	3812	+ if(sysvals.suspendmode == 'mem'):
	3813	+ for fw in fwdata:
	3814	+ if(fw):
	3815	+ fp.write('# fwsuspend %u fwresume %u\n' % (fw[0], fw[1]))
2760	3816	if(prt > 0):
2761	3817	fp.write('# post resume time %u\n' % prt)
2762	3818	fp.close()
2763	3819
2764		−# Function: executeAndroidSuspend
2765		−# Description:
2766		−# Execute system suspend through the sysfs interface
2767		−# on a remote android device, then transfer the output
2768		−# dmesg and ftrace files to the local output directory.
2769		−def executeAndroidSuspend():
2770		− global sysvals
2771		−
2772		− # check to see if the display is currently off
2773		− tp = sysvals.tpath
2774		− out = os.popen(sysvals.adb+\
2775		− ' shell dumpsys power \| grep mScreenOn').read().strip()
2776		− # if so we need to turn it on so we can issue a new suspend
2777		− if(out.endswith('false')):
2778		− print('Waking the device up for the test...')
2779		− # send the KEYPAD_POWER keyevent to wake it up
2780		− os.system(sysvals.adb+' shell input keyevent 26')
2781		− # wait a few seconds so the user can see the device wake up
2782		− time.sleep(3)
2783		− # execute however many s/r runs requested
2784		− for count in range(1,sysvals.execcount+1):
2785		− # clear the kernel ring buffer just as we start
2786		− os.system(sysvals.adb+' shell dmesg -c > /dev/null 2>&1')
2787		− # start ftrace
2788		− if(sysvals.usetraceevents):
2789		− print('START TRACING')
2790		− os.system(sysvals.adb+" shell 'echo 1 > "+tp+"tracing_on'")
2791		− # initiate suspend
2792		− for count in range(1,sysvals.execcount+1):
2793		− if(sysvals.usetraceevents):
2794		− os.system(sysvals.adb+\
2795		− " shell 'echo SUSPEND START > "+tp+"trace_marker'")
2796		− print('SUSPEND START (press a key on the device to resume)')
2797		− os.system(sysvals.adb+" shell 'echo "+sysvals.suspendmode+\
2798		− " > "+sysvals.powerfile+"'")
2799		− # execution will pause here, then adb will exit
2800		− while(True):
2801		− check = os.popen(sysvals.adb+\
2802		− ' shell pwd 2>/dev/null').read().strip()
2803		− if(len(check) > 0):
2804		− break
2805		− time.sleep(1)
2806		− if(sysvals.usetraceevents):
2807		− os.system(sysvals.adb+" shell 'echo RESUME COMPLETE > "+tp+\
2808		− "trace_marker'")
2809		− # return from suspend
2810		− print('RESUME COMPLETE')
2811		− # stop ftrace
2812		− if(sysvals.usetraceevents):
2813		− os.system(sysvals.adb+" shell 'echo 0 > "+tp+"tracing_on'")
2814		− print('CAPTURING TRACE')
2815		− os.system('echo "'+sysvals.teststamp+'" > '+sysvals.ftracefile)
2816		− os.system(sysvals.adb+' shell cat '+tp+\
2817		− 'trace >> '+sysvals.ftracefile)
2818		− # grab a copy of the dmesg output
2819		− print('CAPTURING DMESG')
2820		− os.system('echo "'+sysvals.teststamp+'" > '+sysvals.dmesgfile)
2821		− os.system(sysvals.adb+' shell dmesg >> '+sysvals.dmesgfile)
2822		−
2823	3820	# Function: setUSBDevicesAuto
2824	3821	# Description:
2825	3822	# Set the autosuspend control parameter of all USB devices to auto
@@ -2829,7 +3826,7 @@ def executeAndroidSuspend(): · 3 unmodified lines
2829	3826	def setUSBDevicesAuto():
2830	3827	global sysvals
2831	3828
2832		− rootCheck()
	3829	+ rootCheck(True)
2833	3830	for dirname, dirnames, filenames in os.walk('/sys/devices'):
2834	3831	if(re.match('./usb[0-9].*', dirname) and
2835	3832	'idVendor' in filenames and 'idProduct' in filenames):
@@ -2874,9 +3871,7 @@ def ms2nice(val): · 38 unmodified lines
2874	3871	# Description:
2875	3872	# Detect all the USB hosts and devices currently connected and add
2876	3873	# a list of USB device names to sysvals for better timeline readability
2877		−# Arguments:
2878		−# output: True to output the info to stdout, False otherwise
2879		−def detectUSB(output):
	3874	+def detectUSB():
2880	3875	global sysvals
2881	3876
2882	3877	field = {'idVendor':'', 'idProduct':'', 'product':'', 'speed':''}
@@ -2887,18 +3882,18 @@ def detectUSB(output): · 4 unmodified lines
2887	3882	'runtime_suspended_time':'',
2888	3883	'active_duration':'',
2889	3884	'connected_duration':''}
2890		− if(output):
2891		− print('LEGEND')
2892		− print('---------------------------------------------------------------------------------------------')
2893		− print(' A = async/sync PM queue Y/N D = autosuspend delay (seconds)')
2894		− print(' S = autosuspend Y/N rACTIVE = runtime active (min/sec)')
2895		− print(' P = persist across suspend Y/N rSUSPEN = runtime suspend (min/sec)')
2896		− print(' E = runtime suspend enabled/forbidden Y/N ACTIVE = active duration (min/sec)')
2897		− print(' R = runtime status active/suspended Y/N CONNECT = connected duration (min/sec)')
2898		− print(' U = runtime usage count')
2899		− print('---------------------------------------------------------------------------------------------')
2900		− print(' NAME ID DESCRIPTION SPEED A S P E R U D rACTIVE rSUSPEN ACTIVE CONNECT')
2901		− print('---------------------------------------------------------------------------------------------')
	3885	+
	3886	+ print('LEGEND')
	3887	+ print('---------------------------------------------------------------------------------------------')
	3888	+ print(' A = async/sync PM queue Y/N D = autosuspend delay (seconds)')
	3889	+ print(' S = autosuspend Y/N rACTIVE = runtime active (min/sec)')
	3890	+ print(' P = persist across suspend Y/N rSUSPEN = runtime suspend (min/sec)')
	3891	+ print(' E = runtime suspend enabled/forbidden Y/N ACTIVE = active duration (min/sec)')
	3892	+ print(' R = runtime status active/suspended Y/N CONNECT = connected duration (min/sec)')
	3893	+ print(' U = runtime usage count')
	3894	+ print('---------------------------------------------------------------------------------------------')
	3895	+ print(' NAME ID DESCRIPTION SPEED A S P E R U D rACTIVE rSUSPEN ACTIVE CONNECT')
	3896	+ print('---------------------------------------------------------------------------------------------')
2902	3897
2903	3898	for dirname, dirnames, filenames in os.walk('/sys/devices'):
2904	3899	if(re.match('./usb[0-9].*', dirname) and
@@ -2907,35 +3902,149 @@ def detectUSB(output): · 2 unmodified lines
2907	3902	field[i] = os.popen('cat %s/%s 2>/dev/null' % \
2908	3903	(dirname, i)).read().replace('\n', '')
2909	3904	name = dirname.split('/')[-1]
2910		− if(len(field['product']) > 0):
2911		− sysvals.altdevname[name] = \
2912		− '%s [%s]' % (field['product'], name)
	3905	+ for i in power:
	3906	+ power[i] = os.popen('cat %s/power/%s 2>/dev/null' % \
	3907	+ (dirname, i)).read().replace('\n', '')
	3908	+ if(re.match('usb[0-9]*', name)):
	3909	+ first = '%-8s' % name
2913	3910	else:
2914		− sysvals.altdevname[name] = \
2915		− '%s:%s [%s]' % (field['idVendor'], \
2916		− field['idProduct'], name)
2917		− if(output):
2918		− for i in power:
2919		− power[i] = os.popen('cat %s/power/%s 2>/dev/null' % \
2920		− (dirname, i)).read().replace('\n', '')
2921		− if(re.match('usb[0-9]*', name)):
2922		− first = '%-8s' % name
2923		− else:
2924		− first = '%8s' % name
2925		− print('%s [%s:%s] %-20s %-4s %1s %1s %1s %1s %1s %1s %1s %s %s %s %s' % \
2926		− (first, field['idVendor'], field['idProduct'], \
2927		− field['product'][0:20], field['speed'], \
2928		− yesno(power['async']), \
2929		− yesno(power['control']), \
2930		− yesno(power['persist']), \
2931		− yesno(power['runtime_enabled']), \
2932		− yesno(power['runtime_status']), \
2933		− power['runtime_usage'], \
2934		− power['autosuspend'], \
2935		− ms2nice(power['runtime_active_time']), \
2936		− ms2nice(power['runtime_suspended_time']), \
2937		− ms2nice(power['active_duration']), \
2938		− ms2nice(power['connected_duration'])))
	3911	+ first = '%8s' % name
	3912	+ print('%s [%s:%s] %-20s %-4s %1s %1s %1s %1s %1s %1s %1s %s %s %s %s' % \
	3913	+ (first, field['idVendor'], field['idProduct'], \
	3914	+ field['product'][0:20], field['speed'], \
	3915	+ yesno(power['async']), \
	3916	+ yesno(power['control']), \
	3917	+ yesno(power['persist']), \
	3918	+ yesno(power['runtime_enabled']), \
	3919	+ yesno(power['runtime_status']), \
	3920	+ power['runtime_usage'], \
	3921	+ power['autosuspend'], \
	3922	+ ms2nice(power['runtime_active_time']), \
	3923	+ ms2nice(power['runtime_suspended_time']), \
	3924	+ ms2nice(power['active_duration']), \
	3925	+ ms2nice(power['connected_duration'])))
	3926	+
	3927	+# Function: devProps
	3928	+# Description:
	3929	+# Retrieve a list of properties for all devices in the trace log
	3930	+def devProps(data=0):
	3931	+ global sysvals
	3932	+ props = dict()
	3933	+
	3934	+ if data:
	3935	+ idx = data.index(': ') + 2
	3936	+ if idx >= len(data):
	3937	+ return
	3938	+ devlist = data[idx:].split(';')
	3939	+ for dev in devlist:
	3940	+ f = dev.split(',')
	3941	+ if len(f) < 3:
	3942	+ continue
	3943	+ dev = f[0]
	3944	+ props[dev] = DevProps()
	3945	+ props[dev].altname = f[1]
	3946	+ if int(f[2]):
	3947	+ props[dev].async = True
	3948	+ else:
	3949	+ props[dev].async = False
	3950	+ sysvals.devprops = props
	3951	+ if sysvals.suspendmode == 'command' and 'testcommandstring' in props:
	3952	+ sysvals.testcommand = props['testcommandstring'].altname
	3953	+ return
	3954	+
	3955	+ if(os.path.exists(sysvals.ftracefile) == False):
	3956	+ doError('%s does not exist' % sysvals.ftracefile, False)
	3957	+
	3958	+ # first get the list of devices we need properties for
	3959	+ msghead = 'Additional data added by AnalyzeSuspend'
	3960	+ alreadystamped = False
	3961	+ tp = TestProps()
	3962	+ tf = open(sysvals.ftracefile, 'r')
	3963	+ for line in tf:
	3964	+ if msghead in line:
	3965	+ alreadystamped = True
	3966	+ continue
	3967	+ # determine the trace data type (required for further parsing)
	3968	+ m = re.match(sysvals.tracertypefmt, line)
	3969	+ if(m):
	3970	+ tp.setTracerType(m.group('t'))
	3971	+ continue
	3972	+ # parse only valid lines, if this is not one move on
	3973	+ m = re.match(tp.ftrace_line_fmt, line)
	3974	+ if(not m or 'device_pm_callback_start' not in line):
	3975	+ continue
	3976	+ m = re.match('.: (?P<drv>.) (?P<d>.), parent: (?P<p>.), .', m.group('msg'));
	3977	+ if(not m):
	3978	+ continue
	3979	+ drv, dev, par = m.group('drv'), m.group('d'), m.group('p')
	3980	+ if dev not in props:
	3981	+ props[dev] = DevProps()
	3982	+ tf.close()
	3983	+
	3984	+ if not alreadystamped and sysvals.suspendmode == 'command':
	3985	+ out = '#\n# '+msghead+'\n# Device Properties: '
	3986	+ out += 'testcommandstring,%s,0;' % (sysvals.testcommand)
	3987	+ with open(sysvals.ftracefile, 'a') as fp:
	3988	+ fp.write(out+'\n')
	3989	+ sysvals.devprops = props
	3990	+ return
	3991	+
	3992	+ # now get the syspath for each of our target devices
	3993	+ for dirname, dirnames, filenames in os.walk('/sys/devices'):
	3994	+ if(re.match('.*/power', dirname) and 'async' in filenames):
	3995	+ dev = dirname.split('/')[-2]
	3996	+ if dev in props and (not props[dev].syspath or len(dirname) < len(props[dev].syspath)):
	3997	+ props[dev].syspath = dirname[:-6]
	3998	+
	3999	+ # now fill in the properties for our target devices
	4000	+ for dev in props:
	4001	+ dirname = props[dev].syspath
	4002	+ if not dirname or not os.path.exists(dirname):
	4003	+ continue
	4004	+ with open(dirname+'/power/async') as fp:
	4005	+ text = fp.read()
	4006	+ props[dev].async = False
	4007	+ if 'enabled' in text:
	4008	+ props[dev].async = True
	4009	+ fields = os.listdir(dirname)
	4010	+ if 'product' in fields:
	4011	+ with open(dirname+'/product') as fp:
	4012	+ props[dev].altname = fp.read()
	4013	+ elif 'name' in fields:
	4014	+ with open(dirname+'/name') as fp:
	4015	+ props[dev].altname = fp.read()
	4016	+ elif 'model' in fields:
	4017	+ with open(dirname+'/model') as fp:
	4018	+ props[dev].altname = fp.read()
	4019	+ elif 'description' in fields:
	4020	+ with open(dirname+'/description') as fp:
	4021	+ props[dev].altname = fp.read()
	4022	+ elif 'id' in fields:
	4023	+ with open(dirname+'/id') as fp:
	4024	+ props[dev].altname = fp.read()
	4025	+ elif 'idVendor' in fields and 'idProduct' in fields:
	4026	+ idv, idp = '', ''
	4027	+ with open(dirname+'/idVendor') as fp:
	4028	+ idv = fp.read().strip()
	4029	+ with open(dirname+'/idProduct') as fp:
	4030	+ idp = fp.read().strip()
	4031	+ props[dev].altname = '%s:%s' % (idv, idp)
	4032	+
	4033	+ if props[dev].altname:
	4034	+ out = props[dev].altname.strip().replace('\n', ' ')
	4035	+ out = out.replace(',', ' ')
	4036	+ out = out.replace(';', ' ')
	4037	+ props[dev].altname = out
	4038	+
	4039	+ # and now write the data to the ftrace file
	4040	+ if not alreadystamped:
	4041	+ out = '#\n# '+msghead+'\n# Device Properties: '
	4042	+ for dev in sorted(props):
	4043	+ out += props[dev].out(dev)
	4044	+ with open(sysvals.ftracefile, 'a') as fp:
	4045	+ fp.write(out+'\n')
	4046	+
	4047	+ sysvals.devprops = props
2939	4048
2940	4049	# Function: getModes
2941	4050	# Description:
@@ -2945,15 +4054,10 @@ def detectUSB(output): · 3 unmodified lines
2945	4054	def getModes():
2946	4055	global sysvals
2947	4056	modes = ''
2948		− if(not sysvals.android):
2949		− if(os.path.exists(sysvals.powerfile)):
2950		− fp = open(sysvals.powerfile, 'r')
2951		− modes = string.split(fp.read())
2952		− fp.close()
2953		− else:
2954		− line = os.popen(sysvals.adb+' shell cat '+\
2955		− sysvals.powerfile).read().strip()
2956		− modes = string.split(line)
	4057	+ if(os.path.exists(sysvals.powerfile)):
	4058	+ fp = open(sysvals.powerfile, 'r')
	4059	+ modes = string.split(fp.read())
	4060	+ fp.close()
2957	4061	return modes
2958	4062
2959	4063	# Function: getFPDT
@@ -2971,22 +4075,22 @@ def getFPDT(output): · 11 unmodified lines
2971	4075	prectype[0] = 'Basic S3 Resume Performance Record'
2972	4076	prectype[1] = 'Basic S3 Suspend Performance Record'
2973	4077
2974		− rootCheck()
	4078	+ rootCheck(True)
2975	4079	if(not os.path.exists(sysvals.fpdtpath)):
2976	4080	if(output):
2977		− doError('file doesnt exist: %s' % sysvals.fpdtpath, False)
	4081	+ doError('file does not exist: %s' % sysvals.fpdtpath, False)
2978	4082	return False
2979	4083	if(not os.access(sysvals.fpdtpath, os.R_OK)):
2980	4084	if(output):
2981		− doError('file isnt readable: %s' % sysvals.fpdtpath, False)
	4085	+ doError('file is not readable: %s' % sysvals.fpdtpath, False)
2982	4086	return False
2983	4087	if(not os.path.exists(sysvals.mempath)):
2984	4088	if(output):
2985		− doError('file doesnt exist: %s' % sysvals.mempath, False)
	4089	+ doError('file does not exist: %s' % sysvals.mempath, False)
2986	4090	return False
2987	4091	if(not os.access(sysvals.mempath, os.R_OK)):
2988	4092	if(output):
2989		− doError('file isnt readable: %s' % sysvals.mempath, False)
	4093	+ doError('file is not readable: %s' % sysvals.mempath, False)
2990	4094	return False
2991	4095
2992	4096	fp = open(sysvals.fpdtpath, 'rb')
@@ -3027,15 +4131,19 @@ def getFPDT(output): · 34 unmodified lines
3027	4131	while(i < len(records)):
3028	4132	header = struct.unpack('HBB', records[i:i+4])
3029	4133	if(header[0] not in rectype):
	4134	+ i += header[1]
3030	4135	continue
3031	4136	if(header[1] != 16):
	4137	+ i += header[1]
3032	4138	continue
3033	4139	addr = struct.unpack('Q', records[i+8:i+16])[0]
3034	4140	try:
3035	4141	fp.seek(addr)
3036	4142	first = fp.read(8)
3037	4143	except:
3038		− doError('Bad address 0x%x in %s' % (addr, sysvals.mempath), False)
	4144	+ if(output):
	4145	+ print('Bad address 0x%x in %s' % (addr, sysvals.mempath))
	4146	+ return [0, 0]
3039	4147	rechead = struct.unpack('4sI', first)
3040	4148	recdata = fp.read(rechead[1]-8)
3041	4149	if(rechead[0] == 'FBPT'):
@@ -3090,89 +4198,60 @@ def getFPDT(output): · 48 unmodified lines
3090	4198	# print the results to the terminal
3091	4199	# Output:
3092	4200	# True if the test will work, False if not
3093		−def statusCheck():
	4201	+def statusCheck(probecheck=False):
3094	4202	global sysvals
3095	4203	status = True
3096	4204
3097		− if(sysvals.android):
3098		− print('Checking the android system ...')
3099		− else:
3100		− print('Checking this system (%s)...' % platform.node())
3101		−
3102		− # check if adb is connected to a device
3103		− if(sysvals.android):
3104		− res = 'NO'
3105		− out = os.popen(sysvals.adb+' get-state').read().strip()
3106		− if(out == 'device'):
3107		− res = 'YES'
3108		− print(' is android device connected: %s' % res)
3109		− if(res != 'YES'):
3110		− print(' Please connect the device before using this tool')
3111		− return False
	4205	+ print('Checking this system (%s)...' % platform.node())
3112	4206
3113	4207	# check we have root access
3114		− res = 'NO (No features of this tool will work!)'
3115		− if(sysvals.android):
3116		− out = os.popen(sysvals.adb+' shell id').read().strip()
3117		− if('root' in out):
3118		− res = 'YES'
3119		− else:
3120		− if(os.environ['USER'] == 'root'):
3121		− res = 'YES'
	4208	+ res = sysvals.colorText('NO (No features of this tool will work!)')
	4209	+ if(rootCheck(False)):
	4210	+ res = 'YES'
3122	4211	print(' have root access: %s' % res)
3123	4212	if(res != 'YES'):
3124		− if(sysvals.android):
3125		− print(' Try running "adb root" to restart the daemon as root')
3126		− else:
3127		− print(' Try running this script with sudo')
	4213	+ print(' Try running this script with sudo')
3128	4214	return False
3129	4215
3130	4216	# check sysfs is mounted
3131		− res = 'NO (No features of this tool will work!)'
3132		− if(sysvals.android):
3133		− out = os.popen(sysvals.adb+' shell ls '+\
3134		− sysvals.powerfile).read().strip()
3135		− if(out == sysvals.powerfile):
3136		− res = 'YES'
3137		− else:
3138		− if(os.path.exists(sysvals.powerfile)):
3139		− res = 'YES'
	4217	+ res = sysvals.colorText('NO (No features of this tool will work!)')
	4218	+ if(os.path.exists(sysvals.powerfile)):
	4219	+ res = 'YES'
3140	4220	print(' is sysfs mounted: %s' % res)
3141	4221	if(res != 'YES'):
3142	4222	return False
3143	4223
3144	4224	# check target mode is a valid mode
3145		− res = 'NO'
3146		− modes = getModes()
3147		− if(sysvals.suspendmode in modes):
3148		− res = 'YES'
3149		− else:
3150		− status = False
3151		− print(' is "%s" a valid power mode: %s' % (sysvals.suspendmode, res))
3152		− if(res == 'NO'):
3153		− print(' valid power modes are: %s' % modes)
3154		− print(' please choose one with -m')
3155		−
3156		− # check if the tool can unlock the device
3157		− if(sysvals.android):
3158		− res = 'YES'
3159		− out1 = os.popen(sysvals.adb+\
3160		− ' shell dumpsys power \| grep mScreenOn').read().strip()
3161		− out2 = os.popen(sysvals.adb+\
3162		− ' shell input').read().strip()
3163		− if(not out1.startswith('mScreenOn') or not out2.startswith('usage')):
3164		− res = 'NO (wake the android device up before running the test)'
3165		− print(' can I unlock the screen: %s' % res)
	4225	+ if sysvals.suspendmode != 'command':
	4226	+ res = sysvals.colorText('NO')
	4227	+ modes = getModes()
	4228	+ if(sysvals.suspendmode in modes):
	4229	+ res = 'YES'
	4230	+ else:
	4231	+ status = False
	4232	+ print(' is "%s" a valid power mode: %s' % (sysvals.suspendmode, res))
	4233	+ if(res == 'NO'):
	4234	+ print(' valid power modes are: %s' % modes)
	4235	+ print(' please choose one with -m')
3166	4236
3167	4237	# check if ftrace is available
3168		− res = 'NO'
3169		− ftgood = verifyFtrace()
	4238	+ res = sysvals.colorText('NO')
	4239	+ ftgood = sysvals.verifyFtrace()
3170	4240	if(ftgood):
3171	4241	res = 'YES'
3172	4242	elif(sysvals.usecallgraph):
3173	4243	status = False
3174	4244	print(' is ftrace supported: %s' % res)
3175	4245
	4246	+ # check if kprobes are available
	4247	+ res = sysvals.colorText('NO')
	4248	+ sysvals.usekprobes = sysvals.verifyKprobes()
	4249	+ if(sysvals.usekprobes):
	4250	+ res = 'YES'
	4251	+ else:
	4252	+ sysvals.usedevsrc = False
	4253	+ print(' are kprobes supported: %s' % res)
	4254	+
3176	4255	# what data source are we using
3177	4256	res = 'DMESG'
3178	4257	if(ftgood):
@@ -3180,14 +4259,8 @@ def statusCheck(): · 1 unmodified line
3180	4259	sysvals.usetraceevents = False
3181	4260	for e in sysvals.traceevents:
3182	4261	check = False
3183		− if(sysvals.android):
3184		− out = os.popen(sysvals.adb+' shell ls -d '+\
3185		− sysvals.epath+e).read().strip()
3186		− if(out == sysvals.epath+e):
3187		− check = True
3188		− else:
3189		− if(os.path.exists(sysvals.epath+e)):
3190		− check = True
	4262	+ if(os.path.exists(sysvals.epath+e)):
	4263	+ check = True
3191	4264	if(not check):
3192	4265	sysvals.usetraceeventsonly = False
3193	4266	if(e == 'suspend_resume' and check):
@@ -3199,13 +4272,48 @@ def statusCheck(): · 5 unmodified lines
3199	4272	print(' timeline data source: %s' % res)
3200	4273
3201	4274	# check if rtcwake
3202		− res = 'NO'
	4275	+ res = sysvals.colorText('NO')
3203	4276	if(sysvals.rtcpath != ''):
3204	4277	res = 'YES'
3205	4278	elif(sysvals.rtcwake):
3206	4279	status = False
3207	4280	print(' is rtcwake supported: %s' % res)
3208	4281
	4282	+ if not probecheck:
	4283	+ return status
	4284	+
	4285	+ if (sysvals.usecallgraph and len(sysvals.debugfuncs) > 0) or len(sysvals.kprobes) > 0:
	4286	+ sysvals.initFtrace(True)
	4287	+
	4288	+ # verify callgraph debugfuncs
	4289	+ if sysvals.usecallgraph and len(sysvals.debugfuncs) > 0:
	4290	+ print(' verifying these ftrace callgraph functions work:')
	4291	+ sysvals.setFtraceFilterFunctions(sysvals.debugfuncs)
	4292	+ fp = open(sysvals.tpath+'set_graph_function', 'r')
	4293	+ flist = fp.read().split('\n')
	4294	+ fp.close()
	4295	+ for func in sysvals.debugfuncs:
	4296	+ res = sysvals.colorText('NO')
	4297	+ if func in flist:
	4298	+ res = 'YES'
	4299	+ else:
	4300	+ for i in flist:
	4301	+ if ' [' in i and func == i.split(' ')[0]:
	4302	+ res = 'YES'
	4303	+ break
	4304	+ print(' %s: %s' % (func, res))
	4305	+
	4306	+ # verify kprobes
	4307	+ if len(sysvals.kprobes) > 0:
	4308	+ print(' verifying these kprobes work:')
	4309	+ for name in sorted(sysvals.kprobes):
	4310	+ if name in sysvals.tracefuncs:
	4311	+ continue
	4312	+ res = sysvals.colorText('NO')
	4313	+ if sysvals.testKprobe(sysvals.kprobes[name]):
	4314	+ res = 'YES'
	4315	+ print(' %s: %s' % (name, res))
	4316	+
3209	4317	return status
3210	4318
3211	4319	# Function: doError
@@ -3226,7 +4334,7 @@ def doError(msg, help): · 14 unmodified lines
3226	4334	# Arguments:
3227	4335	# msg: the warning message to print
3228	4336	# file: If not empty, a filename to request be sent to the owner for debug
3229		−def doWarning(msg, file):
	4337	+def doWarning(msg, file=''):
3230	4338	print('/* %s */') % msg
3231	4339	if(file):
3232	4340	print('/* For a fix, please send this'+\
@@ -3235,18 +4343,25 @@ def doWarning(msg, file): · 2 unmodified lines
3235	4343	# Function: rootCheck
3236	4344	# Description:
3237	4345	# quick check to see if we have root access
3238		−def rootCheck():
3239		− if(os.environ['USER'] != 'root'):
3240		− doError('This script must be run as root', False)
	4346	+def rootCheck(fatal):
	4347	+ global sysvals
	4348	+ if(os.access(sysvals.powerfile, os.W_OK)):
	4349	+ return True
	4350	+ if fatal:
	4351	+ doError('This command must be run as root', False)
	4352	+ return False
3241	4353
3242	4354	# Function: getArgInt
3243	4355	# Description:
3244	4356	# pull out an integer argument from the command line with checks
3245		−def getArgInt(name, args, min, max):
3246		− try:
3247		− arg = args.next()
3248		− except:
3249		− doError(name+': no argument supplied', True)
	4357	+def getArgInt(name, args, min, max, main=True):
	4358	+ if main:
	4359	+ try:
	4360	+ arg = args.next()
	4361	+ except:
	4362	+ doError(name+': no argument supplied', True)
	4363	+ else:
	4364	+ arg = args
3250	4365	try:
3251	4366	val = int(arg)
3252	4367	except:
@@ -3255,6 +4370,25 @@ def getArgInt(name, args, min, max): · 2 unmodified lines
3255	4370	doError(name+': value should be between %d and %d' % (min, max), True)
3256	4371	return val
3257	4372
	4373	+# Function: getArgFloat
	4374	+# Description:
	4375	+# pull out a float argument from the command line with checks
	4376	+def getArgFloat(name, args, min, max, main=True):
	4377	+ if main:
	4378	+ try:
	4379	+ arg = args.next()
	4380	+ except:
	4381	+ doError(name+': no argument supplied', True)
	4382	+ else:
	4383	+ arg = args
	4384	+ try:
	4385	+ val = float(arg)
	4386	+ except:
	4387	+ doError(name+': non-numerical value given', True)
	4388	+ if(val < min or val > max):
	4389	+ doError(name+': value should be between %f and %f' % (min, max), True)
	4390	+ return val
	4391	+
3258	4392	# Function: rerunTest
3259	4393	# Description:
3260	4394	# generate an output from an existing set of ftrace/dmesg logs
@@ -3282,15 +4416,12 @@ def rerunTest(): · 21 unmodified lines
3282	4416	# Function: runTest
3283	4417	# Description:
3284	4418	# execute a suspend/resume, gather the logs, and generate the output
3285		−def runTest(subdir):
	4419	+def runTest(subdir, testpath=''):
3286	4420	global sysvals
3287	4421
3288	4422	# prepare for the test
3289		− if(not sysvals.android):
3290		− initFtrace()
3291		− else:
3292		− initFtraceAndroid()
3293		− sysvals.initTestOutput(subdir)
	4423	+ sysvals.initFtrace()
	4424	+ sysvals.initTestOutput(subdir, testpath)
3294	4425
3295	4426	vprint('Output files:\n %s' % sysvals.dmesgfile)
3296	4427	if(sysvals.usecallgraph or
@@ -3300,10 +4431,8 @@ def runTest(subdir): · 3 unmodified lines
3300	4431	vprint(' %s' % sysvals.htmlfile)
3301	4432
3302	4433	# execute the test
3303		− if(not sysvals.android):
3304		− executeSuspend()
3305		− else:
3306		− executeAndroidSuspend()
	4434	+ executeSuspend()
	4435	+ sysvals.cleanupFtrace()
3307	4436
3308	4437	# analyze the data and create the html output
3309	4438	print('PROCESSING DATA')
@@ -3367,6 +4496,153 @@ def runSummary(subdir, output): · 57 unmodified lines
3367	4496
3368	4497	createHTMLSummarySimple(testruns, subdir+'/summary.html')
3369	4498
	4499	+# Function: checkArgBool
	4500	+# Description:
	4501	+# check if a boolean string value is true or false
	4502	+def checkArgBool(value):
	4503	+ yes = ['1', 'true', 'yes', 'on']
	4504	+ if value.lower() in yes:
	4505	+ return True
	4506	+ return False
	4507	+
	4508	+# Function: configFromFile
	4509	+# Description:
	4510	+# Configure the script via the info in a config file
	4511	+def configFromFile(file):
	4512	+ global sysvals
	4513	+ Config = ConfigParser.ConfigParser()
	4514	+
	4515	+ ignorekprobes = False
	4516	+ Config.read(file)
	4517	+ sections = Config.sections()
	4518	+ if 'Settings' in sections:
	4519	+ for opt in Config.options('Settings'):
	4520	+ value = Config.get('Settings', opt).lower()
	4521	+ if(opt.lower() == 'verbose'):
	4522	+ sysvals.verbose = checkArgBool(value)
	4523	+ elif(opt.lower() == 'addlogs'):
	4524	+ sysvals.addlogs = checkArgBool(value)
	4525	+ elif(opt.lower() == 'dev'):
	4526	+ sysvals.usedevsrc = checkArgBool(value)
	4527	+ elif(opt.lower() == 'ignorekprobes'):
	4528	+ ignorekprobes = checkArgBool(value)
	4529	+ elif(opt.lower() == 'x2'):
	4530	+ if checkArgBool(value):
	4531	+ sysvals.execcount = 2
	4532	+ elif(opt.lower() == 'callgraph'):
	4533	+ sysvals.usecallgraph = checkArgBool(value)
	4534	+ elif(opt.lower() == 'callgraphfunc'):
	4535	+ sysvals.debugfuncs = []
	4536	+ if value:
	4537	+ value = value.split(',')
	4538	+ for i in value:
	4539	+ sysvals.debugfuncs.append(i.strip())
	4540	+ elif(opt.lower() == 'expandcg'):
	4541	+ sysvals.cgexp = checkArgBool(value)
	4542	+ elif(opt.lower() == 'srgap'):
	4543	+ if checkArgBool(value):
	4544	+ sysvals.srgap = 5
	4545	+ elif(opt.lower() == 'mode'):
	4546	+ sysvals.suspendmode = value
	4547	+ elif(opt.lower() == 'command'):
	4548	+ sysvals.testcommand = value
	4549	+ elif(opt.lower() == 'x2delay'):
	4550	+ sysvals.x2delay = getArgInt('-x2delay', value, 0, 60000, False)
	4551	+ elif(opt.lower() == 'postres'):
	4552	+ sysvals.postresumetime = getArgInt('-postres', value, 0, 3600, False)
	4553	+ elif(opt.lower() == 'rtcwake'):
	4554	+ sysvals.rtcwake = True
	4555	+ sysvals.rtcwaketime = getArgInt('-rtcwake', value, 0, 3600, False)
	4556	+ elif(opt.lower() == 'timeprec'):
	4557	+ sysvals.setPrecision(getArgInt('-timeprec', value, 0, 6, False))
	4558	+ elif(opt.lower() == 'mindev'):
	4559	+ sysvals.mindevlen = getArgFloat('-mindev', value, 0.0, 10000.0, False)
	4560	+ elif(opt.lower() == 'mincg'):
	4561	+ sysvals.mincglen = getArgFloat('-mincg', value, 0.0, 10000.0, False)
	4562	+ elif(opt.lower() == 'kprobecolor'):
	4563	+ try:
	4564	+ val = int(value, 16)
	4565	+ sysvals.kprobecolor = '#'+value
	4566	+ except:
	4567	+ sysvals.kprobecolor = value
	4568	+ elif(opt.lower() == 'synccolor'):
	4569	+ try:
	4570	+ val = int(value, 16)
	4571	+ sysvals.synccolor = '#'+value
	4572	+ except:
	4573	+ sysvals.synccolor = value
	4574	+ elif(opt.lower() == 'output-dir'):
	4575	+ args = dict()
	4576	+ n = datetime.now()
	4577	+ args['date'] = n.strftime('%y%m%d')
	4578	+ args['time'] = n.strftime('%H%M%S')
	4579	+ args['hostname'] = sysvals.hostname
	4580	+ sysvals.outdir = value.format(**args)
	4581	+
	4582	+ if sysvals.suspendmode == 'command' and not sysvals.testcommand:
	4583	+ doError('No command supplied for mode "command"', False)
	4584	+ if sysvals.usedevsrc and sysvals.usecallgraph:
	4585	+ doError('dev and callgraph cannot both be true', False)
	4586	+ if sysvals.usecallgraph and sysvals.execcount > 1:
	4587	+ doError('-x2 is not compatible with -f', False)
	4588	+
	4589	+ if ignorekprobes:
	4590	+ return
	4591	+
	4592	+ kprobes = dict()
	4593	+ archkprobe = 'Kprobe_'+platform.machine()
	4594	+ if archkprobe in sections:
	4595	+ for name in Config.options(archkprobe):
	4596	+ kprobes[name] = Config.get(archkprobe, name)
	4597	+ if 'Kprobe' in sections:
	4598	+ for name in Config.options('Kprobe'):
	4599	+ kprobes[name] = Config.get('Kprobe', name)
	4600	+
	4601	+ for name in kprobes:
	4602	+ function = name
	4603	+ format = name
	4604	+ color = ''
	4605	+ args = dict()
	4606	+ data = kprobes[name].split()
	4607	+ i = 0
	4608	+ for val in data:
	4609	+ # bracketted strings are special formatting, read them separately
	4610	+ if val[0] == '[' and val[-1] == ']':
	4611	+ for prop in val[1:-1].split(','):
	4612	+ p = prop.split('=')
	4613	+ if p[0] == 'color':
	4614	+ try:
	4615	+ color = int(p[1], 16)
	4616	+ color = '#'+p[1]
	4617	+ except:
	4618	+ color = p[1]
	4619	+ continue
	4620	+ # first real arg should be the format string
	4621	+ if i == 0:
	4622	+ format = val
	4623	+ # all other args are actual function args
	4624	+ else:
	4625	+ d = val.split('=')
	4626	+ args[d[0]] = d[1]
	4627	+ i += 1
	4628	+ if not function or not format:
	4629	+ doError('Invalid kprobe: %s' % name, False)
	4630	+ for arg in re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', format):
	4631	+ if arg not in args:
	4632	+ doError('Kprobe "%s" is missing argument "%s"' % (name, arg), False)
	4633	+ if name in sysvals.kprobes:
	4634	+ doError('Duplicate kprobe found "%s"' % (name), False)
	4635	+ vprint('Adding KPROBE: %s %s %s %s' % (name, function, format, args))
	4636	+ sysvals.kprobes[name] = {
	4637	+ 'name': name,
	4638	+ 'func': function,
	4639	+ 'format': format,
	4640	+ 'args': args,
	4641	+ 'mask': re.sub('{(?P<n>[a-z,A-Z,0-9])}', '.', format)
	4642	+ }
	4643	+ if color:
	4644	+ sysvals.kprobes[name]['color'] = color
	4645	+
3370	4646	# Function: printHelp
3371	4647	# Description:
3372	4648	# print out the help text
@@ -3375,7 +4651,7 @@ def printHelp(): · 2 unmodified lines
3375	4651	modes = getModes()
3376	4652
3377	4653	print('')
3378		− print('AnalyzeSuspend v%.1f' % sysvals.version)
	4654	+ print('AnalyzeSuspend v%s' % sysvals.version)
3379	4655	print('Usage: sudo analyze_suspend.py <options>')
3380	4656	print('')
3381	4657	print('Description:')
@@ -3396,27 +4672,38 @@ def printHelp(): · 14 unmodified lines
3396	4672	print(' [general]')
3397	4673	print(' -h Print this help text')
3398	4674	print(' -v Print the current tool version')
	4675	+ print(' -config file Pull arguments and config options from a file')
3399	4676	print(' -verbose Print extra information during execution and analysis')
3400	4677	print(' -status Test to see if the system is enabled to run this tool')
3401	4678	print(' -modes List available suspend modes')
3402	4679	print(' -m mode Mode to initiate for suspend %s (default: %s)') % (modes, sysvals.suspendmode)
3403		− print(' -rtcwake t Use rtcwake to autoresume after <t> seconds (default: disabled)')
	4680	+ print(' -o subdir Override the output subdirectory')
3404	4681	print(' [advanced]')
	4682	+ print(' -rtcwake t Use rtcwake to autoresume after <t> seconds (default: disabled)')
	4683	+ print(' -addlogs Add the dmesg and ftrace logs to the html output')
	4684	+ print(' -multi n d Execute <n> consecutive tests at <d> seconds intervals. The outputs will')
	4685	+ print(' be created in a new subdirectory with a summary page.')
	4686	+ print(' -srgap Add a visible gap in the timeline between sus/res (default: disabled)')
	4687	+ print(' -cmd {s} Instead of suspend/resume, run a command, e.g. "sync -d"')
	4688	+ print(' -mindev ms Discard all device blocks shorter than ms milliseconds (e.g. 0.001 for us)')
	4689	+ print(' -mincg ms Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)')
	4690	+ print(' -timeprec N Number of significant digits in timestamps (0:S, [3:ms], 6:us)')
	4691	+ print(' [debug]')
3405	4692	print(' -f Use ftrace to create device callgraphs (default: disabled)')
3406		− print(' -filter "d1 d2 ..." Filter out all but this list of dev names')
	4693	+ print(' -expandcg pre-expand the callgraph data in the html output (default: disabled)')
	4694	+ print(' -flist Print the list of functions currently being captured in ftrace')
	4695	+ print(' -flistall Print all functions capable of being captured in ftrace')
	4696	+ print(' -fadd file Add functions to be graphed in the timeline from a list in a text file')
	4697	+ print(' -filter "d1 d2 ..." Filter out all but this list of device names')
	4698	+ print(' -dev Display common low level functions in the timeline')
	4699	+ print(' [post-resume task analysis]')
3407	4700	print(' -x2 Run two suspend/resumes back to back (default: disabled)')
3408	4701	print(' -x2delay t Minimum millisecond delay <t> between the two test runs (default: 0 ms)')
3409	4702	print(' -postres t Time after resume completion to wait for post-resume events (default: 0 S)')
3410		− print(' -multi n d Execute <n> consecutive tests at <d> seconds intervals. The outputs will')
3411		− print(' be created in a new subdirectory with a summary page.')
3412	4703	print(' [utilities]')
3413	4704	print(' -fpdt Print out the contents of the ACPI Firmware Performance Data Table')
3414	4705	print(' -usbtopo Print out the current USB topology with power info')
3415	4706	print(' -usbauto Enable autosuspend for all connected USB devices')
3416		− print(' [android testing]')
3417		− print(' -adb binary Use the given adb binary to run the test on an android device.')
3418		− print(' The device should already be connected and with root access.')
3419		− print(' Commands will be executed on the device using "adb shell"')
3420	4707	print(' [re-analyze data from previous runs]')
3421	4708	print(' -ftrace ftracefile Create HTML output using ftrace input')
3422	4709	print(' -dmesg dmesgfile Create HTML output using dmesg (not needed for kernel >= 3.15)')
@@ -3430,6 +4717,7 @@ if __name__ == '__main__': · 7 unmodified lines
3430	4717	cmd = ''
3431	4718	cmdarg = ''
3432	4719	multitest = {'run': False, 'count': 0, 'delay': 0}
	4720	+ simplecmds = ['-modes', '-fpdt', '-flist', '-flistall', '-usbtopo', '-usbauto', '-status']
3433	4721	# loop through the command line arguments
3434	4722	args = iter(sys.argv[1:])
3435	4723	for arg in args:
@@ -3438,58 +4726,85 @@ if __name__ == '__main__': · 2 unmodified lines
3438	4726	val = args.next()
3439	4727	except:
3440	4728	doError('No mode supplied', True)
	4729	+ if val == 'command' and not sysvals.testcommand:
	4730	+ doError('No command supplied for mode "command"', True)
3441	4731	sysvals.suspendmode = val
3442		− elif(arg == '-adb'):
3443		− try:
3444		− val = args.next()
3445		− except:
3446		− doError('No adb binary supplied', True)
3447		− if(not os.path.exists(val)):
3448		− doError('file doesnt exist: %s' % val, False)
3449		− if(not os.access(val, os.X_OK)):
3450		− doError('file isnt executable: %s' % val, False)
3451		− try:
3452		− check = os.popen(val+' version').read().strip()
3453		− except:
3454		− doError('adb version failed to execute', False)
3455		− if(not re.match('Android Debug Bridge .*', check)):
3456		− doError('adb version failed to execute', False)
3457		− sysvals.adb = val
3458		− sysvals.android = True
	4732	+ elif(arg in simplecmds):
	4733	+ cmd = arg[1:]
	4734	+ elif(arg == '-h'):
	4735	+ printHelp()
	4736	+ sys.exit()
	4737	+ elif(arg == '-v'):
	4738	+ print("Version %s" % sysvals.version)
	4739	+ sys.exit()
3459	4740	elif(arg == '-x2'):
3460		− if(sysvals.postresumetime > 0):
3461		− doError('-x2 is not compatible with -postres', False)
3462	4741	sysvals.execcount = 2
	4742	+ if(sysvals.usecallgraph):
	4743	+ doError('-x2 is not compatible with -f', False)
3463	4744	elif(arg == '-x2delay'):
3464	4745	sysvals.x2delay = getArgInt('-x2delay', args, 0, 60000)
3465	4746	elif(arg == '-postres'):
3466		− if(sysvals.execcount != 1):
3467		− doError('-x2 is not compatible with -postres', False)
3468	4747	sysvals.postresumetime = getArgInt('-postres', args, 0, 3600)
3469	4748	elif(arg == '-f'):
3470	4749	sysvals.usecallgraph = True
3471		− elif(arg == '-modes'):
3472		− cmd = 'modes'
3473		− elif(arg == '-fpdt'):
3474		− cmd = 'fpdt'
3475		− elif(arg == '-usbtopo'):
3476		− cmd = 'usbtopo'
3477		− elif(arg == '-usbauto'):
3478		− cmd = 'usbauto'
3479		− elif(arg == '-status'):
3480		− cmd = 'status'
	4750	+ if(sysvals.execcount > 1):
	4751	+ doError('-x2 is not compatible with -f', False)
	4752	+ if(sysvals.usedevsrc):
	4753	+ doError('-dev is not compatible with -f', False)
	4754	+ elif(arg == '-addlogs'):
	4755	+ sysvals.addlogs = True
3481	4756	elif(arg == '-verbose'):
3482	4757	sysvals.verbose = True
3483		− elif(arg == '-v'):
3484		− print("Version %.1f" % sysvals.version)
3485		− sys.exit()
	4758	+ elif(arg == '-dev'):
	4759	+ sysvals.usedevsrc = True
	4760	+ if(sysvals.usecallgraph):
	4761	+ doError('-dev is not compatible with -f', False)
3486	4762	elif(arg == '-rtcwake'):
3487	4763	sysvals.rtcwake = True
3488	4764	sysvals.rtcwaketime = getArgInt('-rtcwake', args, 0, 3600)
	4765	+ elif(arg == '-timeprec'):
	4766	+ sysvals.setPrecision(getArgInt('-timeprec', args, 0, 6))
	4767	+ elif(arg == '-mindev'):
	4768	+ sysvals.mindevlen = getArgFloat('-mindev', args, 0.0, 10000.0)
	4769	+ elif(arg == '-mincg'):
	4770	+ sysvals.mincglen = getArgFloat('-mincg', args, 0.0, 10000.0)
	4771	+ elif(arg == '-cmd'):
	4772	+ try:
	4773	+ val = args.next()
	4774	+ except:
	4775	+ doError('No command string supplied', True)
	4776	+ sysvals.testcommand = val
	4777	+ sysvals.suspendmode = 'command'
	4778	+ elif(arg == '-expandcg'):
	4779	+ sysvals.cgexp = True
	4780	+ elif(arg == '-srgap'):
	4781	+ sysvals.srgap = 5
3489	4782	elif(arg == '-multi'):
3490	4783	multitest['run'] = True
3491	4784	multitest['count'] = getArgInt('-multi n (exec count)', args, 2, 1000000)
3492	4785	multitest['delay'] = getArgInt('-multi d (delay between tests)', args, 0, 3600)
	4786	+ elif(arg == '-o'):
	4787	+ try:
	4788	+ val = args.next()
	4789	+ except:
	4790	+ doError('No subdirectory name supplied', True)
	4791	+ sysvals.outdir = val
	4792	+ elif(arg == '-config'):
	4793	+ try:
	4794	+ val = args.next()
	4795	+ except:
	4796	+ doError('No text file supplied', True)
	4797	+ if(os.path.exists(val) == False):
	4798	+ doError('%s does not exist' % val, False)
	4799	+ configFromFile(val)
	4800	+ elif(arg == '-fadd'):
	4801	+ try:
	4802	+ val = args.next()
	4803	+ except:
	4804	+ doError('No text file supplied', True)
	4805	+ if(os.path.exists(val) == False):
	4806	+ doError('%s does not exist' % val, False)
	4807	+ sysvals.addFtraceFilterFunctions(val)
3493	4808	elif(arg == '-dmesg'):
3494	4809	try:
3495	4810	val = args.next()
@@ -3498,17 +4813,16 @@ if __name__ == '__main__': · 2 unmodified lines
3498	4813	sysvals.notestrun = True
3499	4814	sysvals.dmesgfile = val
3500	4815	if(os.path.exists(sysvals.dmesgfile) == False):
3501		− doError('%s doesnt exist' % sysvals.dmesgfile, False)
	4816	+ doError('%s does not exist' % sysvals.dmesgfile, False)
3502	4817	elif(arg == '-ftrace'):
3503	4818	try:
3504	4819	val = args.next()
3505	4820	except:
3506	4821	doError('No ftrace file supplied', True)
3507	4822	sysvals.notestrun = True
3508		− sysvals.usecallgraph = True
3509	4823	sysvals.ftracefile = val
3510	4824	if(os.path.exists(sysvals.ftracefile) == False):
3511		− doError('%s doesnt exist' % sysvals.ftracefile, False)
	4825	+ doError('%s does not exist' % sysvals.ftracefile, False)
3512	4826	elif(arg == '-summary'):
3513	4827	try:
3514	4828	val = args.next()
@@ -3518,35 +4832,35 @@ if __name__ == '__main__': · 3 unmodified lines
3518	4832	cmdarg = val
3519	4833	sysvals.notestrun = True
3520	4834	if(os.path.isdir(val) == False):
3521		− doError('%s isnt accesible' % val, False)
	4835	+ doError('%s is not accesible' % val, False)
3522	4836	elif(arg == '-filter'):
3523	4837	try:
3524	4838	val = args.next()
3525	4839	except:
3526	4840	doError('No devnames supplied', True)
3527	4841	sysvals.setDeviceFilter(val)
3528		− elif(arg == '-h'):
3529		− printHelp()
3530		− sys.exit()
3531	4842	else:
3532	4843	doError('Invalid argument: '+arg, True)
3533	4844
	4845	+ # callgraph size cannot exceed device size
	4846	+ if sysvals.mincglen < sysvals.mindevlen:
	4847	+ sysvals.mincglen = sysvals.mindevlen
	4848	+
3534	4849	# just run a utility command and exit
3535	4850	if(cmd != ''):
3536	4851	if(cmd == 'status'):
3537		− statusCheck()
	4852	+ statusCheck(True)
3538	4853	elif(cmd == 'fpdt'):
3539		− if(sysvals.android):
3540		− doError('cannot read FPDT on android device', False)
3541	4854	getFPDT(True)
3542	4855	elif(cmd == 'usbtopo'):
3543		− if(sysvals.android):
3544		− doError('cannot read USB topology '+\
3545		− 'on an android device', False)
3546		− detectUSB(True)
	4856	+ detectUSB()
3547	4857	elif(cmd == 'modes'):
3548	4858	modes = getModes()
3549	4859	print modes
	4860	+ elif(cmd == 'flist'):
	4861	+ sysvals.getFtraceFilterFunctions(True)
	4862	+ elif(cmd == 'flistall'):
	4863	+ sysvals.getFtraceFilterFunctions(False)
3550	4864	elif(cmd == 'usbauto'):
3551	4865	setUSBDevicesAuto()
3552	4866	elif(cmd == 'summary'):
@@ -3554,15 +4868,6 @@ if __name__ == '__main__': · 1 unmodified line
3554	4868	runSummary(cmdarg, True)
3555	4869	sys.exit()
3556	4870
3557		− # run test on android device
3558		− if(sysvals.android):
3559		− if(sysvals.usecallgraph):
3560		− doError('ftrace (-f) is not yet supported '+\
3561		− 'in the android kernel', False)
3562		− if(sysvals.notestrun):
3563		− doError('cannot analyze test files on the '+\
3564		− 'android device', False)
3565		−
3566	4871	# if instructed, re-analyze existing data files
3567	4872	if(sysvals.notestrun):
3568	4873	rerunTest()
@@ -3574,18 +4879,20 @@ if __name__ == '__main__': · 5 unmodified lines
3574	4879	sys.exit()
3575	4880
3576	4881	if multitest['run']:
3577		− # run multiple tests in a separte subdirectory
	4882	+ # run multiple tests in a separate subdirectory
3578	4883	s = 'x%d' % multitest['count']
3579		− subdir = datetime.now().strftime('suspend-'+s+'-%m%d%y-%H%M%S')
3580		− os.mkdir(subdir)
	4884	+ if not sysvals.outdir:
	4885	+ sysvals.outdir = datetime.now().strftime('suspend-'+s+'-%m%d%y-%H%M%S')
	4886	+ if not os.path.isdir(sysvals.outdir):
	4887	+ os.mkdir(sysvals.outdir)
3581	4888	for i in range(multitest['count']):
3582	4889	if(i != 0):
3583	4890	print('Waiting %d seconds...' % (multitest['delay']))
3584	4891	time.sleep(multitest['delay'])
3585	4892	print('TEST (%d/%d) START' % (i+1, multitest['count']))
3586		− runTest(subdir)
	4893	+ runTest(sysvals.outdir)
3587	4894	print('TEST (%d/%d) COMPLETE' % (i+1, multitest['count']))
3588		− runSummary(subdir, False)
	4895	+ runSummary(sysvals.outdir, False)
3589	4896	else:
3590	4897	# run the test in the current directory
3591		− runTest(".")
	4898	+ runTest('.', sysvals.outdir)

Merge tag 'pm-4.8-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm

Keyboard shortcuts

General

Issues and pull requests

Issues, pull requests and Inbox

Repository code