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