Merge branches 'pm-sleep' and 'pm-tools'

* pm-sleep: PM / hibernate: Introduce test_resume mode for hibernation x86 / hibernate: Use hlt_play_dead() when resuming from hibernation 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() PM / hibernate: Recycle safe pages after image restoration PM / hibernate: Simplify mark_unsafe_pages() PM / hibernate: Do not free preallocated safe pages during image restore PM / suspend: show workqueue state in suspend flow PM / sleep: make PM notifiers called symmetrically PM / sleep: Make pm_prepare_console() return void PM / Hibernate: Don't let kasan instrument snapshot.c * pm-tools: PM / tools: scripts: AnalyzeSuspend v4.2 tools/turbostat: allow user to alter DESTDIR and PREFIX

Rafael J. Wysocki committed 10 years ago

Commit 7f234a43 parents 523d939 fe12c00 af1e45e18 files · +3147 −1649Browse files

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

Unified · Split

scripts/analyze_suspend.py+2474−1167

@@ -19,6 +19,17 @@ · 18 unmodified lines
19	# Authors:	19	# Authors:
20	# Todd Brandt <todd.e.brandt@linux.intel.com>	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	# Description:	33	# Description:
23	# This tool is designed to assist kernel and OS developers in optimizing	34	# This tool is designed to assist kernel and OS developers in optimizing
24	# their linux stack's suspend/resume time. Using a kernel image built	35	# their linux stack's suspend/resume time. Using a kernel image built
@@ -35,6 +46,8 @@ · 10 unmodified lines
35	# CONFIG_FTRACE=y	46	# CONFIG_FTRACE=y
36	# CONFIG_FUNCTION_TRACER=y	47	# CONFIG_FUNCTION_TRACER=y
37	# CONFIG_FUNCTION_GRAPH_TRACER=y	48	# CONFIG_FUNCTION_GRAPH_TRACER=y
		49	# CONFIG_KPROBES=y
		50	# CONFIG_KPROBES_ON_FTRACE=y
38	#	51	#
39	# For kernel versions older than 3.15:	52	# For kernel versions older than 3.15:
40	# The following additional kernel parameters are required:	53	# The following additional kernel parameters are required:
@@ -52,6 +65,7 @@ import re · 11 unmodified lines
52	import platform	65	import platform
53	from datetime import datetime	66	from datetime import datetime
54	import struct	67	import struct
		68	import ConfigParser
55		69
56	# ----------------- CLASSES --------------------	70	# ----------------- CLASSES --------------------
57		71
@@ -60,8 +74,15 @@ import struct · 2 unmodified lines
60	# A global, single-instance container used to	74	# A global, single-instance container used to
61	# store system values and test parameters	75	# store system values and test parameters
62	class SystemValues:	76	class SystemValues:
63	version = 3.0	77	ansi = False
		78	version = '4.2'
64	verbose = False	79	verbose = False
		80	addlogs = False
		81	mindevlen = 0.001
		82	mincglen = 1.0
		83	srgap = 0
		84	cgexp = False
		85	outdir = ''
65	testdir = '.'	86	testdir = '.'
66	tpath = '/sys/kernel/debug/tracing/'	87	tpath = '/sys/kernel/debug/tracing/'
67	fpdtpath = '/sys/firmware/acpi/tables/FPDT'	88	fpdtpath = '/sys/firmware/acpi/tables/FPDT'
@@ -71,26 +92,21 @@ class SystemValues: · 3 unmodified lines
71	'device_pm_callback_end',	92	'device_pm_callback_end',
72	'device_pm_callback_start'	93	'device_pm_callback_start'
73	]	94	]
74	modename = {	95	testcommand = ''
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	}
80	mempath = '/dev/mem'	96	mempath = '/dev/mem'
81	powerfile = '/sys/power/state'	97	powerfile = '/sys/power/state'
82	suspendmode = 'mem'	98	suspendmode = 'mem'
83	hostname = 'localhost'	99	hostname = 'localhost'
84	prefix = 'test'	100	prefix = 'test'
85	teststamp = ''	101	teststamp = ''
		102	dmesgstart = 0.0
86	dmesgfile = ''	103	dmesgfile = ''
87	ftracefile = ''	104	ftracefile = ''
88	htmlfile = ''	105	htmlfile = ''
		106	embedded = False
89	rtcwake = False	107	rtcwake = False
90	rtcwaketime = 10	108	rtcwaketime = 10
91	rtcpath = ''	109	rtcpath = ''
92	android = False
93	adb = 'adb'
94	devicefilter = []	110	devicefilter = []
95	stamp = 0	111	stamp = 0
96	execcount = 1	112	execcount = 1
@@ -98,16 +114,90 @@ class SystemValues: · 1 unmodified line
98	usecallgraph = False	114	usecallgraph = False
99	usetraceevents = False	115	usetraceevents = False
100	usetraceeventsonly = False	116	usetraceeventsonly = False
		117	usetracemarkers = True
		118	usekprobes = True
		119	usedevsrc = False
101	notestrun = False	120	notestrun = False
102	altdevname = dict()	121	devprops = dict()
103	postresumetime = 0	122	postresumetime = 0
		123	devpropfmt = '# Device Properties: .*'
104	tracertypefmt = '# tracer: (?P<t>.*)'	124	tracertypefmt = '# tracer: (?P<t>.*)'
105	firmwarefmt = '# fwsuspend (?P<s>[0-9]) fwresume (?P<r>[0-9])$'	125	firmwarefmt = '# fwsuspend (?P<s>[0-9]) fwresume (?P<r>[0-9])$'
106	postresumefmt = '# post resume time (?P<t>[0-9]*)$'	126	postresumefmt = '# post resume time (?P<t>[0-9]*)$'
107	stampfmt = '# suspend-(?P<m>[0-9]{2})(?P<d>[0-9]{2})(?P<y>[0-9]{2})-'+\	127	stampfmt = '# suspend-(?P<m>[0-9]{2})(?P<d>[0-9]{2})(?P<y>[0-9]{2})-'+\
108	'(?P<H>[0-9]{2})(?P<M>[0-9]{2})(?P<S>[0-9]{2})'+\	128	'(?P<H>[0-9]{2})(?P<M>[0-9]{2})(?P<S>[0-9]{2})'+\
109	' (?P<host>.) (?P<mode>.) (?P<kernel>.*)$'	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	def __init__(self):	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	self.hostname = platform.node()	201	self.hostname = platform.node()
112	if(self.hostname == ''):	202	if(self.hostname == ''):
113	self.hostname = 'localhost'	203	self.hostname = 'localhost'
@@ -118,6 +208,12 @@ class SystemValues: · 4 unmodified lines
118	if os.path.exists(rtc) and os.path.exists(rtc+'/date') and \	208	if os.path.exists(rtc) and os.path.exists(rtc+'/date') and \
119	os.path.exists(rtc+'/time') and os.path.exists(rtc+'/wakealarm'):	209	os.path.exists(rtc+'/time') and os.path.exists(rtc+'/wakealarm'):
120	self.rtcpath = rtc	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	def setOutputFile(self):	217	def setOutputFile(self):
122	if((self.htmlfile == '') and (self.dmesgfile != '')):	218	if((self.htmlfile == '') and (self.dmesgfile != '')):
123	m = re.match('(?P<name>.*)_dmesg\.txt$', self.dmesgfile)	219	m = re.match('(?P<name>.*)_dmesg\.txt$', self.dmesgfile)
@@ -129,32 +225,37 @@ class SystemValues: · 5 unmodified lines
129	self.htmlfile = m.group('name')+'.html'	225	self.htmlfile = m.group('name')+'.html'
130	if(self.htmlfile == ''):	226	if(self.htmlfile == ''):
131	self.htmlfile = 'output.html'	227	self.htmlfile = 'output.html'
132	def initTestOutput(self, subdir):	228	def initTestOutput(self, subdir, testpath=''):
133	if(not self.android):	229	self.prefix = self.hostname
134	self.prefix = self.hostname	230	v = open('/proc/version', 'r').read().strip()
135	v = open('/proc/version', 'r').read().strip()	231	kver = string.split(v)[2]
136	kver = string.split(v)[2]	232	n = datetime.now()
137	else:	233	testtime = n.strftime('suspend-%m%d%y-%H%M%S')
138	self.prefix = 'android'	234	if not testpath:
139	v = os.popen(self.adb+' shell cat /proc/version').read().strip()	235	testpath = n.strftime('suspend-%y%m%d-%H%M%S')
140	kver = string.split(v)[2]
141	testtime = datetime.now().strftime('suspend-%m%d%y-%H%M%S')
142	if(subdir != "."):	236	if(subdir != "."):
143	self.testdir = subdir+"/"+testtime	237	self.testdir = subdir+"/"+testpath
144	else:	238	else:
145	self.testdir = testtime	239	self.testdir = testpath
146	self.teststamp = \	240	self.teststamp = \
147	'# '+testtime+' '+self.prefix+' '+self.suspendmode+' '+kver	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	self.dmesgfile = \	248	self.dmesgfile = \
149	self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_dmesg.txt'	249	self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_dmesg.txt'
150	self.ftracefile = \	250	self.ftracefile = \
151	self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_ftrace.txt'	251	self.testdir+'/'+self.prefix+'_'+self.suspendmode+'_ftrace.txt'
152	self.htmlfile = \	252	self.htmlfile = \
153	self.testdir+'/'+self.prefix+'_'+self.suspendmode+'.html'	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	def setDeviceFilter(self, devnames):	256	def setDeviceFilter(self, devnames):
156	self.devicefilter = string.split(devnames)	257	self.devicefilter = string.split(devnames)
157	def rtcWakeAlarm(self):	258	def rtcWakeAlarmOn(self):
158	os.system('echo 0 > '+self.rtcpath+'/wakealarm')	259	os.system('echo 0 > '+self.rtcpath+'/wakealarm')
159	outD = open(self.rtcpath+'/date', 'r').read().strip()	260	outD = open(self.rtcpath+'/date', 'r').read().strip()
160	outT = open(self.rtcpath+'/time', 'r').read().strip()	261	outT = open(self.rtcpath+'/time', 'r').read().strip()
@@ -172,9 +273,361 @@ class SystemValues: · 11 unmodified lines
172	nowtime = int(datetime.now().strftime('%s'))	273	nowtime = int(datetime.now().strftime('%s'))
173	alarm = nowtime + self.rtcwaketime	274	alarm = nowtime + self.rtcwaketime
174	os.system('echo %d > %s/wakealarm' % (alarm, self.rtcpath))	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	sysvals = SystemValues()	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	# Class: DeviceNode	631	# Class: DeviceNode
179	# Description:	632	# Description:
180	# A container used to create a device hierachy, with a single root node	633	# A container used to create a device hierachy, with a single root node
@@ -228,6 +681,7 @@ class Data: · 47 unmodified lines
228	html_device_id = 0	681	html_device_id = 0
229	stamp = 0	682	stamp = 0
230	outfile = ''	683	outfile = ''
		684	dev_ubiquitous = ['msleep', 'udelay']
231	def __init__(self, num):	685	def __init__(self, num):
232	idchar = 'abcdefghijklmnopqrstuvwxyz'	686	idchar = 'abcdefghijklmnopqrstuvwxyz'
233	self.testnumber = num	687	self.testnumber = num
@@ -257,6 +711,9 @@ class Data: · 23 unmodified lines
257	'row': 0, 'color': '#FFFFCC', 'order': 9}	711	'row': 0, 'color': '#FFFFCC', 'order': 9}
258	}	712	}
259	self.phases = self.sortedPhases()	713	self.phases = self.sortedPhases()
		714	self.devicegroups = []
		715	for phase in self.phases:
		716	self.devicegroups.append([phase])
260	def getStart(self):	717	def getStart(self):
261	return self.dmesg[self.phases[0]]['start']	718	return self.dmesg[self.phases[0]]['start']
262	def setStart(self, time):	719	def setStart(self, time):
@@ -273,51 +730,61 @@ class Data: · 10 unmodified lines
273	for dev in list:	730	for dev in list:
274	d = list[dev]	731	d = list[dev]
275	if(d['pid'] == pid and time >= d['start'] and	732	if(d['pid'] == pid and time >= d['start'] and
276	time <= d['end']):	733	time < d['end']):
277	return False	734	return False
278	return True	735	return True
279	def addIntraDevTraceEvent(self, action, name, pid, time):	736	def targetDevice(self, phaselist, start, end, pid=-1):
280	if(action == 'mutex_lock_try'):	737	tgtdev = ''
281	color = 'red'	738	for phase in phaselist:
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:
293	list = self.dmesg[phase]['list']	739	list = self.dmesg[phase]['list']
294	for dev in list:	740	for devname in list:
295	d = list[dev]	741	dev = list[devname]
296	if(d['pid'] == pid and time >= d['start'] and	742	if(pid >= 0 and dev['pid'] != pid):
297	time <= d['end']):	743	continue
298	e = TraceEvent(action, name, color, time)	744	devS = dev['start']
299	if('traceevents' not in d):	745	devE = dev['end']
300	d['traceevents'] = []	746	if(start < devS or start >= devE or end <= devS or end > devE):
301	d['traceevents'].append(e)	747	continue
302	return d	748	tgtdev = dev
303	break	749	break
304	return 0	750	return tgtdev
305	def capIntraDevTraceEvent(self, action, name, pid, time):	751	def addDeviceFunctionCall(self, displayname, kprobename, proc, pid, start, end, cdata, rdata):
306	for phase in self.phases:	752	machstart = self.dmesg['suspend_machine']['start']
307	list = self.dmesg[phase]['list']	753	machend = self.dmesg['resume_machine']['end']
308	for dev in list:	754	tgtdev = self.targetDevice(self.phases, start, end, pid)
309	d = list[dev]	755	if not tgtdev and start >= machstart and end < machend:
310	if(d['pid'] == pid and time >= d['start'] and	756	# device calls in machine phases should be serial
311	time <= d['end']):	757	tgtdev = self.targetDevice(['suspend_machine', 'resume_machine'], start, end)
312	if('traceevents' not in d):	758	if not tgtdev:
313	return	759	if 'scsi_eh' in proc:
314	for e in d['traceevents']:	760	self.newActionGlobal(proc, start, end, pid)
315	if(e.action == action and	761	self.addDeviceFunctionCall(displayname, kprobename, proc, pid, start, end, cdata, rdata)
316	e.name == name and not e.ready):	762	else:
317	e.length = time - e.time	763	vprint('IGNORE: %s[%s](%d) [%f - %f] \| %s \| %s \| %s' % (displayname, kprobename,
318	e.ready = True	764	pid, start, end, cdata, rdata, proc))
319	break	765	return False
320	return	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	def trimTimeVal(self, t, t0, dT, left):	788	def trimTimeVal(self, t, t0, dT, left):
322	if left:	789	if left:
323	if(t > t0):	790	if(t > t0):
@@ -353,11 +820,11 @@ class Data: · 29 unmodified lines
353	cg.end = self.trimTimeVal(cg.end, t0, dT, left)	820	cg.end = self.trimTimeVal(cg.end, t0, dT, left)
354	for line in cg.list:	821	for line in cg.list:
355	line.time = self.trimTimeVal(line.time, t0, dT, left)	822	line.time = self.trimTimeVal(line.time, t0, dT, left)
356	if('traceevents' in d):	823	if('src' in d):
357	for e in d['traceevents']:	824	for e in d['src']:
358	e.time = self.trimTimeVal(e.time, t0, dT, left)	825	e.time = self.trimTimeVal(e.time, t0, dT, left)
359	def normalizeTime(self, tZero):	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	if(self.tSuspended != self.tResumed):	828	if(self.tSuspended != self.tResumed):
362	if(self.tResumed > tZero):	829	if(self.tResumed > tZero):
363	self.trimTime(self.tSuspended, \	830	self.trimTime(self.tSuspended, \
@@ -365,29 +832,6 @@ class Data: · 1 unmodified line
365	else:	832	else:
366	self.trimTime(self.tSuspended, \	833	self.trimTime(self.tSuspended, \
367	self.tResumed-self.tSuspended, False)	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	def newPhaseWithSingleAction(self, phasename, devname, start, end, color):	835	def newPhaseWithSingleAction(self, phasename, devname, start, end, color):
392	for phase in self.phases:	836	for phase in self.phases:
393	self.dmesg[phase]['order'] += 1	837	self.dmesg[phase]['order'] += 1
@@ -417,6 +861,7 @@ class Data: · 23 unmodified lines
417	{'list': list, 'start': start, 'end': end,	861	{'list': list, 'start': start, 'end': end,
418	'row': 0, 'color': color, 'order': order}	862	'row': 0, 'color': color, 'order': order}
419	self.phases = self.sortedPhases()	863	self.phases = self.sortedPhases()
		864	self.devicegroups.append([phasename])
420	def setPhase(self, phase, ktime, isbegin):	865	def setPhase(self, phase, ktime, isbegin):
421	if(isbegin):	866	if(isbegin):
422	self.dmesg[phase]['start'] = ktime	867	self.dmesg[phase]['start'] = ktime
@@ -442,7 +887,10 @@ class Data: · 19 unmodified lines
442	for devname in phaselist:	887	for devname in phaselist:
443	dev = phaselist[devname]	888	dev = phaselist[devname]
444	if(dev['end'] < 0):	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	vprint('%s (%s): callback didnt return' % (devname, phase))	894	vprint('%s (%s): callback didnt return' % (devname, phase))
447	def deviceFilter(self, devicefilter):	895	def deviceFilter(self, devicefilter):
448	# remove all by the relatives of the filter devnames	896	# remove all by the relatives of the filter devnames
@@ -472,22 +920,58 @@ class Data: · 23 unmodified lines
472	# if any calls never returned, clip them at system resume end	920	# if any calls never returned, clip them at system resume end
473	for phase in self.phases:	921	for phase in self.phases:
474	self.fixupInitcalls(phase, self.getEnd())	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	# which phase is this device callback or action "in"	949	# which phase is this device callback or action "in"
477	targetphase = "none"	950	targetphase = "none"
		951	htmlclass = ''
478	overlap = 0.0	952	overlap = 0.0
		953	phases = []
479	for phase in self.phases:	954	for phase in self.phases:
480	pstart = self.dmesg[phase]['start']	955	pstart = self.dmesg[phase]['start']
481	pend = self.dmesg[phase]['end']	956	pend = self.dmesg[phase]['end']
482	o = max(0, min(end, pend) - max(start, pstart))	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	targetphase = phase	963	targetphase = phase
485	overlap = o	964	overlap = o
		965	if pid == -2:
		966	htmlclass = ' bg'
		967	if len(phases) > 1:
		968	htmlclass = ' bg'
		969	self.phaseOverlap(phases)
486	if targetphase in self.phases:	970	if targetphase in self.phases:
487	self.newAction(targetphase, name, -1, '', start, end, '')	971	newname = self.newAction(targetphase, name, pid, '', start, end, '', htmlclass, color)
488	return True	972	return (targetphase, newname)
489	return False	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	# new device callback for a specific phase	975	# new device callback for a specific phase
492	self.html_device_id += 1	976	self.html_device_id += 1
493	devid = '%s%d' % (self.idstr, self.html_device_id)	977	devid = '%s%d' % (self.idstr, self.html_device_id)
@@ -495,8 +979,19 @@ class Data: · 1 unmodified line
495	length = -1.0	979	length = -1.0
496	if(start >= 0 and end >= 0):	980	if(start >= 0 and end >= 0):
497	length = end - start	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	list[name] = {'start': start, 'end': end, 'pid': pid, 'par': parent,	988	list[name] = {'start': start, 'end': end, 'pid': pid, 'par': parent,
499	'length': length, 'row': 0, 'id': devid, 'drv': drv }	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	def deviceIDs(self, devlist, phase):	995	def deviceIDs(self, devlist, phase):
501	idlist = []	996	idlist = []
502	list = self.dmesg[phase]['list']	997	list = self.dmesg[phase]['list']
@@ -536,10 +1031,21 @@ class Data: · 33 unmodified lines
536	vprint(' %16s: %f - %f (%d devices)' % (phase, \	1031	vprint(' %16s: %f - %f (%d devices)' % (phase, \
537	self.dmesg[phase]['start'], self.dmesg[phase]['end'], dc))	1032	self.dmesg[phase]['start'], self.dmesg[phase]['end'], dc))
538	vprint(' test end: %f' % self.end)	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	def masterTopology(self, name, list, depth):	1042	def masterTopology(self, name, list, depth):
540	node = DeviceNode(name, depth)	1043	node = DeviceNode(name, depth)
541	for cname in list:	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	cnode = self.masterTopology(cname, clist, depth+1)	1049	cnode = self.masterTopology(cname, clist, depth+1)
544	node.children.append(cnode)	1050	node.children.append(cnode)
545	return node	1051	return node
@@ -580,7 +1086,8 @@ class Data: · 34 unmodified lines
580	list = self.dmesg[phase]['list']	1086	list = self.dmesg[phase]['list']
581	for dev in list:	1087	for dev in list:
582	pdev = list[dev]['par']	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	continue	1091	continue
585	if pdev and pdev not in real and pdev not in rootlist:	1092	if pdev and pdev not in real and pdev not in rootlist:
586	rootlist.append(pdev)	1093	rootlist.append(pdev)
@@ -589,22 +1096,33 @@ class Data: · 2 unmodified lines
589	rootlist = self.rootDeviceList()	1096	rootlist = self.rootDeviceList()
590	master = self.masterTopology('', rootlist, 0)	1097	master = self.masterTopology('', rootlist, 0)
591	return self.printTopology(master)	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	# Class: TraceEvent	1112	# Class: TraceEvent
594	# Description:	1113	# Description:
595	# A container for trace event data found in the ftrace file	1114	# A container for trace event data found in the ftrace file
596	class TraceEvent:	1115	class TraceEvent:
597	ready = False	1116	text = ''
598	name = ''
599	time = 0.0	1117	time = 0.0
600	color = '#FFFFFF'
601	length = 0.0	1118	length = 0.0
602	action = ''	1119	title = ''
603	def __init__(self, a, n, c, t):	1120	row = 0
604	self.action = a	1121	def __init__(self, a, n, t, l):
605	self.name = n	1122	self.title = a
606	self.color = c	1123	self.text = n
607	self.time = t	1124	self.time = t
		1125	self.length = l
608		1126
609	# Class: FTraceLine	1127	# Class: FTraceLine
610	# Description:	1128	# Description:
@@ -623,11 +1141,14 @@ class FTraceLine: · 12 unmodified lines
623	fcall = False	1141	fcall = False
624	freturn = False	1142	freturn = False
625	fevent = False	1143	fevent = False
		1144	fkprobe = False
626	depth = 0	1145	depth = 0
627	name = ''	1146	name = ''
628	type = ''	1147	type = ''
629	def __init__(self, t, m, d):	1148	def __init__(self, t, m='', d=''):
630	self.time = float(t)	1149	self.time = float(t)
		1150	if not m and not d:
		1151	return
631	# is this a trace event	1152	# is this a trace event
632	if(d == 'traceevent' or re.match('^ \/\ (?P<msg>.) \\/ $', m)):	1153	if(d == 'traceevent' or re.match('^ \/\ (?P<msg>.) \\/ $', m)):
633	if(d == 'traceevent'):	1154	if(d == 'traceevent'):
@@ -644,6 +1165,18 @@ class FTraceLine: · 10 unmodified lines
644	self.type = emm.group('call')	1165	self.type = emm.group('call')
645	else:	1166	else:
646	self.name = msg	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	self.fevent = True	1180	self.fevent = True
648	return	1181	return
649	# convert the duration to seconds	1182	# convert the duration to seconds
@@ -662,7 +1195,7 @@ class FTraceLine: · 12 unmodified lines
662	# includes comment with function name	1195	# includes comment with function name
663	match = re.match('^} \/\ (?P<n>.) \\/$', m)	1196	match = re.match('^} \/\ (?P<n>.) \\/$', m)
664	if(match):	1197	if(match):
665	self.name = match.group('n')	1198	self.name = match.group('n').strip()
666	# function call	1199	# function call
667	else:	1200	else:
668	self.fcall = True	1201	self.fcall = True
@@ -670,19 +1203,19 @@ class FTraceLine: · 1 unmodified line
670	if(m[-1] == '{'):	1203	if(m[-1] == '{'):
671	match = re.match('^(?P<n>.) \(.*', m)	1204	match = re.match('^(?P<n>.) \(.*', m)
672	if(match):	1205	if(match):
673	self.name = match.group('n')	1206	self.name = match.group('n').strip()
674	# function call with no children (leaf)	1207	# function call with no children (leaf)
675	elif(m[-1] == ';'):	1208	elif(m[-1] == ';'):
676	self.freturn = True	1209	self.freturn = True
677	match = re.match('^(?P<n>.) \(.*', m)	1210	match = re.match('^(?P<n>.) \(.*', m)
678	if(match):	1211	if(match):
679	self.name = match.group('n')	1212	self.name = match.group('n').strip()
680	# something else (possibly a trace marker)	1213	# something else (possibly a trace marker)
681	else:	1214	else:
682	self.name = m	1215	self.name = m
683	def getDepth(self, str):	1216	def getDepth(self, str):
684	return len(str)/2	1217	return len(str)/2
685	def debugPrint(self, dev):	1218	def debugPrint(self, dev=''):
686	if(self.freturn and self.fcall):	1219	if(self.freturn and self.fcall):
687	print('%s -- %f (%02d): %s(); (%.3f us)' % (dev, self.time, \	1220	print('%s -- %f (%02d): %s(); (%.3f us)' % (dev, self.time, \
688	self.depth, self.name, self.length*1000000))	1221	self.depth, self.name, self.length*1000000))
@@ -692,6 +1225,33 @@ class FTraceLine: · 3 unmodified lines
692	else:	1225	else:
693	print('%s -- %f (%02d): %s() { (%.3f us)' % (dev, self.time, \	1226	print('%s -- %f (%02d): %s() { (%.3f us)' % (dev, self.time, \
694	self.depth, self.name, self.length*1000000))	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	# Class: FTraceCallGraph	1256	# Class: FTraceCallGraph
697	# Description:	1257	# Description:
@@ -705,54 +1265,124 @@ class FTraceCallGraph: · 7 unmodified lines
705	list = []	1265	list = []
706	invalid = False	1266	invalid = False
707	depth = 0	1267	depth = 0
708	def __init__(self):	1268	pid = 0
		1269	def __init__(self, pid):
709	self.start = -1.0	1270	self.start = -1.0
710	self.end = -1.0	1271	self.end = -1.0
711	self.list = []	1272	self.list = []
712	self.depth = 0	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	if(line.fcall and not line.freturn):	1353	if(line.fcall and not line.freturn):
715	line.depth = self.depth
716	self.depth += 1	1354	self.depth += 1
717	elif(line.freturn and not line.fcall):	1355	elif(line.freturn and not line.fcall):
718	self.depth -= 1	1356	self.depth -= 1
719	line.depth = self.depth	1357	if len(self.list) < 1:
720	else:	1358	self.start = line.time
721	line.depth = self.depth	1359	self.list.append(line)
722	def addLine(self, line, match):
723	if(not self.invalid):
724	self.setDepth(line)
725	if(line.depth == 0 and line.freturn):	1360	if(line.depth == 0 and line.freturn):
726	if(self.start < 0):	1361	if(self.start < 0):
727	self.start = line.time	1362	self.start = line.time
728	self.end = line.time	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	return True	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	return False	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	def slice(self, t0, tN):	1384	def slice(self, t0, tN):
755	minicg = FTraceCallGraph()	1385	minicg = FTraceCallGraph(0)
756	count = -1	1386	count = -1
757	firstdepth = 0	1387	firstdepth = 0
758	for l in self.list:	1388	for l in self.list:
@@ -764,13 +1394,26 @@ class FTraceCallGraph: · 5 unmodified lines
764	firstdepth = l.depth	1394	firstdepth = l.depth
765	count = 0	1395	count = 0
766	l.depth -= firstdepth	1396	l.depth -= firstdepth
767	minicg.addLine(l, 0)	1397	minicg.addLine(l)
768	if((count == 0 and l.freturn and l.fcall) or	1398	if((count == 0 and l.freturn and l.fcall) or
769	(count > 0 and l.depth <= 0)):	1399	(count > 0 and l.depth <= 0)):
770	break	1400	break
771	count += 1	1401	count += 1
772	return minicg	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	stack = dict()	1417	stack = dict()
775	cnt = 0	1418	cnt = 0
776	for l in self.list:	1419	for l in self.list:
@@ -779,98 +1422,317 @@ class FTraceCallGraph: · 2 unmodified lines
779	cnt += 1	1422	cnt += 1
780	elif(l.freturn and not l.fcall):	1423	elif(l.freturn and not l.fcall):
781	if(l.depth not in stack):	1424	if(l.depth not in stack):
		1425	if debug:
		1426	print 'Post Process Error: Depth missing'
		1427	l.debugPrint()
782	return False	1428	return False
		1429	# transfer total time from return line to call line
783	stack[l.depth].length = l.length	1430	stack[l.depth].length = l.length
784	stack[l.depth] = 0	1431	stack.pop(l.depth)
785	l.length = 0	1432	l.length = 0
786	cnt -= 1	1433	cnt -= 1
787	if(cnt == 0):	1434	if(cnt == 0):
		1435	# trace caught the whole call tree
788	return True	1436	return True
789	return False	1437	elif(cnt < 0):
790	def debugPrint(self, filename):	1438	if debug:
791	if(filename == 'stdout'):	1439	print 'Post Process Error: Depth is less than 0'
792	print('[%f - %f]') % (self.start, self.end)	1440	return False
793	for l in self.list:	1441	# trace ended before call tree finished
794	if(l.freturn and l.fcall):	1442	return self.repair(cnt)
795	print('%f (%02d): %s(); (%.3f us)' % (l.time, \	1443	def deviceMatch(self, pid, data):
796	l.depth, l.name, l.length*1000000))	1444	found = False
797	elif(l.freturn):	1445	# add the callgraph data to the device hierarchy
798	print('%f (%02d): %s} (%.3f us)' % (l.time, \	1446	borderphase = {
799	l.depth, l.name, l.length*1000000))	1447	'dpm_prepare': 'suspend_prepare',
800	else:	1448	'dpm_complete': 'resume_complete'
801	print('%f (%02d): %s() { (%.3f us)' % (l.time, \	1449	}
802	l.depth, l.name, l.length*1000000))	1450	if(self.list[0].name in borderphase):
803	print(' ')	1451	p = borderphase[self.list[0].name]
804	else:	1452	list = data.dmesg[p]['list']
805	fp = open(filename, 'w')	1453	for devname in list:
806	print(filename)	1454	dev = list[devname]
807	for l in self.list:	1455	if(pid == dev['pid'] and
808	if(l.freturn and l.fcall):	1456	self.start <= dev['start'] and
809	fp.write('%f (%02d): %s(); (%.3f us)\n' % (l.time, \	1457	self.end >= dev['end']):
810	l.depth, l.name, l.length*1000000))	1458	dev['ftrace'] = self.slice(dev['start'], dev['end'])
811	elif(l.freturn):	1459	found = True
812	fp.write('%f (%02d): %s} (%.3f us)\n' % (l.time, \	1460	return found
813	l.depth, l.name, l.length*1000000))	1461	for p in data.phases:
814	else:	1462	if(data.dmesg[p]['start'] <= self.start and
815	fp.write('%f (%02d): %s() { (%.3f us)\n' % (l.time, \	1463	self.start <= data.dmesg[p]['end']):
816	l.depth, l.name, l.length*1000000))	1464	list = data.dmesg[p]['list']
817	fp.close()	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	# Class: Timeline	1509	# Class: Timeline
820	# Description:	1510	# Description:
821	# A container for a suspend/resume html timeline. In older versions	1511	# A container for a device timeline which calculates
822	# of the script there were multiple timelines, but in the latest	1512	# all the html properties to display it correctly
823	# there is only one.
824	class Timeline:	1513	class Timeline:
825	html = {}	1514	html = {}
826	scaleH = 0.0 # height of the row as a percent of the timeline height	1515	height = 0 # total timeline height
827	rowH = 0.0 # height of each row in percent of the timeline height	1516	scaleH = 20 # timescale (top) row height
828	row_height_pixels = 30	1517	rowH = 30 # device row height
829	maxrows = 0	1518	bodyH = 0 # body height
830	height = 0	1519	rows = 0 # total timeline rows
831	def __init__(self):	1520	phases = []
		1521	rowmaxlines = dict()
		1522	rowcount = dict()
		1523	rowheight = dict()
		1524	def __init__(self, rowheight):
		1525	self.rowH = rowheight
832	self.html = {	1526	self.html = {
		1527	'header': '',
833	'timeline': '',	1528	'timeline': '',
834	'legend': '',	1529	'legend': '',
835	'scale': ''
836	}	1530	}
837	def setRows(self, rows):	1531	# Function: getDeviceRows
838	self.maxrows = int(rows)	1532	# Description:
839	self.scaleH = 100.0/float(self.maxrows)	1533	# determine how may rows the device funcs will take
840	self.height = self.maxrows*self.row_height_pixels	1534	# Arguments:
841	r = float(self.maxrows - 1)	1535	# rawlist: the list of devices/actions for a single phase
842	if(r < 1.0):	1536	# Output:
843	r = 1.0	1537	# The total number of rows needed to display this phase of the timeline
844	self.rowH = (100.0 - self.scaleH)/r	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	# Description:	1715	# Description:
848	# A container for a suspend/resume test run. This is necessary as	1716	# A list of values describing the properties of these test runs
849	# there could be more than one, and they need to be separate.	1717	class TestProps:
850	class TestRun:	1718	stamp = ''
		1719	tracertype = ''
		1720	S0i3 = False
		1721	fwdata = []
851	ftrace_line_fmt_fg = \	1722	ftrace_line_fmt_fg = \
852	'^ (?P<time>[0-9\.]) \\| (?P<cpu>[0-9]*)\)'+\	1723	'^ (?P<time>[0-9\.]) \\| (?P<cpu>[0-9]*)\)'+\
853	' (?P<proc>.)-(?P<pid>[0-9]) \\|'+\	1724	' (?P<proc>.)-(?P<pid>[0-9]) \\|'+\
854	'[ +!](?P<dur>[0-9\.]) .\\| (?P<msg>.)'	1725	'[ +!#\@$](?P<dur>[0-9\.]) .\\| (?P<msg>.*)'
855	ftrace_line_fmt_nop = \	1726	ftrace_line_fmt_nop = \
856	' (?P<proc>.)-(?P<pid>[0-9]) \[(?P<cpu>[0-9])\] '+\	1727	' (?P<proc>.)-(?P<pid>[0-9]) \[(?P<cpu>[0-9])\] '+\
857	'(?P<flags>.{4}) (?P<time>[0-9\.]): *'+\	1728	'(?P<flags>.{4}) (?P<time>[0-9\.]): *'+\
858	'(?P<msg>.*)'	1729	'(?P<msg>.*)'
859	ftrace_line_fmt = ftrace_line_fmt_nop	1730	ftrace_line_fmt = ftrace_line_fmt_nop
860	cgformat = False	1731	cgformat = False
861	ftemp = dict()
862	ttemp = dict()
863	inthepipe = False
864	tracertype = ''
865	data = 0	1732	data = 0
866	def __init__(self, dataobj):	1733	ktemp = dict()
867	self.data = dataobj	1734	def __init__(self):
868	self.ftemp = dict()	1735	self.ktemp = dict()
869	self.ttemp = dict()
870	def isReady(self):
871	if(tracertype == '' or not data):
872	return False
873	return True
874	def setTracerType(self, tracer):	1736	def setTracerType(self, tracer):
875	self.tracertype = tracer	1737	self.tracertype = tracer
876	if(tracer == 'function_graph'):	1738	if(tracer == 'function_graph'):
@@ -881,6 +1743,19 @@ class TestRun: · 4 unmodified lines
881	else:	1743	else:
882	doError('Invalid tracer format: [%s]' % tracer, False)	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	# ----------------- FUNCTIONS --------------------	1759	# ----------------- FUNCTIONS --------------------
885		1760
886	# Function: vprint	1761	# Function: vprint
@@ -893,104 +1768,16 @@ def vprint(msg): · 6 unmodified lines
893	if(sysvals.verbose):	1768	if(sysvals.verbose):
894	print(msg)	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	# Function: parseStamp	1771	# Function: parseStamp
987	# Description:	1772	# Description:
988	# Pull in the stamp comment line from the data file(s),	1773	# Pull in the stamp comment line from the data file(s),
989	# create the stamp, and add it to the global sysvals object	1774	# create the stamp, and add it to the global sysvals object
990	# Arguments:	1775	# Arguments:
991	# m: the valid re.match output for the stamp line	1776	# m: the valid re.match output for the stamp line
992	def parseStamp(m, data):	1777	def parseStamp(line, data):
993	global sysvals	1778	global sysvals
		1779
		1780	m = re.match(sysvals.stampfmt, line)
994	data.stamp = {'time': '', 'host': '', 'mode': ''}	1781	data.stamp = {'time': '', 'host': '', 'mode': ''}
995	dt = datetime(int(m.group('y'))+2000, int(m.group('m')),	1782	dt = datetime(int(m.group('y'))+2000, int(m.group('m')),
996	int(m.group('d')), int(m.group('H')), int(m.group('M')),	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	data.stamp['host'] = m.group('host')	1786	data.stamp['host'] = m.group('host')
1000	data.stamp['mode'] = m.group('mode')	1787	data.stamp['mode'] = m.group('mode')
1001	data.stamp['kernel'] = m.group('kernel')	1788	data.stamp['kernel'] = m.group('kernel')
		1789	sysvals.hostname = data.stamp['host']
1002	sysvals.suspendmode = data.stamp['mode']	1790	sysvals.suspendmode = data.stamp['mode']
1003	if not sysvals.stamp:	1791	if not sysvals.stamp:
1004	sysvals.stamp = data.stamp	1792	sysvals.stamp = data.stamp
@@ -1031,14 +1819,35 @@ def diffStamp(stamp1, stamp2): · 26 unmodified lines
1031	def doesTraceLogHaveTraceEvents():	1819	def doesTraceLogHaveTraceEvents():
1032	global sysvals	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	sysvals.usetraceeventsonly = True	1838	sysvals.usetraceeventsonly = True
1035	sysvals.usetraceevents = False	1839	sysvals.usetraceevents = False
1036	for e in sysvals.traceevents:	1840	for e in sysvals.traceevents:
1037	out = os.popen('cat '+sysvals.ftracefile+' \| grep "'+e+': "').read()	1841	out = os.system('grep -q "'+e+': " '+sysvals.ftracefile)
1038	if(not out):	1842	if(out != 0):
1039	sysvals.usetraceeventsonly = False	1843	sysvals.usetraceeventsonly = False
1040	if(e == 'suspend_resume' and out):	1844	if(e == 'suspend_resume' and out == 0):
1041	sysvals.usetraceevents = True	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	# Function: appendIncompleteTraceLog	1852	# Function: appendIncompleteTraceLog
1044	# Description:	1853	# Description:
@@ -1055,44 +1864,42 @@ def appendIncompleteTraceLog(testruns): · 10 unmodified lines
1055		1864
1056	# create TestRun vessels for ftrace parsing	1865	# create TestRun vessels for ftrace parsing
1057	testcnt = len(testruns)	1866	testcnt = len(testruns)
1058	testidx = -1	1867	testidx = 0
1059	testrun = []	1868	testrun = []
1060	for data in testruns:	1869	for data in testruns:
1061	testrun.append(TestRun(data))	1870	testrun.append(TestRun(data))
1062		1871
1063	# extract the callgraph and traceevent data	1872	# extract the callgraph and traceevent data
1064	vprint('Analyzing the ftrace data...')	1873	vprint('Analyzing the ftrace data...')
		1874	tp = TestProps()
1065	tf = open(sysvals.ftracefile, 'r')	1875	tf = open(sysvals.ftracefile, 'r')
		1876	data = 0
1066	for line in tf:	1877	for line in tf:
1067	# remove any latent carriage returns	1878	# remove any latent carriage returns
1068	line = line.replace('\r\n', '')	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	m = re.match(sysvals.stampfmt, line)	1881	m = re.match(sysvals.stampfmt, line)
1071	if(m):	1882	if(m):
1072	testidx += 1	1883	tp.stamp = line
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):
1080	continue	1884	continue
1081	# determine the trace data type (required for further parsing)	1885	# determine the trace data type (required for further parsing)
1082	m = re.match(sysvals.tracertypefmt, line)	1886	m = re.match(sysvals.tracertypefmt, line)
1083	if(m):	1887	if(m):
1084	tracer = m.group('t')	1888	tp.setTracerType(m.group('t'))
1085	testrun[testidx].setTracerType(tracer)	1889	continue
		1890	# device properties line
		1891	if(re.match(sysvals.devpropfmt, line)):
		1892	devProps(line)
1086	continue	1893	continue
1087	# parse only valid lines, if this isnt one move on	1894	# parse only valid lines, if this is not one move on
1088	m = re.match(testrun[testidx].ftrace_line_fmt, line)	1895	m = re.match(tp.ftrace_line_fmt, line)
1089	if(not m):	1896	if(not m):
1090	continue	1897	continue
1091	# gather the basic message data from the line	1898	# gather the basic message data from the line
1092	m_time = m.group('time')	1899	m_time = m.group('time')
1093	m_pid = m.group('pid')	1900	m_pid = m.group('pid')
1094	m_msg = m.group('msg')	1901	m_msg = m.group('msg')
1095	if(testrun[testidx].cgformat):	1902	if(tp.cgformat):
1096	m_param3 = m.group('dur')	1903	m_param3 = m.group('dur')
1097	else:	1904	else:
1098	m_param3 = 'traceevent'	1905	m_param3 = 'traceevent'
@@ -1104,119 +1911,114 @@ def appendIncompleteTraceLog(testruns): · 5 unmodified lines
1104	# the line should be a call, return, or event	1911	# the line should be a call, return, or event
1105	if(not t.fcall and not t.freturn and not t.fevent):	1912	if(not t.fcall and not t.freturn and not t.fevent):
1106	continue	1913	continue
1107	# only parse the ftrace data during suspend/resume	1914	# look for the suspend start marker
1108	data = testrun[testidx].data	1915	if(t.startMarker()):
1109	if(not testrun[testidx].inthepipe):	1916	data = testrun[testidx].data
1110	# look for the suspend start marker	1917	parseStamp(tp.stamp, data)
1111	if(t.fevent):	1918	data.setStart(t.time)
1112	if(t.name == 'SUSPEND START'):	1919	continue
1113	testrun[testidx].inthepipe = True	1920	if(not data):
1114	data.setStart(t.time)	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	continue	1937	continue
1116	else:	1938	m = re.match('(?P<name>.)\[(?P<val>[0-9])\] .*', t.name)
1117	# trace event processing	1939	if(m):
1118	if(t.fevent):	1940	val = m.group('val')
1119	if(t.name == 'RESUME COMPLETE'):	1941	if val == '0':
1120	testrun[testidx].inthepipe = False	1942	name = m.group('name')
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
1130	else:	1943	else:
1131	continue	1944	name = m.group('name')+'['+val+']'
1132	m = re.match('(?P<name>.)\[(?P<val>[0-9])\] .*', t.name)	1945	else:
1133	if(m):	1946	m = re.match('(?P<name>.) .', t.name)
1134	val = m.group('val')	1947	name = m.group('name')
1135	if val == '0':	1948	# special processing for trace events
1136	name = m.group('name')	1949	if re.match('dpm_prepare\[.*', name):
1137	else:	1950	continue
1138	name = m.group('name')+'['+val+']'	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	else:	1964	else:
1140	m = re.match('(?P<name>.) .', t.name)	1965	data.dmesg['suspend_late']['end'] = t.time
1141	name = m.group('name')	1966	continue
1142	# special processing for trace events	1967	elif re.match('dpm_suspend_noirq\[.*', name):
1143	if re.match('dpm_prepare\[.*', name):	1968	if(isbegin):
1144	continue	1969	data.dmesg['suspend_noirq']['start'] = t.time
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
1205	else:	1970	else:
1206	if(isbegin):	1971	data.dmesg['suspend_noirq']['end'] = t.time
1207	data.addIntraDevTraceEvent('', name, pid, t.time)	1972	continue
1208	else:	1973	elif re.match('dpm_resume_noirq\[.*', name):
1209	data.capIntraDevTraceEvent('', name, pid, t.time)	1974	if(isbegin):
1210	# call/return processing	1975	data.dmesg['resume_machine']['end'] = t.time
1211	elif sysvals.usecallgraph:	1976	data.dmesg['resume_noirq']['start'] = t.time
1212	# create a callgraph object for the data	1977	else:
1213	if(pid not in testrun[testidx].ftemp):	1978	data.dmesg['resume_noirq']['end'] = t.time
1214	testrun[testidx].ftemp[pid] = []	1979	continue
1215	testrun[testidx].ftemp[pid].append(FTraceCallGraph())	1980	elif re.match('dpm_resume_early\[.*', name):
1216	# when the call is finished, see which device matches it	1981	if(isbegin):
1217	cg = testrun[testidx].ftemp[pid][-1]	1982	data.dmesg['resume_early']['start'] = t.time
1218	if(cg.addLine(t, m)):	1983	else:
1219	testrun[testidx].ftemp[pid].append(FTraceCallGraph())	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	tf.close()	2022	tf.close()
1221		2023
1222	for test in testrun:	2024	for test in testrun:
@@ -1224,20 +2026,14 @@ def appendIncompleteTraceLog(testruns): · 1 unmodified line
1224	if(sysvals.usetraceevents):	2026	if(sysvals.usetraceevents):
1225	for name in test.ttemp:	2027	for name in test.ttemp:
1226	for event in test.ttemp[name]:	2028	for event in test.ttemp[name]:
1227	begin = event['begin']	2029	test.data.newActionGlobal(name, event['begin'], event['end'])
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)
1236		2030
1237	# add the callgraph data to the device hierarchy	2031	# add the callgraph data to the device hierarchy
1238	for pid in test.ftemp:	2032	for pid in test.ftemp:
1239	for cg in test.ftemp[pid]:	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	id = 'task %s cpu %s' % (pid, m.group('cpu'))	2037	id = 'task %s cpu %s' % (pid, m.group('cpu'))
1242	vprint('Sanity check failed for '+\	2038	vprint('Sanity check failed for '+\
1243	id+', ignoring this callback')	2039	id+', ignoring this callback')
@@ -1259,14 +2055,6 @@ def appendIncompleteTraceLog(testruns): · 15 unmodified lines
1259	if(sysvals.verbose):	2055	if(sysvals.verbose):
1260	test.data.printDetails()	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	# Function: parseTraceLog	2058	# Function: parseTraceLog
1271	# Description:	2059	# Description:
1272	# Analyze an ftrace log output file generated from this app during	2060	# Analyze an ftrace log output file generated from this app during
@@ -1280,9 +2068,16 @@ def parseTraceLog(): · 7 unmodified lines
1280		2068
1281	vprint('Analyzing the ftrace data...')	2069	vprint('Analyzing the ftrace data...')
1282	if(os.path.exists(sysvals.ftracefile) == False):	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	# extract the callgraph and traceevent data	2079	# extract the callgraph and traceevent data
		2080	tp = TestProps()
1286	testruns = []	2081	testruns = []
1287	testdata = []	2082	testdata = []
1288	testrun = 0	2083	testrun = 0
@@ -1295,27 +2090,17 @@ def parseTraceLog(): · 6 unmodified lines
1295	# stamp line: each stamp means a new test run	2090	# stamp line: each stamp means a new test run
1296	m = re.match(sysvals.stampfmt, line)	2091	m = re.match(sysvals.stampfmt, line)
1297	if(m):	2092	if(m):
1298	data = Data(len(testdata))	2093	tp.stamp = line
1299	testdata.append(data)
1300	testrun = TestRun(data)
1301	testruns.append(testrun)
1302	parseStamp(m, data)
1303	continue
1304	if(not data):
1305	continue	2094	continue
1306	# firmware line: pull out any firmware data	2095	# firmware line: pull out any firmware data
1307	m = re.match(sysvals.firmwarefmt, line)	2096	m = re.match(sysvals.firmwarefmt, line)
1308	if(m):	2097	if(m):
1309	data.fwSuspend = int(m.group('s'))	2098	tp.fwdata.append((int(m.group('s')), int(m.group('r'))))
1310	data.fwResume = int(m.group('r'))
1311	if(data.fwSuspend > 0 or data.fwResume > 0):
1312	data.fwValid = True
1313	continue	2099	continue
1314	# tracer type line: determine the trace data type	2100	# tracer type line: determine the trace data type
1315	m = re.match(sysvals.tracertypefmt, line)	2101	m = re.match(sysvals.tracertypefmt, line)
1316	if(m):	2102	if(m):
1317	tracer = m.group('t')	2103	tp.setTracerType(m.group('t'))
1318	testrun.setTracerType(tracer)
1319	continue	2104	continue
1320	# post resume time line: did this test run include post-resume data	2105	# post resume time line: did this test run include post-resume data
1321	m = re.match(sysvals.postresumefmt, line)	2106	m = re.match(sysvals.postresumefmt, line)
@@ -1324,15 +2109,20 @@ def parseTraceLog(): · 2 unmodified lines
1324	if(t > 0):	2109	if(t > 0):
1325	sysvals.postresumetime = t	2110	sysvals.postresumetime = t
1326	continue	2111	continue
		2112	# device properties line
		2113	if(re.match(sysvals.devpropfmt, line)):
		2114	devProps(line)
		2115	continue
1327	# ftrace line: parse only valid lines	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	if(not m):	2118	if(not m):
1330	continue	2119	continue
1331	# gather the basic message data from the line	2120	# gather the basic message data from the line
1332	m_time = m.group('time')	2121	m_time = m.group('time')
		2122	m_proc = m.group('proc')
1333	m_pid = m.group('pid')	2123	m_pid = m.group('pid')
1334	m_msg = m.group('msg')	2124	m_msg = m.group('msg')
1335	if(testrun.cgformat):	2125	if(tp.cgformat):
1336	m_param3 = m.group('dur')	2126	m_param3 = m.group('dur')
1337	else:	2127	else:
1338	m_param3 = 'traceevent'	2128	m_param3 = 'traceevent'
@@ -1344,24 +2134,38 @@ def parseTraceLog(): · 5 unmodified lines
1344	# the line should be a call, return, or event	2134	# the line should be a call, return, or event
1345	if(not t.fcall and not t.freturn and not t.fevent):	2135	if(not t.fcall and not t.freturn and not t.fevent):
1346	continue	2136	continue
1347	# only parse the ftrace data during suspend/resume	2137	# find the start of suspend
1348	if(not testrun.inthepipe):	2138	if(t.startMarker()):
1349	# look for the suspend start marker	2139	phase = 'suspend_prepare'
1350	if(t.fevent):	2140	data = Data(len(testdata))
1351	if(t.name == 'SUSPEND START'):	2141	testdata.append(data)
1352	testrun.inthepipe = True	2142	testrun = TestRun(data)
1353	data.setStart(t.time)	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	continue	2166	continue
1355	# trace event processing	2167	# trace event processing
1356	if(t.fevent):	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	if(phase == 'post_resume'):	2169	if(phase == 'post_resume'):
1366	data.setEnd(t.time)	2170	data.setEnd(t.time)
1367	if(t.type == 'suspend_resume'):	2171	if(t.type == 'suspend_resume'):
@@ -1383,8 +2187,7 @@ def parseTraceLog(): · 15 unmodified lines
1383	m = re.match('(?P<name>.) .', t.name)	2187	m = re.match('(?P<name>.) .', t.name)
1384	name = m.group('name')	2188	name = m.group('name')
1385	# ignore these events	2189	# ignore these events
1386	if(re.match('acpi_suspend\[.*', t.name) or	2190	if(name.split('[')[0] in tracewatch):
1387	re.match('suspend_enter\[.*', name)):
1388	continue	2191	continue
1389	# -- phase changes --	2192	# -- phase changes --
1390	# suspend_prepare start	2193	# suspend_prepare start
@@ -1418,7 +2221,7 @@ def parseTraceLog(): · 27 unmodified lines
1418	data.dmesg[phase]['end'] = t.time	2221	data.dmesg[phase]['end'] = t.time
1419	data.tSuspended = t.time	2222	data.tSuspended = t.time
1420	else:	2223	else:
1421	if(sysvals.suspendmode in ['mem', 'disk']):	2224	if(sysvals.suspendmode in ['mem', 'disk'] and not tp.S0i3):
1422	data.dmesg['suspend_machine']['end'] = t.time	2225	data.dmesg['suspend_machine']['end'] = t.time
1423	data.tSuspended = t.time	2226	data.tSuspended = t.time
1424	phase = 'resume_machine'	2227	phase = 'resume_machine'
@@ -1426,6 +2229,15 @@ def parseTraceLog(): · 1 unmodified line
1426	data.tResumed = t.time	2229	data.tResumed = t.time
1427	data.tLow = data.tResumed - data.tSuspended	2230	data.tLow = data.tResumed - data.tSuspended
1428	continue	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	# resume_noirq start	2241	# resume_noirq start
1430	elif(re.match('dpm_resume_noirq\[.*', t.name)):	2242	elif(re.match('dpm_resume_noirq\[.*', t.name)):
1431	phase = 'resume_noirq'	2243	phase = 'resume_noirq'
@@ -1449,30 +2261,25 @@ def parseTraceLog(): · 17 unmodified lines
1449	if(isbegin):	2261	if(isbegin):
1450	data.dmesg[phase]['start'] = t.time	2262	data.dmesg[phase]['start'] = t.time
1451	continue	2263	continue
1452		2264	# skip trace events inside devices calls
1453	# is this trace event outside of the devices calls	2265	if(not data.isTraceEventOutsideDeviceCalls(pid, t.time)):
1454	if(data.isTraceEventOutsideDeviceCalls(pid, t.time)):	2266	continue
1455	# global events (outside device calls) are simply graphed	2267	# global events (outside device calls) are graphed
1456	if(name not in testrun.ttemp):	2268	if(name not in testrun.ttemp):
1457	testrun.ttemp[name] = []	2269	testrun.ttemp[name] = []
1458	if(isbegin):	2270	if(isbegin):
1459	# create a new list entry	2271	# create a new list entry
1460	testrun.ttemp[name].append(\	2272	testrun.ttemp[name].append(\
1461	{'begin': t.time, 'end': t.time})	2273	{'begin': t.time, 'end': t.time, 'pid': pid})
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})
1471	else:	2274	else:
1472	if(isbegin):	2275	if(len(testrun.ttemp[name]) > 0):
1473	data.addIntraDevTraceEvent('', name, pid, t.time)	2276	# if an entry exists, assume this is its end
1474	else:	2277	testrun.ttemp[name][-1]['end'] = t.time
1475	data.capIntraDevTraceEvent('', name, pid, 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	# device callback start	2283	# device callback start
1477	elif(t.type == 'device_pm_callback_start'):	2284	elif(t.type == 'device_pm_callback_start'):
1478	m = re.match('(?P<drv>.) (?P<d>.), parent: (?P<p>.), .*',\	2285	m = re.match('(?P<drv>.) (?P<d>.), parent: (?P<p>.), .*',\
@@ -1495,75 +2302,127 @@ def parseTraceLog(): · 16 unmodified lines
1495	dev = list[n]	2302	dev = list[n]
1496	dev['length'] = t.time - dev['start']	2303	dev['length'] = t.time - dev['start']
1497	dev['end'] = t.time	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	# callgraph processing	2335	# callgraph processing
1499	elif sysvals.usecallgraph:	2336	elif sysvals.usecallgraph:
1500	# this shouldn't happen, but JIC, ignore callgraph data post-res
1501	if(phase == 'post_resume'):
1502	continue
1503	# create a callgraph object for the data	2337	# create a callgraph object for the data
1504	if(pid not in testrun.ftemp):	2338	key = (m_proc, pid)
1505	testrun.ftemp[pid] = []	2339	if(key not in testrun.ftemp):
1506	testrun.ftemp[pid].append(FTraceCallGraph())	2340	testrun.ftemp[key] = []
		2341	testrun.ftemp[key].append(FTraceCallGraph(pid))
1507	# when the call is finished, see which device matches it	2342	# when the call is finished, see which device matches it
1508	cg = testrun.ftemp[pid][-1]	2343	cg = testrun.ftemp[key][-1]
1509	if(cg.addLine(t, m)):	2344	if(cg.addLine(t)):
1510	testrun.ftemp[pid].append(FTraceCallGraph())	2345	testrun.ftemp[key].append(FTraceCallGraph(pid))
1511	tf.close()	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	for test in testruns:	2362	for test in testruns:
1514	# add the traceevent data to the device hierarchy	2363	# add the traceevent data to the device hierarchy
1515	if(sysvals.usetraceevents):	2364	if(sysvals.usetraceevents):
		2365	# add actual trace funcs
1516	for name in test.ttemp:	2366	for name in test.ttemp:
1517	for event in test.ttemp[name]:	2367	for event in test.ttemp[name]:
1518	begin = event['begin']	2368	test.data.newActionGlobal(name, event['begin'], event['end'], event['pid'])
1519	end = event['end']	2369	# add the kprobe based virtual tracefuncs as actual devices
1520	# if event starts before timeline start, expand timeline	2370	for key in tp.ktemp:
1521	if(begin < test.data.start):	2371	name, pid = key
1522	test.data.setStart(begin)	2372	if name not in sysvals.tracefuncs:
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:
1536	continue	2373	continue
1537	if(not cg.sanityCheck()):	2374	for e in tp.ktemp[key]:
1538	id = 'task %s cpu %s' % (pid, m.group('cpu'))	2375	kb, ke = e['begin'], e['end']
1539	vprint('Sanity check failed for '+\	2376	if kb == ke or not test.data.isInsideTimeline(kb, ke):
1540	id+', ignoring this callback')	2377	continue
1541	continue	2378	test.data.newActionGlobal(e['name'], kb, ke, pid)
1542	callstart = cg.start	2379	# add config base kprobes and dev kprobes
1543	callend = cg.end	2380	for key in tp.ktemp:
1544	if(cg.list[0].name in borderphase):	2381	name, pid = key
1545	p = borderphase[cg.list[0].name]	2382	if name in sysvals.tracefuncs:
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'):
1555	continue	2383	continue
1556	for p in test.data.phases:	2384	for e in tp.ktemp[key]:
1557	if(test.data.dmesg[p]['start'] <= callstart and	2385	kb, ke = e['begin'], e['end']
1558	callstart <= test.data.dmesg[p]['end']):	2386	if kb == ke or not test.data.isInsideTimeline(kb, ke):
1559	list = test.data.dmesg[p]['list']	2387	continue
1560	for devname in list:	2388	color = sysvals.kprobeColor(e['name'])
1561	dev = list[devname]	2389	if name not in sysvals.dev_tracefuncs:
1562	if(pid == dev['pid'] and	2390	# config base kprobe
1563	callstart <= dev['start'] and	2391	test.data.newActionGlobal(e['name'], kb, ke, -2, color)
1564	callend >= dev['end']):	2392	elif sysvals.usedevsrc:
1565	dev['ftrace'] = cg	2393	# dev kprobe
1566	break	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	# fill in any missing phases	2427	# fill in any missing phases
1569	for data in testdata:	2428	for data in testdata:
@@ -1587,14 +2446,52 @@ def parseTraceLog(): · 17 unmodified lines
1587	if(sysvals.verbose):	2446	if(sysvals.verbose):
1588	data.printDetails()	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	return testdata	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	# Function: loadKernelLog	2495	# Function: loadKernelLog
1599	# Description:	2496	# Description:
1600	# [deprecated for kernel 3.15.0 or newer]	2497	# [deprecated for kernel 3.15.0 or newer]
@@ -1607,9 +2504,10 @@ def loadKernelLog(): · 6 unmodified lines
1607		2504
1608	vprint('Analyzing the dmesg data...')	2505	vprint('Analyzing the dmesg data...')
1609	if(os.path.exists(sysvals.dmesgfile) == False):	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	testruns = []	2511	testruns = []
1614	data = 0	2512	data = 0
1615	lf = open(sysvals.dmesgfile, 'r')	2513	lf = open(sysvals.dmesgfile, 'r')
@@ -1620,35 +2518,43 @@ def loadKernelLog(): · 4 unmodified lines
1620	line = line[idx:]	2518	line = line[idx:]
1621	m = re.match(sysvals.stampfmt, line)	2519	m = re.match(sysvals.stampfmt, line)
1622	if(m):	2520	if(m):
1623	if(data):	2521	tp.stamp = line
1624	testruns.append(data)
1625	data = Data(len(testruns))
1626	parseStamp(m, data)
1627	continue
1628	if(not data):
1629	continue	2522	continue
1630	m = re.match(sysvals.firmwarefmt, line)	2523	m = re.match(sysvals.firmwarefmt, line)
1631	if(m):	2524	if(m):
1632	data.fwSuspend = int(m.group('s'))	2525	tp.fwdata.append((int(m.group('s')), int(m.group('r'))))
1633	data.fwResume = int(m.group('r'))
1634	if(data.fwSuspend > 0 or data.fwResume > 0):
1635	data.fwValid = True
1636	continue	2526	continue
1637	m = re.match('[ \t](\[ )(?P<ktime>[0-9\.])(\]) (?P<msg>.)', line)	2527	m = re.match('[ \t](\[ )(?P<ktime>[0-9\.])(\]) (?P<msg>.)', line)
1638	if(m):	2528	if(not m):
1639	data.dmesgtext.append(line)	2529	continue
1640	if(re.match('ACPI: resume from mwait', m.group('msg'))):	2530	msg = m.group("msg")
1641	print('NOTE: This suspend appears to be freeze rather than'+\	2531	if(re.match('PM: Syncing filesystems.*', msg)):
1642	' %s, it will be treated as such' % sysvals.suspendmode)	2532	if(data):
1643	sysvals.suspendmode = 'freeze'	2533	testruns.append(data)
1644	else:	2534	data = Data(len(testruns))
1645	vprint('ignoring dmesg line: %s' % line.replace('\n', ''))	2535	parseStamp(tp.stamp, data)
1646	testruns.append(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	lf.close()	2549	lf.close()
1648		2550
1649	if(not data):	2551	if(len(testruns) < 1):
1650	print('ERROR: analyze_suspend header missing from dmesg log')	2552	# bad log, but see if you can extract something meaningful anyway
1651	sys.exit()	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	# fix lines with same timestamp/function with the call and return swapped	2559	# fix lines with same timestamp/function with the call and return swapped
1654	for data in testruns:	2560	for data in testruns:
@@ -1865,7 +2771,8 @@ def parseKernelLog(data): · 210 unmodified lines
1865	actions[a] = []	2771	actions[a] = []
1866	actions[a].append({'begin': ktime, 'end': ktime})	2772	actions[a].append({'begin': ktime, 'end': ktime})
1867	if(re.match(at[a]['emsg'], msg)):	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	# now look for CPU on/off events	2776	# now look for CPU on/off events
1870	if(re.match('Disabling non-boot CPUs .*', msg)):	2777	if(re.match('Disabling non-boot CPUs .*', msg)):
1871	# start of first cpu suspend	2778	# start of first cpu suspend
@@ -1912,15 +2819,7 @@ def parseKernelLog(data): · 40 unmodified lines
1912	# fill in any actions we've found	2819	# fill in any actions we've found
1913	for name in actions:	2820	for name in actions:
1914	for event in actions[name]:	2821	for event in actions[name]:
1915	begin = event['begin']	2822	data.newActionGlobal(name, event['begin'], event['end'])
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)
1924		2823
1925	if(sysvals.verbose):	2824	if(sysvals.verbose):
1926	data.printDetails()	2825	data.printDetails()
@@ -1929,92 +2828,6 @@ def parseKernelLog(data): · 2 unmodified lines
1929	data.fixupInitcallsThatDidntReturn()	2828	data.fixupInitcallsThatDidntReturn()
1930	return True	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	# Function: createHTMLSummarySimple	2831	# Function: createHTMLSummarySimple
2019	# Description:	2832	# Description:
2020	# Create summary html file for a series of tests	2833	# Create summary html file for a series of tests
@@ -2146,6 +2959,32 @@ def createHTMLSummarySimple(testruns, htmlfile): · 125 unmodified lines
2146	hf.write('</body>\n</html>\n')	2959	hf.write('</body>\n</html>\n')
2147	hf.close()	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	# Function: createHTML	2988	# Function: createHTML
2150	# Description:	2989	# Description:
2151	# Create the output html file from the resident test data	2990	# Create the output html file from the resident test data
@@ -2156,6 +2995,10 @@ def createHTMLSummarySimple(testruns, htmlfile): · 4 unmodified lines
2156	def createHTML(testruns):	2995	def createHTML(testruns):
2157	global sysvals	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	for data in testruns:	3002	for data in testruns:
2160	data.normalizeTime(testruns[-1].tSuspended)	3003	data.normalizeTime(testruns[-1].tSuspended)
2161		3004
@@ -2163,16 +3006,18 @@ def createHTML(testruns): · 1 unmodified line
2163	if len(testruns) > 1:	3006	if len(testruns) > 1:
2164	x2changes = ['1', 'relative']	3007	x2changes = ['1', 'relative']
2165	# html function templates	3008	# html function templates
		3009	headline_version = '<div class="version"><a href="https://01.org/suspendresume">AnalyzeSuspend v%s</a></div>' % sysvals.version
2166	headline_stamp = '<div class="stamp">{0} {1} {2} {3}</div>\n'	3010	headline_stamp = '<div class="stamp">{0} {1} {2} {3}</div>\n'
2167	html_devlist1 = '<button id="devlist1" class="devlist" style="float:left;">Device Detail%s</button>' % x2changes[0]	3011	html_devlist1 = '<button id="devlist1" class="devlist" style="float:left;">Device Detail%s</button>' % x2changes[0]
2168	html_zoombox = '<center><button id="zoomin">ZOOM IN</button><button id="zoomout">ZOOM OUT</button><button id="zoomdef">ZOOM 1:1</button></center>\n'	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	html_devlist2 = '<button id="devlist2" class="devlist" style="float:right;">Device Detail2</button>\n'	3013	html_devlist2 = '<button id="devlist2" class="devlist" style="float:right;">Device Detail2</button>\n'
2170	html_timeline = '<div id="dmesgzoombox" class="zoombox">\n<div id="{0}" class="timeline" style="height:{1}px">\n'	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'	3015	html_tblock = '<div id="block{0}" class="tblock" style="left:{1}%;width:{2}%;">\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'	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'
2173	html_phase = '<div class="phase" style="left:{0}%;width:{1}%;top:{2}%;height:{3}%;background-color:{4}">{5}</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	html_phaselet = '<div id="{0}" class="phaselet" style="left:{1}%;width:{2}%;background-color:{3}"></div>\n'	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	html_timetotal = '<table class="time1">\n<tr>'\	3021	html_timetotal = '<table class="time1">\n<tr>'\
2177	'<td class="green">{2} Suspend Time: <b>{0} ms</b></td>'\	3022	'<td class="green">{2} Suspend Time: <b>{0} ms</b></td>'\
2178	'<td class="yellow">{2} Resume Time: <b>{1} ms</b></td>'\	3023	'<td class="yellow">{2} Resume Time: <b>{1} ms</b></td>'\
@@ -2182,6 +3027,10 @@ def createHTML(testruns): · 3 unmodified lines
2182	'<td class="gray">'+sysvals.suspendmode+' time: <b>{1} ms</b></td>'\	3027	'<td class="gray">'+sysvals.suspendmode+' time: <b>{1} ms</b></td>'\
2183	'<td class="yellow">{3} Resume Time: <b>{2} ms</b></td>'\	3028	'<td class="yellow">{3} Resume Time: <b>{2} ms</b></td>'\
2184	'</tr>\n</table>\n'	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	html_timegroups = '<table class="time2">\n<tr>'\	3034	html_timegroups = '<table class="time2">\n<tr>'\
2186	'<td class="green">{4}Kernel Suspend: {0} ms</td>'\	3035	'<td class="green">{4}Kernel Suspend: {0} ms</td>'\
2187	'<td class="purple">{4}Firmware Suspend: {1} ms</td>'\	3036	'<td class="purple">{4}Firmware Suspend: {1} ms</td>'\
@@ -2189,12 +3038,21 @@ def createHTML(testruns): · 1 unmodified line
2189	'<td class="yellow">{4}Kernel Resume: {3} ms</td>'\	3038	'<td class="yellow">{4}Kernel Resume: {3} ms</td>'\
2190	'</tr>\n</table>\n'	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	# device timeline	3050	# device timeline
2193	vprint('Creating Device Timeline...')	3051	vprint('Creating Device Timeline...')
2194	devtl = Timeline()	3052
		3053	devtl = Timeline(rowheight)
2195		3054
2196	# Generate the header for this timeline	3055	# Generate the header for this timeline
2197	textnum = ['First', 'Second']
2198	for data in testruns:	3056	for data in testruns:
2199	tTotal = data.end - data.start	3057	tTotal = data.end - data.start
2200	tEnd = data.dmesg['resume_complete']['end']	3058	tEnd = data.dmesg['resume_complete']['end']
@@ -2203,7 +3061,17 @@ def createHTML(testruns): · 2 unmodified lines
2203	sys.exit()	3061	sys.exit()
2204	if(data.tLow > 0):	3062	if(data.tLow > 0):
2205	low_time = '%.0f'%(data.tLow*1000)	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	suspend_time = '%.0f'%((data.tSuspended-data.start)*1000 + \	3075	suspend_time = '%.0f'%((data.tSuspended-data.start)*1000 + \
2208	(data.fwSuspend/1000000.0))	3076	(data.fwSuspend/1000000.0))
2209	resume_time = '%.0f'%((tEnd-data.tSuspended)*1000 + \	3077	resume_time = '%.0f'%((tEnd-data.tSuspended)*1000 + \
@@ -2211,7 +3079,7 @@ def createHTML(testruns): · 1 unmodified line
2211	testdesc1 = 'Total'	3079	testdesc1 = 'Total'
2212	testdesc2 = ''	3080	testdesc2 = ''
2213	if(len(testruns) > 1):	3081	if(len(testruns) > 1):
2214	testdesc1 = testdesc2 = textnum[data.testnumber]	3082	testdesc1 = testdesc2 = ordinal(data.testnumber+1)
2215	testdesc2 += ' '	3083	testdesc2 += ' '
2216	if(data.tLow == 0):	3084	if(data.tLow == 0):
2217	thtml = html_timetotal.format(suspend_time, \	3085	thtml = html_timetotal.format(suspend_time, \
@@ -2219,28 +3087,28 @@ def createHTML(testruns): · 1 unmodified line
2219	else:	3087	else:
2220	thtml = html_timetotal2.format(suspend_time, low_time, \	3088	thtml = html_timetotal2.format(suspend_time, low_time, \
2221	resume_time, testdesc1)	3089	resume_time, testdesc1)
2222	devtl.html['timeline'] += thtml	3090	devtl.html['header'] += thtml
2223	sktime = '%.3f'%((data.dmesg['suspend_machine']['end'] - \	3091	sktime = '%.3f'%((data.dmesg['suspend_machine']['end'] - \
2224	data.getStart())*1000)	3092	data.getStart())*1000)
2225	sftime = '%.3f'%(data.fwSuspend / 1000000.0)	3093	sftime = '%.3f'%(data.fwSuspend / 1000000.0)
2226	rftime = '%.3f'%(data.fwResume / 1000000.0)	3094	rftime = '%.3f'%(data.fwResume / 1000000.0)
2227	rktime = '%.3f'%((data.getEnd() - \	3095	rktime = '%.3f'%((data.dmesg['resume_complete']['end'] - \
2228	data.dmesg['resume_machine']['start'])*1000)	3096	data.dmesg['resume_machine']['start'])*1000)
2229	devtl.html['timeline'] += html_timegroups.format(sktime, \	3097	devtl.html['header'] += html_timegroups.format(sktime, \
2230	sftime, rftime, rktime, testdesc2)	3098	sftime, rftime, rktime, testdesc2)
2231	else:	3099	else:
2232	suspend_time = '%.0f'%((data.tSuspended-data.start)*1000)	3100	suspend_time = '%.0f'%((data.tSuspended-data.start)*1000)
2233	resume_time = '%.0f'%((tEnd-data.tSuspended)*1000)	3101	resume_time = '%.0f'%((tEnd-data.tSuspended)*1000)
2234	testdesc = 'Kernel'	3102	testdesc = 'Kernel'
2235	if(len(testruns) > 1):	3103	if(len(testruns) > 1):
2236	testdesc = textnum[data.testnumber]+' '+testdesc	3104	testdesc = ordinal(data.testnumber+1)+' '+testdesc
2237	if(data.tLow == 0):	3105	if(data.tLow == 0):
2238	thtml = html_timetotal.format(suspend_time, \	3106	thtml = html_timetotal.format(suspend_time, \
2239	resume_time, testdesc)	3107	resume_time, testdesc)
2240	else:	3108	else:
2241	thtml = html_timetotal2.format(suspend_time, low_time, \	3109	thtml = html_timetotal2.format(suspend_time, low_time, \
2242	resume_time, testdesc)	3110	resume_time, testdesc)
2243	devtl.html['timeline'] += thtml	3111	devtl.html['header'] += thtml
2244		3112
2245	# time scale for potentially multiple datasets	3113	# time scale for potentially multiple datasets
2246	t0 = testruns[0].start	3114	t0 = testruns[0].start
@@ -2249,153 +3117,241 @@ def createHTML(testruns): · 2 unmodified lines
2249	tTotal = tMax - t0	3117	tTotal = tMax - t0
2250		3118
2251	# determine the maximum number of rows we need to draw	3119	# determine the maximum number of rows we need to draw
2252	timelinerows = 0
2253	for data in testruns:	3120	for data in testruns:
2254	for phase in data.dmesg:	3121	data.selectTimelineDevices('%f', tTotal, sysvals.mindevlen)
2255	list = data.dmesg[phase]['list']	3122	for group in data.devicegroups:
2256	rows = setTimelineRows(list, list)	3123	devlist = []
2257	data.dmesg[phase]['row'] = rows	3124	for phase in group:
2258	if(rows > timelinerows):	3125	for devname in data.tdevlist[phase]:
2259	timelinerows = rows	3126	devlist.append((phase,devname))
2260		3127	devtl.getPhaseRows(data.dmesg, devlist)
2261	# calculate the timeline height and create bounding box, add buttons	3128	devtl.calcTotalRows()
2262	devtl.setRows(timelinerows + 1)	3129
2263	devtl.html['timeline'] += html_devlist1	3130	# create bounding box, add buttons
2264	if len(testruns) > 1:	3131	if sysvals.suspendmode != 'command':
2265	devtl.html['timeline'] += html_devlist2	3132	devtl.html['timeline'] += html_devlist1
		3133	if len(testruns) > 1:
		3134	devtl.html['timeline'] += html_devlist2
2266	devtl.html['timeline'] += html_zoombox	3135	devtl.html['timeline'] += html_zoombox
2267	devtl.html['timeline'] += html_timeline.format('dmesg', devtl.height)	3136	devtl.html['timeline'] += html_timeline.format('dmesg', devtl.height)
2268		3137
2269	# draw the colored boxes for each of the phases	3138	# draw the full timeline
2270	for data in testruns:	3139	phases = {'suspend':[],'resume':[]}
2271	for b in data.dmesg:	3140	for phase in data.dmesg:
2272	phase = data.dmesg[b]	3141	if 'resume' in phase:
2273	length = phase['end']-phase['start']	3142	phases['resume'].append(phase)
2274	left = '%.3f' % (((phase['start']-t0)*100.0)/tTotal)	3143	else:
2275	width = '%.3f' % ((length*100.0)/tTotal)	3144	phases['suspend'].append(phase)
2276	devtl.html['timeline'] += html_phase.format(left, width, \
2277	'%.3f'%devtl.scaleH, '%.3f'%(100-devtl.scaleH), \
2278	data.dmesg[b]['color'], '')
2279		3145
2280	# draw the time scale, try to make the number of labels readable	3146	# draw each test run chronologically
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
2304	for data in testruns:	3147	for data in testruns:
2305	for b in data.dmesg:	3148	# if nore than one test, draw a block to represent user mode
2306	phaselist = data.dmesg[b]['list']	3149	if(data.testnumber > 0):
2307	for name in phaselist:	3150	m0 = testruns[data.testnumber-1].end
2308	dev = phaselist[name]	3151	mMax = testruns[data.testnumber].start
2309	if('traceevents' in dev):	3152	mTotal = mMax - m0
2310	vprint('Debug trace events found for device %s' % name)	3153	name = 'usermode%d' % data.testnumber
2311	vprint('%20s %20s %10s %8s' % ('action', \	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	'name', 'time(ms)', 'length(ms)'))	3226	'name', 'time(ms)', 'length(ms)'))
2313	for e in dev['traceevents']:	3227	for e in dev['src']:
2314	vprint('%20s %20s %10.3f %8.3f' % (e.action, \	3228	vprint('%20s %20s %10.3f %8.3f' % (e.title, \
2315	e.name, e.time1000, e.length1000))	3229	e.text, e.time1000, e.length1000))
2316	height = (100.0 - devtl.scaleH)/data.dmesg[b]['row']	3230	height = devtl.rowH
2317	top = '%.3f' % ((dev['row']*height) + devtl.scaleH)	3231	top = '%.3f' % (rowtop + devtl.scaleH + (e.row*devtl.rowH))
2318	left = '%.3f' % (((e.time-t0)*100)/tTotal)	3232	left = '%f' % (((e.time-m0)*100)/mTotal)
2319	width = '%.3f' % (e.length*100/tTotal)	3233	width = '%f' % (e.length*100/mTotal)
2320	color = 'rgba(204,204,204,0.5)'	3234	color = 'rgba(204,204,204,0.5)'
2321	devtl.html['timeline'] += \	3235	devtl.html['timeline'] += \
2322	html_traceevent.format(e.action+' '+e.name, \	3236	html_traceevent.format(e.title, \
2323	left, top, '%.3f'%height, \	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	# timeline is finished	3243	# timeline is finished
2327	devtl.html['timeline'] += '</div>\n</div>\n'	3244	devtl.html['timeline'] += '</div>\n</div>\n'
2328		3245
2329	# draw a legend which describes the phases by color	3246	# draw a legend which describes the phases by color
2330	data = testruns[-1]	3247	if sysvals.suspendmode != 'command':
2331	devtl.html['legend'] = '<div class="legend">\n'	3248	data = testruns[-1]
2332	pdelta = 100.0/len(data.phases)	3249	devtl.html['legend'] = '<div class="legend">\n'
2333	pmargin = pdelta / 4.0	3250	pdelta = 100.0/len(data.phases)
2334	for phase in data.phases:	3251	pmargin = pdelta / 4.0
2335	order = '%.2f' % ((data.dmesg[phase]['order'] * pdelta) + pmargin)	3252	for phase in data.phases:
2336	name = string.replace(phase, '_', '  ')	3253	tmp = phase.split('_')
2337	devtl.html['legend'] += html_legend.format(order, \	3254	id = tmp[0][0]
2338	data.dmesg[phase]['color'], name)	3255	if(len(tmp) > 1):
2339	devtl.html['legend'] += '</div>\n'	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	hf = open(sysvals.htmlfile, 'w')	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	# write the html header first (html head, css code, up to body start)	3272	# write the html header first (html head, css code, up to body start)
2345	html_header = '<!DOCTYPE html>\n<html>\n<head>\n\	3273	html_header = '<!DOCTYPE html>\n<html>\n<head>\n\
2346	<meta http-equiv="content-type" content="text/html; charset=UTF-8">\n\	3274	<meta http-equiv="content-type" content="text/html; charset=UTF-8">\n\
2347	<title>AnalyzeSuspend</title>\n\	3275	<title>'+htmlTitle()+'</title>\n\
2348	<style type=\'text/css\'>\n\	3276	<style type=\'text/css\'>\n\
2349	body {overflow-y: scroll;}\n\	3277	body {overflow-y:scroll;}\n\
2350	.stamp {width: 100%;text-align:center;background-color:gray;line-height:30px;color:white;font: 25px Arial;}\n\	3278	.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\	3279	.callgraph {margin-top:30px;box-shadow:5px 5px 20px black;}\n\
2352	.callgraph article * {padding-left: 28px;}\n\	3280	.callgraph article * {padding-left:28px;}\n\
2353	h1 {color:black;font: bold 30px Times;}\n\	3281	h1 {color:black;font:bold 30px Times;}\n\
2354	t0 {color:black;font: bold 30px Times;}\n\	3282	t0 {color:black;font:bold 30px Times;}\n\
2355	t1 {color:black;font: 30px Times;}\n\	3283	t1 {color:black;font:30px Times;}\n\
2356	t2 {color:black;font: 25px Times;}\n\	3284	t2 {color:black;font:25px Times;}\n\
2357	t3 {color:black;font: 20px Times;white-space:nowrap;}\n\	3285	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\	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	table {width:100%;}\n\	3289	table {width:100%;}\n\
2360	.gray {background-color:rgba(80,80,80,0.1);}\n\	3290	.gray {background-color:rgba(80,80,80,0.1);}\n\
2361	.green {background-color:rgba(204,255,204,0.4);}\n\	3291	.green {background-color:rgba(204,255,204,0.4);}\n\
2362	.purple {background-color:rgba(128,0,128,0.2);}\n\	3292	.purple {background-color:rgba(128,0,128,0.2);}\n\
2363	.yellow {background-color:rgba(255,255,204,0.4);}\n\	3293	.yellow {background-color:rgba(255,255,204,0.4);}\n\
2364	.time1 {font: 22px Arial;border:1px solid;}\n\	3294	.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\	3295	.time2 {font:15px Arial;border-bottom:1px solid;border-left:1px solid;border-right:1px solid;}\n\
2366	td {text-align: center;}\n\	3296	td {text-align:center;}\n\
2367	r {color:#500000;font:15px Tahoma;}\n\	3297	r {color:#500000;font:15px Tahoma;}\n\
2368	n {color:#505050;font:15px Tahoma;}\n\	3298	n {color:#505050;font:15px Tahoma;}\n\
2369	.tdhl {color: red;}\n\	3299	.tdhl {color:red;}\n\
2370	.hide {display: none;}\n\	3300	.hide {display:none;}\n\
2371	.pf {display: none;}\n\	3301	.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\	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\
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\	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\
2374	.pf:checked ~ *:not(:nth-child(2)) {display: none;}\n\	3304	.pf:'+cgchk+' ~ *:not(:nth-child(2)) {display:none;}\n\
2375	.zoombox {position: relative; width: 100%; overflow-x: scroll;}\n\	3305	.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\	3306	.timeline {position:relative;font-size:14px;cursor:pointer;width:100%; overflow:hidden;background:linear-gradient(#cccccc, white);}\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\	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\
2378	.thread:hover {background-color:white;border:1px solid red;z-index:10;}\n\	3308	.thread.sync {background-color:'+sysvals.synccolor+';}\n\
2379	.hover {background-color:white;border:1px solid red;z-index:10;}\n\	3309	.thread.bg {background-color:'+sysvals.kprobecolor+';}\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\	3310	.thread:hover {background-color:white;border:1px solid red;'+hoverZ+'}\n\
2381	.phase {position: absolute;overflow: hidden;border:0px;text-align:center;}\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	.phaselet {position:absolute;overflow:hidden;border:0px;text-align:center;height:100px;font-size:24px;}\n\	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\	3318	.t {z-index:2;position:absolute;pointer-events:none;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\	3319	.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\	3320	.legend .square {position:absolute;cursor:pointer;top:10px; width:0px;height:20px;border:1px solid;padding-left:20px;}\n\
2386	button {height:40px;width:200px;margin-bottom:20px;margin-top:20px;font-size:24px;}\n\	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	.devlist {position:'+x2changes[1]+';width:190px;}\n\	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	</style>\n</head>\n<body>\n'	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	# write the test title and general info header	3342	# write the test title and general info header
2393	if(sysvals.stamp['time'] != ""):	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	hf.write(headline_stamp.format(sysvals.stamp['host'],	3349	hf.write(headline_stamp.format(sysvals.stamp['host'],
2395	sysvals.stamp['kernel'], sysvals.stamp['mode'], \	3350	sysvals.stamp['kernel'], sysvals.stamp['mode'], \
2396	sysvals.stamp['time']))	3351	sysvals.stamp['time']))
2397		3352
2398	# write the device timeline	3353	# write the device timeline
		3354	hf.write(devtl.html['header'])
2399	hf.write(devtl.html['timeline'])	3355	hf.write(devtl.html['timeline'])
2400	hf.write(devtl.html['legend'])	3356	hf.write(devtl.html['legend'])
2401	hf.write('<div id="devicedetailtitle"></div>\n')	3357	hf.write('<div id="devicedetailtitle"></div>\n')
@@ -2410,12 +3366,15 @@ def createHTML(testruns): · 8 unmodified lines
2410	width = '%.3f' % ((length*100.0)/tTotal)	3366	width = '%.3f' % ((length*100.0)/tTotal)
2411	hf.write(html_phaselet.format(b, left, width, \	3367	hf.write(html_phaselet.format(b, left, width, \
2412	data.dmesg[b]['color']))	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	hf.write('</div>\n')	3372	hf.write('</div>\n')
2414	hf.write('</div>\n')	3373	hf.write('</div>\n')
2415		3374
2416	# write the ftrace data (callgraph)	3375	# write the ftrace data (callgraph)
2417	data = testruns[-1]	3376	data = testruns[-1]
2418	if(sysvals.usecallgraph):	3377	if(sysvals.usecallgraph and not sysvals.embedded):
2419	hf.write('<section id="callgraphs" class="callgraph">\n')	3378	hf.write('<section id="callgraphs" class="callgraph">\n')
2420	# write out the ftrace data converted to html	3379	# write out the ftrace data converted to html
2421	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'	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	for devname in data.sortedDevices(p):	3387	for devname in data.sortedDevices(p):
2429	if('ftrace' not in list[devname]):	3388	if('ftrace' not in list[devname]):
2430	continue	3389	continue
2431	name = devname
2432	if(devname in sysvals.altdevname):
2433	name = sysvals.altdevname[devname]
2434	devid = list[devname]['id']	3390	devid = list[devname]['id']
2435	cg = list[devname]['ftrace']	3391	cg = list[devname]['ftrace']
2436	flen = '<r>(%.3f ms @ %.3f to %.3f)</r>' % \	3392	clen = (cg.end - cg.start) * 1000
2437	((cg.end - cg.start)1000, cg.start1000, cg.end*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	hf.write(html_func_top.format(devid, data.dmesg[p]['color'], \	3404	hf.write(html_func_top.format(devid, data.dmesg[p]['color'], \
2439	num, name+' '+p, flen))	3405	num, ftitle, flen))
2440	num += 1	3406	num += 1
2441	for line in cg.list:	3407	for line in cg.list:
2442	if(line.length < 0.000000001):	3408	if(line.length < 0.000000001):
2443	flen = ''	3409	flen = ''
2444	else:	3410	else:
2445	flen = '<n>(%.3f ms @ %.3f)</n>' % (line.length*1000, \	3411	fmt = '<n>(%.3f ms @ '+sysvals.timeformat+')</n>'
2446	line.time*1000)	3412	flen = fmt % (line.length*1000, line.time)
2447	if(line.freturn and line.fcall):	3413	if(line.freturn and line.fcall):
2448	hf.write(html_func_leaf.format(line.name, flen))	3414	hf.write(html_func_leaf.format(line.name, flen))
2449	elif(line.freturn):	3415	elif(line.freturn):
@@ -2453,9 +3419,40 @@ def createHTML(testruns): · 3 unmodified lines
2453	num += 1	3419	num += 1
2454	hf.write(html_func_end)	3420	hf.write(html_func_end)
2455	hf.write('\n\n </section>\n')	3421	hf.write('\n\n </section>\n')
2456	# write the footer and close	3422
2457	addScriptCode(hf, testruns)	3423	# add the dmesg log as a hidden div
2458	hf.write('</body>\n</html>\n')	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	hf.close()	3456	hf.close()
2460	return True	3457	return True
2461		3458
@@ -2466,8 +3463,8 @@ def createHTML(testruns): · 4 unmodified lines
2466	# hf: the open html file pointer	3463	# hf: the open html file pointer
2467	# testruns: array of Data objects from parseKernelLog or parseTraceLog	3464	# testruns: array of Data objects from parseKernelLog or parseTraceLog
2468	def addScriptCode(hf, testruns):	3465	def addScriptCode(hf, testruns):
2469	t0 = (testruns[0].start - testruns[-1].tSuspended) * 1000	3466	t0 = testruns[0].start * 1000
2470	tMax = (testruns[-1].end - testruns[-1].tSuspended) * 1000	3467	tMax = testruns[-1].end * 1000
2471	# create an array in javascript memory with the device details	3468	# create an array in javascript memory with the device details
2472	detail = ' var devtable = [];\n'	3469	detail = ' var devtable = [];\n'
2473	for data in testruns:	3470	for data in testruns:
@@ -2477,8 +3474,43 @@ def addScriptCode(hf, testruns): · 3 unmodified lines
2477	# add the code which will manipulate the data in the browser	3474	# add the code which will manipulate the data in the browser
2478	script_code = \	3475	script_code = \
2479	'<script type="text/javascript">\n'+detail+\	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	' function zoomTimeline() {\n'\	3513	' function zoomTimeline() {\n'\
2481	' var timescale = document.getElementById("timescale");\n'\
2482	' var dmesg = document.getElementById("dmesg");\n'\	3514	' var dmesg = document.getElementById("dmesg");\n'\
2483	' var zoombox = document.getElementById("dmesgzoombox");\n'\	3515	' var zoombox = document.getElementById("dmesgzoombox");\n'\
2484	' var val = parseFloat(dmesg.style.width);\n'\	3516	' var val = parseFloat(dmesg.style.width);\n'\
@@ -2486,7 +3518,7 @@ def addScriptCode(hf, testruns): · 1 unmodified line
2486	' var sh = window.outerWidth / 2;\n'\	3518	' var sh = window.outerWidth / 2;\n'\
2487	' if(this.id == "zoomin") {\n'\	3519	' if(this.id == "zoomin") {\n'\
2488	' newval = val * 1.2;\n'\	3520	' newval = val * 1.2;\n'\
2489	' if(newval > 40000) newval = 40000;\n'\	3521	' if(newval > 910034) newval = 910034;\n'\
2490	' dmesg.style.width = newval+"%";\n'\	3522	' dmesg.style.width = newval+"%";\n'\
2491	' zoombox.scrollLeft = ((zoombox.scrollLeft + sh) * newval / val) - sh;\n'\	3523	' zoombox.scrollLeft = ((zoombox.scrollLeft + sh) * newval / val) - sh;\n'\
2492	' } else if (this.id == "zoomout") {\n'\	3524	' } else if (this.id == "zoomout") {\n'\
@@ -2498,19 +3530,17 @@ def addScriptCode(hf, testruns): · 5 unmodified lines
2498	' zoombox.scrollLeft = 0;\n'\	3530	' zoombox.scrollLeft = 0;\n'\
2499	' dmesg.style.width = "100%";\n'\	3531	' dmesg.style.width = "100%";\n'\
2500	' }\n'\	3532	' }\n'\
2501	' var html = "";\n'\	3533	' var tS = [10000, 5000, 2000, 1000, 500, 200, 100, 50, 20, 10, 5, 2, 1];\n'\
2502	' var t0 = bounds[0];\n'\	3534	' var t0 = bounds[0];\n'\
2503	' var tMax = bounds[1];\n'\	3535	' var tMax = bounds[1];\n'\
2504	' var tTotal = tMax - t0;\n'\	3536	' var tTotal = tMax - t0;\n'\
2505	' var wTotal = tTotal * 100.0 / newval;\n'\	3537	' var wTotal = tTotal * 100.0 / newval;\n'\
2506	' for(var tS = 1000; (wTotal / tS) < 3; tS /= 10);\n'\	3538	' var idx = 7*window.innerWidth/1100;\n'\
2507	' if(tS < 1) tS = 1;\n'\	3539	' for(var i = 0; (i < tS.length)&&((wTotal / tS[i]) < idx); i++);\n'\
2508	' for(var s = ((t0 / tS)\|0) * tS; s < tMax; s += tS) {\n'\	3540	' if(i >= tS.length) i = tS.length - 1;\n'\
2509	' var pos = (tMax - s) * 100.0 / tTotal;\n'\	3541	' if(tS[i] == resolution) return;\n'\
2510	' var name = (s == 0)?"S/R":(s+"ms");\n'\	3542	' resolution = tS[i];\n'\
2511	' html += "<div class=\\"t\\" style=\\"right:"+pos+"%\\">"+name+"</div>";\n'\	3543	' redrawTimescale(t0, tMax, tS[i]);\n'\
2512	' }\n'\
2513	' timescale.innerHTML = html;\n'\
2514	' }\n'\	3544	' }\n'\
2515	' function deviceHover() {\n'\	3545	' function deviceHover() {\n'\
2516	' var name = this.title.slice(0, this.title.indexOf(" ("));\n'\	3546	' var name = this.title.slice(0, this.title.indexOf(" ("));\n'\
@@ -2523,12 +3553,13 @@ def addScriptCode(hf, testruns): · 6 unmodified lines
2523	' cpu = parseInt(name.slice(8));\n'\	3553	' cpu = parseInt(name.slice(8));\n'\
2524	' for (var i = 0; i < dev.length; i++) {\n'\	3554	' for (var i = 0; i < dev.length; i++) {\n'\
2525	' dname = dev[i].title.slice(0, dev[i].title.indexOf(" ("));\n'\	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	' if((cpu >= 0 && dname.match("CPU_O[NF]\\\["+cpu+"\\\]")) \|\|\n'\	3557	' if((cpu >= 0 && dname.match("CPU_O[NF]\\\["+cpu+"\\\]")) \|\|\n'\
2527	' (name == dname))\n'\	3558	' (name == dname))\n'\
2528	' {\n'\	3559	' {\n'\
2529	' dev[i].className = "thread hover";\n'\	3560	' dev[i].className = "hover "+cname;\n'\
2530	' } else {\n'\	3561	' } else {\n'\
2531	' dev[i].className = "thread";\n'\	3562	' dev[i].className = cname;\n'\
2532	' }\n'\	3563	' }\n'\
2533	' }\n'\	3564	' }\n'\
2534	' }\n'\	3565	' }\n'\
@@ -2536,7 +3567,7 @@ def addScriptCode(hf, testruns): · 1 unmodified line
2536	' var dmesg = document.getElementById("dmesg");\n'\	3567	' var dmesg = document.getElementById("dmesg");\n'\
2537	' var dev = dmesg.getElementsByClassName("thread");\n'\	3568	' var dev = dmesg.getElementsByClassName("thread");\n'\
2538	' for (var i = 0; i < dev.length; i++) {\n'\	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	' }\n'\	3571	' }\n'\
2541	' }\n'\	3572	' }\n'\
2542	' function deviceTitle(title, total, cpu) {\n'\	3573	' function deviceTitle(title, total, cpu) {\n'\
@@ -2547,7 +3578,7 @@ def addScriptCode(hf, testruns): · 4 unmodified lines
2547	' total[2] = (total[2]+total[4])/2;\n'\	3578	' total[2] = (total[2]+total[4])/2;\n'\
2548	' }\n'\	3579	' }\n'\
2549	' var devtitle = document.getElementById("devicedetailtitle");\n'\	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	' if(cpu >= 0) name = "CPU"+cpu;\n'\	3582	' if(cpu >= 0) name = "CPU"+cpu;\n'\
2552	' var driver = "";\n'\	3583	' var driver = "";\n'\
2553	' var tS = "<t2>(</t2>";\n'\	3584	' var tS = "<t2>(</t2>";\n'\
@@ -2579,6 +3610,8 @@ def addScriptCode(hf, testruns): · 25 unmodified lines
2579	' var dev = dmesg.getElementsByClassName("thread");\n'\	3610	' var dev = dmesg.getElementsByClassName("thread");\n'\
2580	' var idlist = [];\n'\	3611	' var idlist = [];\n'\
2581	' var pdata = [[]];\n'\	3612	' var pdata = [[]];\n'\
		3613	' if(document.getElementById("devicedetail1"))\n'\
		3614	' pdata = [[], []];\n'\
2582	' var pd = pdata[0];\n'\	3615	' var pd = pdata[0];\n'\
2583	' var total = [0.0, 0.0, 0.0];\n'\	3616	' var total = [0.0, 0.0, 0.0];\n'\
2584	' for (var i = 0; i < dev.length; i++) {\n'\	3617	' for (var i = 0; i < dev.length; i++) {\n'\
@@ -2634,6 +3667,7 @@ def addScriptCode(hf, testruns): · 49 unmodified lines
2634	' var cglist = document.getElementById("callgraphs");\n'\	3667	' var cglist = document.getElementById("callgraphs");\n'\
2635	' if(!cglist) return;\n'\	3668	' if(!cglist) return;\n'\
2636	' var cg = cglist.getElementsByClassName("atop");\n'\	3669	' var cg = cglist.getElementsByClassName("atop");\n'\
		3670	' if(cg.length < 10) return;\n'\
2637	' for (var i = 0; i < cg.length; i++) {\n'\	3671	' for (var i = 0; i < cg.length; i++) {\n'\
2638	' if(idlist.indexOf(cg[i].id) >= 0) {\n'\	3672	' if(idlist.indexOf(cg[i].id) >= 0) {\n'\
2639	' cg[i].style.display = "block";\n'\	3673	' cg[i].style.display = "block";\n'\
@@ -2658,15 +3692,32 @@ def addScriptCode(hf, testruns): · 18 unmodified lines
2658	' dt = devtable[1];\n'\	3692	' dt = devtable[1];\n'\
2659	' win.document.write(html+dt);\n'\	3693	' win.document.write(html+dt);\n'\
2660	' }\n'\	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	' window.addEventListener("load", function () {\n'\	3706	' window.addEventListener("load", function () {\n'\
2662	' var dmesg = document.getElementById("dmesg");\n'\	3707	' var dmesg = document.getElementById("dmesg");\n'\
2663	' dmesg.style.width = "100%"\n'\	3708	' dmesg.style.width = "100%"\n'\
2664	' document.getElementById("zoomin").onclick = zoomTimeline;\n'\	3709	' document.getElementById("zoomin").onclick = zoomTimeline;\n'\
2665	' document.getElementById("zoomout").onclick = zoomTimeline;\n'\	3710	' document.getElementById("zoomout").onclick = zoomTimeline;\n'\
2666	' document.getElementById("zoomdef").onclick = zoomTimeline;\n'\	3711	' document.getElementById("zoomdef").onclick = zoomTimeline;\n'\
2667	' var devlist = document.getElementsByClassName("devlist");\n'\	3712	' var list = document.getElementsByClassName("square");\n'\
2668	' for (var i = 0; i < devlist.length; i++)\n'\	3713	' for (var i = 0; i < list.length; i++)\n'\
2669	' devlist[i].onclick = devListWindow;\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	' var dev = dmesg.getElementsByClassName("thread");\n'\	3721	' var dev = dmesg.getElementsByClassName("thread");\n'\
2671	' for (var i = 0; i < dev.length; i++) {\n'\	3722	' for (var i = 0; i < dev.length; i++) {\n'\
2672	' dev[i].onclick = deviceDetail;\n'\	3723	' dev[i].onclick = deviceDetail;\n'\
@@ -2685,141 +3736,87 @@ def addScriptCode(hf, testruns): · 12 unmodified lines
2685	def executeSuspend():	3736	def executeSuspend():
2686	global sysvals	3737	global sysvals
2687		3738
2688	detectUSB(False)
2689	t0 = time.time()*1000	3739	t0 = time.time()*1000
2690	tp = sysvals.tpath	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	# execute however many s/r runs requested	3748	# execute however many s/r runs requested
2692	for count in range(1,sysvals.execcount+1):	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	# if this is test2 and there's a delay, start here	3750	# if this is test2 and there's a delay, start here
2707	if(count > 1 and sysvals.x2delay > 0):	3751	if(count > 1 and sysvals.x2delay > 0):
2708	tN = time.time()*1000	3752	tN = time.time()*1000
2709	while (tN - t0) < sysvals.x2delay:	3753	while (tN - t0) < sysvals.x2delay:
2710	tN = time.time()*1000	3754	tN = time.time()*1000
2711	time.sleep(0.001)	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	# initiate suspend	3756	# initiate suspend
2717	if(sysvals.usecallgraph or sysvals.usetraceevents):	3757	if(sysvals.usecallgraph or sysvals.usetraceevents):
2718	os.system('echo SUSPEND START > '+tp+'trace_marker')	3758	sysvals.fsetVal('SUSPEND START', 'trace_marker')
2719	if(sysvals.rtcwake):	3759	if sysvals.suspendmode == 'command':
2720	print('SUSPEND START')	3760	print('COMMAND START')
2721	print('will autoresume in %d seconds' % sysvals.rtcwaketime)	3761	if(sysvals.rtcwake):
2722	sysvals.rtcWakeAlarm()	3762	print('will issue an rtcwake in %d seconds' % sysvals.rtcwaketime)
		3763	sysvals.rtcWakeAlarmOn()
		3764	os.system(sysvals.testcommand)
2723	else:	3765	else:
2724	print('SUSPEND START (press a key to resume)')	3766	if(sysvals.rtcwake):
2725	pf = open(sysvals.powerfile, 'w')	3767	print('SUSPEND START')
2726	pf.write(sysvals.suspendmode)	3768	print('will autoresume in %d seconds' % sysvals.rtcwaketime)
2727	# execution will pause here	3769	sysvals.rtcWakeAlarmOn()
2728	pf.close()	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	t0 = time.time()*1000	3779	t0 = time.time()*1000
		3780	if(sysvals.rtcwake):
		3781	sysvals.rtcWakeAlarmOff()
2730	# return from suspend	3782	# return from suspend
2731	print('RESUME COMPLETE')	3783	print('RESUME COMPLETE')
2732	if(sysvals.usecallgraph or sysvals.usetraceevents):	3784	if(sysvals.usecallgraph or sysvals.usetraceevents):
2733	os.system('echo RESUME COMPLETE > '+tp+'trace_marker')	3785	sysvals.fsetVal('RESUME COMPLETE', 'trace_marker')
2734	# see if there's firmware timing data to be had	3786	if(sysvals.suspendmode == 'mem'):
2735	t = sysvals.postresumetime	3787	fwdata.append(getFPDT(False))
2736	if(t > 0):	3788	# look for post resume events after the last test run
2737	print('Waiting %d seconds for POST-RESUME trace events...' % t)	3789	t = sysvals.postresumetime
2738	time.sleep(t)	3790	if(t > 0):
2739	# stop ftrace	3791	print('Waiting %d seconds for POST-RESUME trace events...' % t)
2740	if(sysvals.usecallgraph or sysvals.usetraceevents):	3792	time.sleep(t)
2741	os.system('echo 0 > '+tp+'tracing_on')	3793	# stop ftrace
2742	print('CAPTURING TRACE')	3794	if(sysvals.usecallgraph or sysvals.usetraceevents):
2743	writeDatafileHeader(sysvals.ftracefile)	3795	sysvals.fsetVal('0', 'tracing_on')
2744	os.system('cat '+tp+'trace >> '+sysvals.ftracefile)	3796	print('CAPTURING TRACE')
2745	os.system('echo "" > '+tp+'trace')	3797	writeDatafileHeader(sysvals.ftracefile, fwdata)
2746	# grab a copy of the dmesg output	3798	os.system('cat '+tp+'trace >> '+sysvals.ftracefile)
2747	print('CAPTURING DMESG')	3799	sysvals.fsetVal('', 'trace')
2748	writeDatafileHeader(sysvals.dmesgfile)	3800	devProps()
2749	os.system('dmesg -c >> '+sysvals.dmesgfile)	3801	# grab a copy of the dmesg output
2750		3802	print('CAPTURING DMESG')
2751	def writeDatafileHeader(filename):	3803	writeDatafileHeader(sysvals.dmesgfile, fwdata)
		3804	sysvals.getdmesg()
		3805
		3806	def writeDatafileHeader(filename, fwdata):
2752	global sysvals	3807	global sysvals
2753		3808
2754	fw = getFPDT(False)
2755	prt = sysvals.postresumetime	3809	prt = sysvals.postresumetime
2756	fp = open(filename, 'a')	3810	fp = open(filename, 'a')
2757	fp.write(sysvals.teststamp+'\n')	3811	fp.write(sysvals.teststamp+'\n')
2758	if(fw):	3812	if(sysvals.suspendmode == 'mem'):
2759	fp.write('# fwsuspend %u fwresume %u\n' % (fw[0], fw[1]))	3813	for fw in fwdata:
		3814	if(fw):
		3815	fp.write('# fwsuspend %u fwresume %u\n' % (fw[0], fw[1]))
2760	if(prt > 0):	3816	if(prt > 0):
2761	fp.write('# post resume time %u\n' % prt)	3817	fp.write('# post resume time %u\n' % prt)
2762	fp.close()	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	# Function: setUSBDevicesAuto	3820	# Function: setUSBDevicesAuto
2824	# Description:	3821	# Description:
2825	# Set the autosuspend control parameter of all USB devices to auto	3822	# Set the autosuspend control parameter of all USB devices to auto
@@ -2829,7 +3826,7 @@ def executeAndroidSuspend(): · 3 unmodified lines
2829	def setUSBDevicesAuto():	3826	def setUSBDevicesAuto():
2830	global sysvals	3827	global sysvals
2831		3828
2832	rootCheck()	3829	rootCheck(True)
2833	for dirname, dirnames, filenames in os.walk('/sys/devices'):	3830	for dirname, dirnames, filenames in os.walk('/sys/devices'):
2834	if(re.match('./usb[0-9].*', dirname) and	3831	if(re.match('./usb[0-9].*', dirname) and
2835	'idVendor' in filenames and 'idProduct' in filenames):	3832	'idVendor' in filenames and 'idProduct' in filenames):
@@ -2874,9 +3871,7 @@ def ms2nice(val): · 38 unmodified lines
2874	# Description:	3871	# Description:
2875	# Detect all the USB hosts and devices currently connected and add	3872	# Detect all the USB hosts and devices currently connected and add
2876	# a list of USB device names to sysvals for better timeline readability	3873	# a list of USB device names to sysvals for better timeline readability
2877	# Arguments:	3874	def detectUSB():
2878	# output: True to output the info to stdout, False otherwise
2879	def detectUSB(output):
2880	global sysvals	3875	global sysvals
2881		3876
2882	field = {'idVendor':'', 'idProduct':'', 'product':'', 'speed':''}	3877	field = {'idVendor':'', 'idProduct':'', 'product':'', 'speed':''}
@@ -2887,18 +3882,18 @@ def detectUSB(output): · 4 unmodified lines
2887	'runtime_suspended_time':'',	3882	'runtime_suspended_time':'',
2888	'active_duration':'',	3883	'active_duration':'',
2889	'connected_duration':''}	3884	'connected_duration':''}
2890	if(output):	3885
2891	print('LEGEND')	3886	print('LEGEND')
2892	print('---------------------------------------------------------------------------------------------')	3887	print('---------------------------------------------------------------------------------------------')
2893	print(' A = async/sync PM queue Y/N D = autosuspend delay (seconds)')	3888	print(' A = async/sync PM queue Y/N D = autosuspend delay (seconds)')
2894	print(' S = autosuspend Y/N rACTIVE = runtime active (min/sec)')	3889	print(' S = autosuspend Y/N rACTIVE = runtime active (min/sec)')
2895	print(' P = persist across suspend Y/N rSUSPEN = runtime suspend (min/sec)')	3890	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)')	3891	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)')	3892	print(' R = runtime status active/suspended Y/N CONNECT = connected duration (min/sec)')
2898	print(' U = runtime usage count')	3893	print(' U = runtime usage count')
2899	print('---------------------------------------------------------------------------------------------')	3894	print('---------------------------------------------------------------------------------------------')
2900	print(' NAME ID DESCRIPTION SPEED A S P E R U D rACTIVE rSUSPEN ACTIVE CONNECT')	3895	print(' NAME ID DESCRIPTION SPEED A S P E R U D rACTIVE rSUSPEN ACTIVE CONNECT')
2901	print('---------------------------------------------------------------------------------------------')	3896	print('---------------------------------------------------------------------------------------------')
2902		3897
2903	for dirname, dirnames, filenames in os.walk('/sys/devices'):	3898	for dirname, dirnames, filenames in os.walk('/sys/devices'):
2904	if(re.match('./usb[0-9].*', dirname) and	3899	if(re.match('./usb[0-9].*', dirname) and
@@ -2907,35 +3902,149 @@ def detectUSB(output): · 2 unmodified lines
2907	field[i] = os.popen('cat %s/%s 2>/dev/null' % \	3902	field[i] = os.popen('cat %s/%s 2>/dev/null' % \
2908	(dirname, i)).read().replace('\n', '')	3903	(dirname, i)).read().replace('\n', '')
2909	name = dirname.split('/')[-1]	3904	name = dirname.split('/')[-1]
2910	if(len(field['product']) > 0):	3905	for i in power:
2911	sysvals.altdevname[name] = \	3906	power[i] = os.popen('cat %s/power/%s 2>/dev/null' % \
2912	'%s [%s]' % (field['product'], name)	3907	(dirname, i)).read().replace('\n', '')
		3908	if(re.match('usb[0-9]*', name)):
		3909	first = '%-8s' % name
2913	else:	3910	else:
2914	sysvals.altdevname[name] = \	3911	first = '%8s' % name
2915	'%s:%s [%s]' % (field['idVendor'], \	3912	print('%s [%s:%s] %-20s %-4s %1s %1s %1s %1s %1s %1s %1s %s %s %s %s' % \
2916	field['idProduct'], name)	3913	(first, field['idVendor'], field['idProduct'], \
2917	if(output):	3914	field['product'][0:20], field['speed'], \
2918	for i in power:	3915	yesno(power['async']), \
2919	power[i] = os.popen('cat %s/power/%s 2>/dev/null' % \	3916	yesno(power['control']), \
2920	(dirname, i)).read().replace('\n', '')	3917	yesno(power['persist']), \
2921	if(re.match('usb[0-9]*', name)):	3918	yesno(power['runtime_enabled']), \
2922	first = '%-8s' % name	3919	yesno(power['runtime_status']), \
2923	else:	3920	power['runtime_usage'], \
2924	first = '%8s' % name	3921	power['autosuspend'], \
2925	print('%s [%s:%s] %-20s %-4s %1s %1s %1s %1s %1s %1s %1s %s %s %s %s' % \	3922	ms2nice(power['runtime_active_time']), \
2926	(first, field['idVendor'], field['idProduct'], \	3923	ms2nice(power['runtime_suspended_time']), \
2927	field['product'][0:20], field['speed'], \	3924	ms2nice(power['active_duration']), \
2928	yesno(power['async']), \	3925	ms2nice(power['connected_duration'])))
2929	yesno(power['control']), \	3926
2930	yesno(power['persist']), \	3927	# Function: devProps
2931	yesno(power['runtime_enabled']), \	3928	# Description:
2932	yesno(power['runtime_status']), \	3929	# Retrieve a list of properties for all devices in the trace log
2933	power['runtime_usage'], \	3930	def devProps(data=0):
2934	power['autosuspend'], \	3931	global sysvals
2935	ms2nice(power['runtime_active_time']), \	3932	props = dict()
2936	ms2nice(power['runtime_suspended_time']), \	3933
2937	ms2nice(power['active_duration']), \	3934	if data:
2938	ms2nice(power['connected_duration'])))	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	# Function: getModes	4049	# Function: getModes
2941	# Description:	4050	# Description:
@@ -2945,15 +4054,10 @@ def detectUSB(output): · 3 unmodified lines
2945	def getModes():	4054	def getModes():
2946	global sysvals	4055	global sysvals
2947	modes = ''	4056	modes = ''
2948	if(not sysvals.android):	4057	if(os.path.exists(sysvals.powerfile)):
2949	if(os.path.exists(sysvals.powerfile)):	4058	fp = open(sysvals.powerfile, 'r')
2950	fp = open(sysvals.powerfile, 'r')	4059	modes = string.split(fp.read())
2951	modes = string.split(fp.read())	4060	fp.close()
2952	fp.close()
2953	else:
2954	line = os.popen(sysvals.adb+' shell cat '+\
2955	sysvals.powerfile).read().strip()
2956	modes = string.split(line)
2957	return modes	4061	return modes
2958		4062
2959	# Function: getFPDT	4063	# Function: getFPDT
@@ -2971,22 +4075,22 @@ def getFPDT(output): · 11 unmodified lines
2971	prectype[0] = 'Basic S3 Resume Performance Record'	4075	prectype[0] = 'Basic S3 Resume Performance Record'
2972	prectype[1] = 'Basic S3 Suspend Performance Record'	4076	prectype[1] = 'Basic S3 Suspend Performance Record'
2973		4077
2974	rootCheck()	4078	rootCheck(True)
2975	if(not os.path.exists(sysvals.fpdtpath)):	4079	if(not os.path.exists(sysvals.fpdtpath)):
2976	if(output):	4080	if(output):
2977	doError('file doesnt exist: %s' % sysvals.fpdtpath, False)	4081	doError('file does not exist: %s' % sysvals.fpdtpath, False)
2978	return False	4082	return False
2979	if(not os.access(sysvals.fpdtpath, os.R_OK)):	4083	if(not os.access(sysvals.fpdtpath, os.R_OK)):
2980	if(output):	4084	if(output):
2981	doError('file isnt readable: %s' % sysvals.fpdtpath, False)	4085	doError('file is not readable: %s' % sysvals.fpdtpath, False)
2982	return False	4086	return False
2983	if(not os.path.exists(sysvals.mempath)):	4087	if(not os.path.exists(sysvals.mempath)):
2984	if(output):	4088	if(output):
2985	doError('file doesnt exist: %s' % sysvals.mempath, False)	4089	doError('file does not exist: %s' % sysvals.mempath, False)
2986	return False	4090	return False
2987	if(not os.access(sysvals.mempath, os.R_OK)):	4091	if(not os.access(sysvals.mempath, os.R_OK)):
2988	if(output):	4092	if(output):
2989	doError('file isnt readable: %s' % sysvals.mempath, False)	4093	doError('file is not readable: %s' % sysvals.mempath, False)
2990	return False	4094	return False
2991		4095
2992	fp = open(sysvals.fpdtpath, 'rb')	4096	fp = open(sysvals.fpdtpath, 'rb')
@@ -3027,15 +4131,19 @@ def getFPDT(output): · 34 unmodified lines
3027	while(i < len(records)):	4131	while(i < len(records)):
3028	header = struct.unpack('HBB', records[i:i+4])	4132	header = struct.unpack('HBB', records[i:i+4])
3029	if(header[0] not in rectype):	4133	if(header[0] not in rectype):
		4134	i += header[1]
3030	continue	4135	continue
3031	if(header[1] != 16):	4136	if(header[1] != 16):
		4137	i += header[1]
3032	continue	4138	continue
3033	addr = struct.unpack('Q', records[i+8:i+16])[0]	4139	addr = struct.unpack('Q', records[i+8:i+16])[0]
3034	try:	4140	try:
3035	fp.seek(addr)	4141	fp.seek(addr)
3036	first = fp.read(8)	4142	first = fp.read(8)
3037	except:	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	rechead = struct.unpack('4sI', first)	4147	rechead = struct.unpack('4sI', first)
3040	recdata = fp.read(rechead[1]-8)	4148	recdata = fp.read(rechead[1]-8)
3041	if(rechead[0] == 'FBPT'):	4149	if(rechead[0] == 'FBPT'):
@@ -3090,89 +4198,60 @@ def getFPDT(output): · 48 unmodified lines
3090	# print the results to the terminal	4198	# print the results to the terminal
3091	# Output:	4199	# Output:
3092	# True if the test will work, False if not	4200	# True if the test will work, False if not
3093	def statusCheck():	4201	def statusCheck(probecheck=False):
3094	global sysvals	4202	global sysvals
3095	status = True	4203	status = True
3096		4204
3097	if(sysvals.android):	4205	print('Checking this system (%s)...' % platform.node())
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
3112		4206
3113	# check we have root access	4207	# check we have root access
3114	res = 'NO (No features of this tool will work!)'	4208	res = sysvals.colorText('NO (No features of this tool will work!)')
3115	if(sysvals.android):	4209	if(rootCheck(False)):
3116	out = os.popen(sysvals.adb+' shell id').read().strip()	4210	res = 'YES'
3117	if('root' in out):
3118	res = 'YES'
3119	else:
3120	if(os.environ['USER'] == 'root'):
3121	res = 'YES'
3122	print(' have root access: %s' % res)	4211	print(' have root access: %s' % res)
3123	if(res != 'YES'):	4212	if(res != 'YES'):
3124	if(sysvals.android):	4213	print(' Try running this script with sudo')
3125	print(' Try running "adb root" to restart the daemon as root')
3126	else:
3127	print(' Try running this script with sudo')
3128	return False	4214	return False
3129		4215
3130	# check sysfs is mounted	4216	# check sysfs is mounted
3131	res = 'NO (No features of this tool will work!)'	4217	res = sysvals.colorText('NO (No features of this tool will work!)')
3132	if(sysvals.android):	4218	if(os.path.exists(sysvals.powerfile)):
3133	out = os.popen(sysvals.adb+' shell ls '+\	4219	res = 'YES'
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'
3140	print(' is sysfs mounted: %s' % res)	4220	print(' is sysfs mounted: %s' % res)
3141	if(res != 'YES'):	4221	if(res != 'YES'):
3142	return False	4222	return False
3143		4223
3144	# check target mode is a valid mode	4224	# check target mode is a valid mode
3145	res = 'NO'	4225	if sysvals.suspendmode != 'command':
3146	modes = getModes()	4226	res = sysvals.colorText('NO')
3147	if(sysvals.suspendmode in modes):	4227	modes = getModes()
3148	res = 'YES'	4228	if(sysvals.suspendmode in modes):
3149	else:	4229	res = 'YES'
3150	status = False	4230	else:
3151	print(' is "%s" a valid power mode: %s' % (sysvals.suspendmode, res))	4231	status = False
3152	if(res == 'NO'):	4232	print(' is "%s" a valid power mode: %s' % (sysvals.suspendmode, res))
3153	print(' valid power modes are: %s' % modes)	4233	if(res == 'NO'):
3154	print(' please choose one with -m')	4234	print(' valid power modes are: %s' % modes)
3155		4235	print(' please choose one with -m')
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)
3166		4236
3167	# check if ftrace is available	4237	# check if ftrace is available
3168	res = 'NO'	4238	res = sysvals.colorText('NO')
3169	ftgood = verifyFtrace()	4239	ftgood = sysvals.verifyFtrace()
3170	if(ftgood):	4240	if(ftgood):
3171	res = 'YES'	4241	res = 'YES'
3172	elif(sysvals.usecallgraph):	4242	elif(sysvals.usecallgraph):
3173	status = False	4243	status = False
3174	print(' is ftrace supported: %s' % res)	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	# what data source are we using	4255	# what data source are we using
3177	res = 'DMESG'	4256	res = 'DMESG'
3178	if(ftgood):	4257	if(ftgood):
@@ -3180,14 +4259,8 @@ def statusCheck(): · 1 unmodified line
3180	sysvals.usetraceevents = False	4259	sysvals.usetraceevents = False
3181	for e in sysvals.traceevents:	4260	for e in sysvals.traceevents:
3182	check = False	4261	check = False
3183	if(sysvals.android):	4262	if(os.path.exists(sysvals.epath+e)):
3184	out = os.popen(sysvals.adb+' shell ls -d '+\	4263	check = True
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
3191	if(not check):	4264	if(not check):
3192	sysvals.usetraceeventsonly = False	4265	sysvals.usetraceeventsonly = False
3193	if(e == 'suspend_resume' and check):	4266	if(e == 'suspend_resume' and check):
@@ -3199,13 +4272,48 @@ def statusCheck(): · 5 unmodified lines
3199	print(' timeline data source: %s' % res)	4272	print(' timeline data source: %s' % res)
3200		4273
3201	# check if rtcwake	4274	# check if rtcwake
3202	res = 'NO'	4275	res = sysvals.colorText('NO')
3203	if(sysvals.rtcpath != ''):	4276	if(sysvals.rtcpath != ''):
3204	res = 'YES'	4277	res = 'YES'
3205	elif(sysvals.rtcwake):	4278	elif(sysvals.rtcwake):
3206	status = False	4279	status = False
3207	print(' is rtcwake supported: %s' % res)	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	return status	4317	return status
3210		4318
3211	# Function: doError	4319	# Function: doError
@@ -3226,7 +4334,7 @@ def doError(msg, help): · 14 unmodified lines
3226	# Arguments:	4334	# Arguments:
3227	# msg: the warning message to print	4335	# msg: the warning message to print
3228	# file: If not empty, a filename to request be sent to the owner for debug	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	print('/* %s */') % msg	4338	print('/* %s */') % msg
3231	if(file):	4339	if(file):
3232	print('/* For a fix, please send this'+\	4340	print('/* For a fix, please send this'+\
@@ -3235,18 +4343,25 @@ def doWarning(msg, file): · 2 unmodified lines
3235	# Function: rootCheck	4343	# Function: rootCheck
3236	# Description:	4344	# Description:
3237	# quick check to see if we have root access	4345	# quick check to see if we have root access
3238	def rootCheck():	4346	def rootCheck(fatal):
3239	if(os.environ['USER'] != 'root'):	4347	global sysvals
3240	doError('This script must be run as root', False)	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	# Function: getArgInt	4354	# Function: getArgInt
3243	# Description:	4355	# Description:
3244	# pull out an integer argument from the command line with checks	4356	# pull out an integer argument from the command line with checks
3245	def getArgInt(name, args, min, max):	4357	def getArgInt(name, args, min, max, main=True):
3246	try:	4358	if main:
3247	arg = args.next()	4359	try:
3248	except:	4360	arg = args.next()
3249	doError(name+': no argument supplied', True)	4361	except:
		4362	doError(name+': no argument supplied', True)
		4363	else:
		4364	arg = args
3250	try:	4365	try:
3251	val = int(arg)	4366	val = int(arg)
3252	except:	4367	except:
@@ -3255,6 +4370,25 @@ def getArgInt(name, args, min, max): · 2 unmodified lines
3255	doError(name+': value should be between %d and %d' % (min, max), True)	4370	doError(name+': value should be between %d and %d' % (min, max), True)
3256	return val	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	# Function: rerunTest	4392	# Function: rerunTest
3259	# Description:	4393	# Description:
3260	# generate an output from an existing set of ftrace/dmesg logs	4394	# generate an output from an existing set of ftrace/dmesg logs
@@ -3282,15 +4416,12 @@ def rerunTest(): · 21 unmodified lines
3282	# Function: runTest	4416	# Function: runTest
3283	# Description:	4417	# Description:
3284	# execute a suspend/resume, gather the logs, and generate the output	4418	# execute a suspend/resume, gather the logs, and generate the output
3285	def runTest(subdir):	4419	def runTest(subdir, testpath=''):
3286	global sysvals	4420	global sysvals
3287		4421
3288	# prepare for the test	4422	# prepare for the test
3289	if(not sysvals.android):	4423	sysvals.initFtrace()
3290	initFtrace()	4424	sysvals.initTestOutput(subdir, testpath)
3291	else:
3292	initFtraceAndroid()
3293	sysvals.initTestOutput(subdir)
3294		4425
3295	vprint('Output files:\n %s' % sysvals.dmesgfile)	4426	vprint('Output files:\n %s' % sysvals.dmesgfile)
3296	if(sysvals.usecallgraph or	4427	if(sysvals.usecallgraph or
@@ -3300,10 +4431,8 @@ def runTest(subdir): · 3 unmodified lines
3300	vprint(' %s' % sysvals.htmlfile)	4431	vprint(' %s' % sysvals.htmlfile)
3301		4432
3302	# execute the test	4433	# execute the test
3303	if(not sysvals.android):	4434	executeSuspend()
3304	executeSuspend()	4435	sysvals.cleanupFtrace()
3305	else:
3306	executeAndroidSuspend()
3307		4436
3308	# analyze the data and create the html output	4437	# analyze the data and create the html output
3309	print('PROCESSING DATA')	4438	print('PROCESSING DATA')
@@ -3367,6 +4496,153 @@ def runSummary(subdir, output): · 57 unmodified lines
3367		4496
3368	createHTMLSummarySimple(testruns, subdir+'/summary.html')	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	# Function: printHelp	4646	# Function: printHelp
3371	# Description:	4647	# Description:
3372	# print out the help text	4648	# print out the help text
@@ -3375,7 +4651,7 @@ def printHelp(): · 2 unmodified lines
3375	modes = getModes()	4651	modes = getModes()
3376		4652
3377	print('')	4653	print('')
3378	print('AnalyzeSuspend v%.1f' % sysvals.version)	4654	print('AnalyzeSuspend v%s' % sysvals.version)
3379	print('Usage: sudo analyze_suspend.py <options>')	4655	print('Usage: sudo analyze_suspend.py <options>')
3380	print('')	4656	print('')
3381	print('Description:')	4657	print('Description:')
@@ -3396,27 +4672,38 @@ def printHelp(): · 14 unmodified lines
3396	print(' [general]')	4672	print(' [general]')
3397	print(' -h Print this help text')	4673	print(' -h Print this help text')
3398	print(' -v Print the current tool version')	4674	print(' -v Print the current tool version')
		4675	print(' -config file Pull arguments and config options from a file')
3399	print(' -verbose Print extra information during execution and analysis')	4676	print(' -verbose Print extra information during execution and analysis')
3400	print(' -status Test to see if the system is enabled to run this tool')	4677	print(' -status Test to see if the system is enabled to run this tool')
3401	print(' -modes List available suspend modes')	4678	print(' -modes List available suspend modes')
3402	print(' -m mode Mode to initiate for suspend %s (default: %s)') % (modes, sysvals.suspendmode)	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	print(' [advanced]')	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	print(' -f Use ftrace to create device callgraphs (default: disabled)')	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	print(' -x2 Run two suspend/resumes back to back (default: disabled)')	4700	print(' -x2 Run two suspend/resumes back to back (default: disabled)')
3408	print(' -x2delay t Minimum millisecond delay <t> between the two test runs (default: 0 ms)')	4701	print(' -x2delay t Minimum millisecond delay <t> between the two test runs (default: 0 ms)')
3409	print(' -postres t Time after resume completion to wait for post-resume events (default: 0 S)')	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	print(' [utilities]')	4703	print(' [utilities]')
3413	print(' -fpdt Print out the contents of the ACPI Firmware Performance Data Table')	4704	print(' -fpdt Print out the contents of the ACPI Firmware Performance Data Table')
3414	print(' -usbtopo Print out the current USB topology with power info')	4705	print(' -usbtopo Print out the current USB topology with power info')
3415	print(' -usbauto Enable autosuspend for all connected USB devices')	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	print(' [re-analyze data from previous runs]')	4707	print(' [re-analyze data from previous runs]')
3421	print(' -ftrace ftracefile Create HTML output using ftrace input')	4708	print(' -ftrace ftracefile Create HTML output using ftrace input')
3422	print(' -dmesg dmesgfile Create HTML output using dmesg (not needed for kernel >= 3.15)')	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	cmd = ''	4717	cmd = ''
3431	cmdarg = ''	4718	cmdarg = ''
3432	multitest = {'run': False, 'count': 0, 'delay': 0}	4719	multitest = {'run': False, 'count': 0, 'delay': 0}
		4720	simplecmds = ['-modes', '-fpdt', '-flist', '-flistall', '-usbtopo', '-usbauto', '-status']
3433	# loop through the command line arguments	4721	# loop through the command line arguments
3434	args = iter(sys.argv[1:])	4722	args = iter(sys.argv[1:])
3435	for arg in args:	4723	for arg in args:
@@ -3438,58 +4726,85 @@ if __name__ == '__main__': · 2 unmodified lines
3438	val = args.next()	4726	val = args.next()
3439	except:	4727	except:
3440	doError('No mode supplied', True)	4728	doError('No mode supplied', True)
		4729	if val == 'command' and not sysvals.testcommand:
		4730	doError('No command supplied for mode "command"', True)
3441	sysvals.suspendmode = val	4731	sysvals.suspendmode = val
3442	elif(arg == '-adb'):	4732	elif(arg in simplecmds):
3443	try:	4733	cmd = arg[1:]
3444	val = args.next()	4734	elif(arg == '-h'):
3445	except:	4735	printHelp()
3446	doError('No adb binary supplied', True)	4736	sys.exit()
3447	if(not os.path.exists(val)):	4737	elif(arg == '-v'):
3448	doError('file doesnt exist: %s' % val, False)	4738	print("Version %s" % sysvals.version)
3449	if(not os.access(val, os.X_OK)):	4739	sys.exit()
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
3459	elif(arg == '-x2'):	4740	elif(arg == '-x2'):
3460	if(sysvals.postresumetime > 0):
3461	doError('-x2 is not compatible with -postres', False)
3462	sysvals.execcount = 2	4741	sysvals.execcount = 2
		4742	if(sysvals.usecallgraph):
		4743	doError('-x2 is not compatible with -f', False)
3463	elif(arg == '-x2delay'):	4744	elif(arg == '-x2delay'):
3464	sysvals.x2delay = getArgInt('-x2delay', args, 0, 60000)	4745	sysvals.x2delay = getArgInt('-x2delay', args, 0, 60000)
3465	elif(arg == '-postres'):	4746	elif(arg == '-postres'):
3466	if(sysvals.execcount != 1):
3467	doError('-x2 is not compatible with -postres', False)
3468	sysvals.postresumetime = getArgInt('-postres', args, 0, 3600)	4747	sysvals.postresumetime = getArgInt('-postres', args, 0, 3600)
3469	elif(arg == '-f'):	4748	elif(arg == '-f'):
3470	sysvals.usecallgraph = True	4749	sysvals.usecallgraph = True
3471	elif(arg == '-modes'):	4750	if(sysvals.execcount > 1):
3472	cmd = 'modes'	4751	doError('-x2 is not compatible with -f', False)
3473	elif(arg == '-fpdt'):	4752	if(sysvals.usedevsrc):
3474	cmd = 'fpdt'	4753	doError('-dev is not compatible with -f', False)
3475	elif(arg == '-usbtopo'):	4754	elif(arg == '-addlogs'):
3476	cmd = 'usbtopo'	4755	sysvals.addlogs = True
3477	elif(arg == '-usbauto'):
3478	cmd = 'usbauto'
3479	elif(arg == '-status'):
3480	cmd = 'status'
3481	elif(arg == '-verbose'):	4756	elif(arg == '-verbose'):
3482	sysvals.verbose = True	4757	sysvals.verbose = True
3483	elif(arg == '-v'):	4758	elif(arg == '-dev'):
3484	print("Version %.1f" % sysvals.version)	4759	sysvals.usedevsrc = True
3485	sys.exit()	4760	if(sysvals.usecallgraph):
		4761	doError('-dev is not compatible with -f', False)
3486	elif(arg == '-rtcwake'):	4762	elif(arg == '-rtcwake'):
3487	sysvals.rtcwake = True	4763	sysvals.rtcwake = True
3488	sysvals.rtcwaketime = getArgInt('-rtcwake', args, 0, 3600)	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	elif(arg == '-multi'):	4782	elif(arg == '-multi'):
3490	multitest['run'] = True	4783	multitest['run'] = True
3491	multitest['count'] = getArgInt('-multi n (exec count)', args, 2, 1000000)	4784	multitest['count'] = getArgInt('-multi n (exec count)', args, 2, 1000000)
3492	multitest['delay'] = getArgInt('-multi d (delay between tests)', args, 0, 3600)	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	elif(arg == '-dmesg'):	4808	elif(arg == '-dmesg'):
3494	try:	4809	try:
3495	val = args.next()	4810	val = args.next()
@@ -3498,17 +4813,16 @@ if __name__ == '__main__': · 2 unmodified lines
3498	sysvals.notestrun = True	4813	sysvals.notestrun = True
3499	sysvals.dmesgfile = val	4814	sysvals.dmesgfile = val
3500	if(os.path.exists(sysvals.dmesgfile) == False):	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	elif(arg == '-ftrace'):	4817	elif(arg == '-ftrace'):
3503	try:	4818	try:
3504	val = args.next()	4819	val = args.next()
3505	except:	4820	except:
3506	doError('No ftrace file supplied', True)	4821	doError('No ftrace file supplied', True)
3507	sysvals.notestrun = True	4822	sysvals.notestrun = True
3508	sysvals.usecallgraph = True
3509	sysvals.ftracefile = val	4823	sysvals.ftracefile = val
3510	if(os.path.exists(sysvals.ftracefile) == False):	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	elif(arg == '-summary'):	4826	elif(arg == '-summary'):
3513	try:	4827	try:
3514	val = args.next()	4828	val = args.next()
@@ -3518,35 +4832,35 @@ if __name__ == '__main__': · 3 unmodified lines
3518	cmdarg = val	4832	cmdarg = val
3519	sysvals.notestrun = True	4833	sysvals.notestrun = True
3520	if(os.path.isdir(val) == False):	4834	if(os.path.isdir(val) == False):
3521	doError('%s isnt accesible' % val, False)	4835	doError('%s is not accesible' % val, False)
3522	elif(arg == '-filter'):	4836	elif(arg == '-filter'):
3523	try:	4837	try:
3524	val = args.next()	4838	val = args.next()
3525	except:	4839	except:
3526	doError('No devnames supplied', True)	4840	doError('No devnames supplied', True)
3527	sysvals.setDeviceFilter(val)	4841	sysvals.setDeviceFilter(val)
3528	elif(arg == '-h'):
3529	printHelp()
3530	sys.exit()
3531	else:	4842	else:
3532	doError('Invalid argument: '+arg, True)	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	# just run a utility command and exit	4849	# just run a utility command and exit
3535	if(cmd != ''):	4850	if(cmd != ''):
3536	if(cmd == 'status'):	4851	if(cmd == 'status'):
3537	statusCheck()	4852	statusCheck(True)
3538	elif(cmd == 'fpdt'):	4853	elif(cmd == 'fpdt'):
3539	if(sysvals.android):
3540	doError('cannot read FPDT on android device', False)
3541	getFPDT(True)	4854	getFPDT(True)
3542	elif(cmd == 'usbtopo'):	4855	elif(cmd == 'usbtopo'):
3543	if(sysvals.android):	4856	detectUSB()
3544	doError('cannot read USB topology '+\
3545	'on an android device', False)
3546	detectUSB(True)
3547	elif(cmd == 'modes'):	4857	elif(cmd == 'modes'):
3548	modes = getModes()	4858	modes = getModes()
3549	print modes	4859	print modes
		4860	elif(cmd == 'flist'):
		4861	sysvals.getFtraceFilterFunctions(True)
		4862	elif(cmd == 'flistall'):
		4863	sysvals.getFtraceFilterFunctions(False)
3550	elif(cmd == 'usbauto'):	4864	elif(cmd == 'usbauto'):
3551	setUSBDevicesAuto()	4865	setUSBDevicesAuto()
3552	elif(cmd == 'summary'):	4866	elif(cmd == 'summary'):
@@ -3554,15 +4868,6 @@ if __name__ == '__main__': · 1 unmodified line
3554	runSummary(cmdarg, True)	4868	runSummary(cmdarg, True)
3555	sys.exit()	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	# if instructed, re-analyze existing data files	4871	# if instructed, re-analyze existing data files
3567	if(sysvals.notestrun):	4872	if(sysvals.notestrun):
3568	rerunTest()	4873	rerunTest()
@@ -3574,18 +4879,20 @@ if __name__ == '__main__': · 5 unmodified lines
3574	sys.exit()	4879	sys.exit()
3575		4880
3576	if multitest['run']:	4881	if multitest['run']:
3577	# run multiple tests in a separte subdirectory	4882	# run multiple tests in a separate subdirectory
3578	s = 'x%d' % multitest['count']	4883	s = 'x%d' % multitest['count']
3579	subdir = datetime.now().strftime('suspend-'+s+'-%m%d%y-%H%M%S')	4884	if not sysvals.outdir:
3580	os.mkdir(subdir)	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	for i in range(multitest['count']):	4888	for i in range(multitest['count']):
3582	if(i != 0):	4889	if(i != 0):
3583	print('Waiting %d seconds...' % (multitest['delay']))	4890	print('Waiting %d seconds...' % (multitest['delay']))
3584	time.sleep(multitest['delay'])	4891	time.sleep(multitest['delay'])
3585	print('TEST (%d/%d) START' % (i+1, multitest['count']))	4892	print('TEST (%d/%d) START' % (i+1, multitest['count']))
3586	runTest(subdir)	4893	runTest(sysvals.outdir)
3587	print('TEST (%d/%d) COMPLETE' % (i+1, multitest['count']))	4894	print('TEST (%d/%d) COMPLETE' % (i+1, multitest['count']))
3588	runSummary(subdir, False)	4895	runSummary(sysvals.outdir, False)
3589	else:	4896	else:
3590	# run the test in the current directory	4897	# run the test in the current directory
3591	runTest(".")	4898	runTest('.', sysvals.outdir)