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