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