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