#!/usr/bin/python
  #
  # Tool for analyzing suspend/resume timing
  # Copyright (c) 2013, Intel Corporation.
  #
  # This program is free software; you can redistribute it and/or modify it
  # under the terms and conditions of the GNU General Public License,
  # version 2, as published by the Free Software Foundation.
  #
  # This program is distributed in the hope it will be useful, but WITHOUT
  # ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
  # FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License for
  # more details.
  #
  # You should have received a copy of the GNU General Public License along with
  # this program; if not, write to the Free Software Foundation, Inc.,
  # 51 Franklin St - Fifth Floor, Boston, MA 02110-1301 USA.
  #
  # Authors:
  #	 Todd Brandt <todd.e.brandt@linux.intel.com>
  #
  # Description:
  #	 This tool is designed to assist kernel and OS developers in optimizing
  #	 their linux stack's suspend/resume time. Using a kernel image built
  #	 with a few extra options enabled, the tool will execute a suspend and
  #	 will capture dmesg and ftrace data until resume is complete. This data
  #	 is transformed into a device timeline and a callgraph to give a quick
  #	 and detailed view of which devices and callbacks are taking the most
  #	 time in suspend/resume. The output is a single html file which can be
  #	 viewed in firefox or chrome.
  #
  #	 The following kernel build options are required:
  #		 CONFIG_PM_DEBUG=y
  #		 CONFIG_PM_SLEEP_DEBUG=y
  #		 CONFIG_FTRACE=y
  #		 CONFIG_FUNCTION_TRACER=y
  #		 CONFIG_FUNCTION_GRAPH_TRACER=y
  #
  #	 The following additional kernel parameters are required:
  #		 (e.g. in file /etc/default/grub)
  #		 GRUB_CMDLINE_LINUX_DEFAULT="... initcall_debug log_buf_len=16M ..."
  #
  
  import sys
  import time
  import os
  import string
  import re
  import array
  import platform
  import datetime
  import struct
  
  # -- classes --
  
  class SystemValues:
  	testdir = "."
  	tpath = "/sys/kernel/debug/tracing/"
  	mempath = "/dev/mem"
  	powerfile = "/sys/power/state"
  	suspendmode = "mem"
  	prefix = "test"
  	teststamp = ""
  	dmesgfile = ""
  	ftracefile = ""
  	htmlfile = ""
  	rtcwake = False
  	def setOutputFile(self):
  		if((self.htmlfile == "") and (self.dmesgfile != "")):
  			m = re.match(r"(?P<name>.*)_dmesg\.txt$", self.dmesgfile)
  			if(m):
  				self.htmlfile = m.group("name")+".html"
  		if((self.htmlfile == "") and (self.ftracefile != "")):
  			m = re.match(r"(?P<name>.*)_ftrace\.txt$", self.ftracefile)
  			if(m):
  				self.htmlfile = m.group("name")+".html"
  		if(self.htmlfile == ""):
  			self.htmlfile = "output.html"
  	def initTestOutput(self):
  		hostname = platform.node()
  		if(hostname != ""):
  			self.prefix = hostname
  		v = os.popen("cat /proc/version").read().strip()
  		kver = string.split(v)[2]
  		self.testdir = os.popen("date \"+suspend-%m%d%y-%H%M%S\"").read().strip()
  		self.teststamp = "# "+self.testdir+" "+self.prefix+" "+self.suspendmode+" "+kver
  		self.dmesgfile = self.testdir+"/"+self.prefix+"_"+self.suspendmode+"_dmesg.txt"
  		self.ftracefile = self.testdir+"/"+self.prefix+"_"+self.suspendmode+"_ftrace.txt"
  		self.htmlfile = self.testdir+"/"+self.prefix+"_"+self.suspendmode+".html"
  		os.mkdir(self.testdir)
  
  class Data:
  	altdevname = dict()
  	usedmesg = False
  	useftrace = False
  	notestrun = False
  	verbose = False
  	phases = []
  	dmesg = {} # root data structure
  	start = 0.0
  	end = 0.0
  	stamp = {'time': "", 'host': "", 'mode': ""}
  	id = 0
  	tSuspended = 0.0
  	fwValid = False
  	fwSuspend = 0
  	fwResume = 0
  	def initialize(self):
  		self.dmesg = { # dmesg log data
  			'suspend_general': {'list': dict(), 'start': -1.0, 'end': -1.0,
  								'row': 0, 'color': "#CCFFCC", 'order': 0},
  			  'suspend_early': {'list': dict(), 'start': -1.0, 'end': -1.0,
  								'row': 0, 'color': "green", 'order': 1},
  			  'suspend_noirq': {'list': dict(), 'start': -1.0, 'end': -1.0,
  								'row': 0, 'color': "#00FFFF", 'order': 2},
  				'suspend_cpu': {'list': dict(), 'start': -1.0, 'end': -1.0,
  								'row': 0, 'color': "blue", 'order': 3},
  				 'resume_cpu': {'list': dict(), 'start': -1.0, 'end': -1.0,
  								'row': 0, 'color': "red", 'order': 4},
  			   'resume_noirq': {'list': dict(), 'start': -1.0, 'end': -1.0,
  								'row': 0, 'color': "orange", 'order': 5},
  			   'resume_early': {'list': dict(), 'start': -1.0, 'end': -1.0,
  								'row': 0, 'color': "yellow", 'order': 6},
  			 'resume_general': {'list': dict(), 'start': -1.0, 'end': -1.0,
  								'row': 0, 'color': "#FFFFCC", 'order': 7}
  		}
  		self.phases = self.sortedPhases()
  	def normalizeTime(self):
  		tSus = tRes = self.tSuspended
  		if self.fwValid:
  			tSus -= -self.fwSuspend / 1000000000.0
  			tRes -= self.fwResume / 1000000000.0
  		self.tSuspended = 0.0
  		self.start -= tSus
  		self.end -= tRes
  		for phase in self.phases:
  			zero = tRes
  			if "suspend" in phase:
  				zero = tSus
  			p = self.dmesg[phase]
  			p['start'] -= zero
  			p['end'] -= zero
  			list = p['list']
  			for name in list:
  				d = list[name]
  				d['start'] -= zero
  				d['end'] -= zero
  				if('ftrace' in d):
  					cg = d['ftrace']
  					cg.start -= zero
  					cg.end -= zero
  					for line in cg.list:
  						line.time -= zero
  		if self.fwValid:
  			fws = -self.fwSuspend / 1000000000.0
  			fwr = self.fwResume / 1000000000.0
  			list = dict()
  			self.id += 1
  			devid = "dc%d" % self.id
  			list["firmware-suspend"] = \
  				{'start': fws, 'end': 0, 'pid': 0, 'par': "",
  				'length': -fws, 'row': 0, 'id': devid };
  			self.id += 1
  			devid = "dc%d" % self.id
  			list["firmware-resume"] = \
  				{'start': 0, 'end': fwr, 'pid': 0, 'par': "",
  				'length': fwr, 'row': 0, 'id': devid };
  			self.dmesg['BIOS'] = \
  				{'list': list, 'start': fws, 'end': fwr,
  				'row': 0, 'color': "purple", 'order': 4}
  			self.dmesg['resume_cpu']['order'] += 1
  			self.dmesg['resume_noirq']['order'] += 1
  			self.dmesg['resume_early']['order'] += 1
  			self.dmesg['resume_general']['order'] += 1
  			self.phases = self.sortedPhases()
  	def vprint(self, msg):
  		if(self.verbose):
  			print(msg)
  	def dmesgSortVal(self, phase):
  		return self.dmesg[phase]['order']
  	def sortedPhases(self):
  		return sorted(self.dmesg, key=self.dmesgSortVal)
  	def sortedDevices(self, phase):
  		list = self.dmesg[phase]['list']
  		slist = []
  		tmp = dict()
  		for devname in list:
  			dev = list[devname]
  			tmp[dev['start']] = devname
  		for t in sorted(tmp):
  			slist.append(tmp[t])
  		return slist
  	def fixupInitcalls(self, phase, end):
  		# if any calls never returned, clip them at system resume end
  		phaselist = self.dmesg[phase]['list']
  		for devname in phaselist:
  			dev = phaselist[devname]
  			if(dev['end'] < 0):
  				dev['end'] = end
  				self.vprint("%s (%s): callback didn't return" % (devname, phase))
  	def fixupInitcallsThatDidntReturn(self):
  		# if any calls never returned, clip them at system resume end
  		for phase in self.phases:
  			self.fixupInitcalls(phase, self.dmesg['resume_general']['end'])
  			if(phase == "resume_general"):
  				break
  	def newAction(self, phase, name, pid, parent, start, end):
  		self.id += 1
  		devid = "dc%d" % self.id
  		list = self.dmesg[phase]['list']
  		length = -1.0
  		if(start >= 0 and end >= 0):
  			length = end - start
  		list[name] = {'start': start, 'end': end, 'pid': pid, 'par': parent,
  					  'length': length, 'row': 0, 'id': devid }
  	def deviceIDs(self, devlist, phase):
  		idlist = []
  		for p in self.phases:
  			if(p[0] != phase[0]):
  				continue
  			list = data.dmesg[p]['list']
  			for devname in list:
  				if devname in devlist:
  					idlist.append(list[devname]['id'])
  		return idlist
  	def deviceParentID(self, devname, phase):
  		pdev = ""
  		pdevid = ""
  		for p in self.phases:
  			if(p[0] != phase[0]):
  				continue
  			list = data.dmesg[p]['list']
  			if devname in list:
  				pdev = list[devname]['par']
  		for p in self.phases:
  			if(p[0] != phase[0]):
  				continue
  			list = data.dmesg[p]['list']
  			if pdev in list:
  				return list[pdev]['id']
  		return pdev
  	def deviceChildrenIDs(self, devname, phase):
  		devlist = []
  		for p in self.phases:
  			if(p[0] != phase[0]):
  				continue
  			list = data.dmesg[p]['list']
  			for child in list:
  				if(list[child]['par'] == devname):
  					devlist.append(child)
  		return self.deviceIDs(devlist, phase)
  
  class FTraceLine:
  	time = 0.0
  	length = 0.0
  	fcall = False
  	freturn = False
  	fevent = False
  	depth = 0
  	name = ""
  	def __init__(self, t, m, d):
  		self.time = float(t)
  		# check to see if this is a trace event
  		em = re.match(r"^ *\/\* *(?P<msg>.*) \*\/ *$", m)
  		if(em):
  			self.name = em.group("msg")
  			self.fevent = True
  			return
  		# convert the duration to seconds
  		if(d):
  			self.length = float(d)/1000000
  		# the indentation determines the depth
  		match = re.match(r"^(?P<d> *)(?P<o>.*)$", m)
  		if(not match):
  			return
  		self.depth = self.getDepth(match.group('d'))
  		m = match.group('o')
  		# function return
  		if(m[0] == '}'):
  			self.freturn = True
  			if(len(m) > 1):
  				# includes comment with function name
  				match = re.match(r"^} *\/\* *(?P<n>.*) *\*\/$", m)
  				if(match):
  					self.name = match.group('n')
  		# function call
  		else:
  			self.fcall = True
  			# function call with children
  			if(m[-1] == '{'):
  				match = re.match(r"^(?P<n>.*) *\(.*", m)
  				if(match):
  					self.name = match.group('n')
  			# function call with no children (leaf)
  			elif(m[-1] == ';'):
  				self.freturn = True
  				match = re.match(r"^(?P<n>.*) *\(.*", m)
  				if(match):
  					self.name = match.group('n')
  			# something else (possibly a trace marker)
  			else:
  				self.name = m
  	def getDepth(self, str):
  		return len(str)/2
  
  class FTraceCallGraph:
  	start = -1.0
  	end = -1.0
  	list = []
  	invalid = False
  	depth = 0
  	def __init__(self):
  		self.start = -1.0
  		self.end = -1.0
  		self.list = []
  		self.depth = 0
  	def setDepth(self, line):
  		if(line.fcall and not line.freturn):
  			line.depth = self.depth
  			self.depth += 1
  		elif(line.freturn and not line.fcall):
  			self.depth -= 1
  			line.depth = self.depth
  		else:
  			line.depth = self.depth
  	def addLine(self, line, match):
  		if(not self.invalid):
  			self.setDepth(line)
  		if(line.depth == 0 and line.freturn):
  			self.end = line.time
  			self.list.append(line)
  			return True
  		if(self.invalid):
  			return False
  		if(len(self.list) >= 1000000 or self.depth < 0):
  		   first = self.list[0]
  		   self.list = []
  		   self.list.append(first)
  		   self.invalid = True
  		   id = "task %s cpu %s" % (match.group("pid"), match.group("cpu"))
  		   window = "(%f - %f)" % (self.start, line.time)
  		   data.vprint("Too much data for "+id+" "+window+", ignoring this callback")
  		   return False
  		self.list.append(line)
  		if(self.start < 0):
  			self.start = line.time
  		return False
  	def sanityCheck(self):
  		stack = dict()
  		cnt = 0
  		for l in self.list:
  			if(l.fcall and not l.freturn):
  				stack[l.depth] = l
  				cnt += 1
  			elif(l.freturn and not l.fcall):
  				if(not stack[l.depth]):
  					return False
  				stack[l.depth].length = l.length
  				stack[l.depth] = 0
  				l.length = 0
  				cnt -= 1
  		if(cnt == 0):
  			return True
  		return False
  	def debugPrint(self, filename):
  		if(filename == "stdout"):
  			print("[%f - %f]") % (self.start, self.end)
  			for l in self.list:
  				if(l.freturn and l.fcall):
  					print("%f (%02d): %s(); (%.3f us)" % (l.time, l.depth, l.name, l.length*1000000))
  				elif(l.freturn):
  					print("%f (%02d): %s} (%.3f us)" % (l.time, l.depth, l.name, l.length*1000000))
  				else:
  					print("%f (%02d): %s() { (%.3f us)" % (l.time, l.depth, l.name, l.length*1000000))
  			print(" ")
  		else:
  			fp = open(filename, 'w')
  			print(filename)
  			for l in self.list:
  				if(l.freturn and l.fcall):
  					fp.write("%f (%02d): %s(); (%.3f us)
  " % (l.time, l.depth, l.name, l.length*1000000))
  				elif(l.freturn):
  					fp.write("%f (%02d): %s} (%.3f us)
  " % (l.time, l.depth, l.name, l.length*1000000))
  				else:
  					fp.write("%f (%02d): %s() { (%.3f us)
  " % (l.time, l.depth, l.name, l.length*1000000))
  			fp.close()
  
  class Timeline:
  	html = {}
  	scaleH = 0.0 # height of the timescale row as a percent of the timeline height
  	rowH = 0.0 # height of each row in percent of the timeline height
  	row_height_pixels = 30
  	maxrows = 0
  	height = 0
  	def __init__(self):
  		self.html = {
  			'timeline': "",
  			'legend': "",
  			'scale': ""
  		}
  	def setRows(self, rows):
  		self.maxrows = int(rows)
  		self.scaleH = 100.0/float(self.maxrows)
  		self.height = self.maxrows*self.row_height_pixels
  		r = float(self.maxrows - 1)
  		if(r < 1.0):
  			r = 1.0
  		self.rowH = (100.0 - self.scaleH)/r
  
  # -- global objects --
  
  sysvals = SystemValues()
  data = Data()
  
  # -- functions --
  
  # Function: initFtrace
  # Description:
  #	 Configure ftrace to capture a function trace during suspend/resume
  def initFtrace():
  	global sysvals
  
  	print("INITIALIZING FTRACE...")
  	# turn trace off
  	os.system("echo 0 > "+sysvals.tpath+"tracing_on")
  	# set the trace clock to global
  	os.system("echo global > "+sysvals.tpath+"trace_clock")
  	# set trace buffer to a huge value
  	os.system("echo nop > "+sysvals.tpath+"current_tracer")
  	os.system("echo 100000 > "+sysvals.tpath+"buffer_size_kb")
  	# clear the trace buffer
  	os.system("echo \"\" > "+sysvals.tpath+"trace")
  	# set trace type
  	os.system("echo function_graph > "+sysvals.tpath+"current_tracer")
  	os.system("echo \"\" > "+sysvals.tpath+"set_ftrace_filter")
  	# set trace format options
  	os.system("echo funcgraph-abstime > "+sysvals.tpath+"trace_options")
  	os.system("echo funcgraph-proc > "+sysvals.tpath+"trace_options")
  	# focus only on device suspend and resume
  	os.system("cat "+sysvals.tpath+"available_filter_functions | grep dpm_run_callback > "+sysvals.tpath+"set_graph_function")
  
  # Function: verifyFtrace
  # Description:
  #	 Check that ftrace is working on the system
  def verifyFtrace():
  	global sysvals
  	files = ["available_filter_functions", "buffer_size_kb",
  			 "current_tracer", "set_ftrace_filter",
  			 "trace", "trace_marker"]
  	for f in files:
  		if(os.path.exists(sysvals.tpath+f) == False):
  			return False
  	return True
  
  def parseStamp(line):
  	global data, sysvals
  	stampfmt = r"# suspend-(?P<m>[0-9]{2})(?P<d>[0-9]{2})(?P<y>[0-9]{2})-"+\
  				"(?P<H>[0-9]{2})(?P<M>[0-9]{2})(?P<S>[0-9]{2})"+\
  				" (?P<host>.*) (?P<mode>.*) (?P<kernel>.*)$"
  	m = re.match(stampfmt, line)
  	if(m):
  		dt = datetime.datetime(int(m.group("y"))+2000, int(m.group("m")),
  			int(m.group("d")), int(m.group("H")), int(m.group("M")),
  			int(m.group("S")))
  		data.stamp['time'] = dt.strftime("%B %d %Y, %I:%M:%S %p")
  		data.stamp['host'] = m.group("host")
  		data.stamp['mode'] = m.group("mode")
  		data.stamp['kernel'] = m.group("kernel")
  		sysvals.suspendmode = data.stamp['mode']
  
  # Function: analyzeTraceLog
  # Description:
  #	 Analyse an ftrace log output file generated from this app during
  #	 the execution phase. Create an "ftrace" structure in memory for
  #	 subsequent formatting in the html output file
  def analyzeTraceLog():
  	global sysvals, data
  
  	# the ftrace data is tied to the dmesg data
  	if(not data.usedmesg):
  		return
  
  	# read through the ftrace and parse the data
  	data.vprint("Analyzing the ftrace data...")
  	ftrace_line_fmt = r"^ *(?P<time>[0-9\.]*) *\| *(?P<cpu>[0-9]*)\)"+\
  					   " *(?P<proc>.*)-(?P<pid>[0-9]*) *\|"+\
  					   "[ +!]*(?P<dur>[0-9\.]*) .*\|  (?P<msg>.*)"
  	ftemp = dict()
  	inthepipe = False
  	tf = open(sysvals.ftracefile, 'r')
  	count = 0
  	for line in tf:
  		count = count + 1
  		# grab the time stamp if it's valid
  		if(count == 1):
  			parseStamp(line)
  			continue
  		# parse only valid lines
  		m = re.match(ftrace_line_fmt, line)
  		if(not m):
  			continue
  		m_time = m.group("time")
  		m_pid = m.group("pid")
  		m_msg = m.group("msg")
  		m_dur = m.group("dur")
  		if(m_time and m_pid and m_msg):
  			t = FTraceLine(m_time, m_msg, m_dur)
  			pid = int(m_pid)
  		else:
  			continue
  		# the line should be a call, return, or event
  		if(not t.fcall and not t.freturn and not t.fevent):
  			continue
  		# only parse the ftrace data during suspend/resume
  		if(not inthepipe):
  			# look for the suspend start marker
  			if(t.fevent):
  				if(t.name == "SUSPEND START"):
  					data.vprint("SUSPEND START %f %s:%d" % (t.time, sysvals.ftracefile, count))
  					inthepipe = True
  				continue
  		else:
  			# look for the resume end marker
  			if(t.fevent):
  				if(t.name == "RESUME COMPLETE"):
  					data.vprint("RESUME COMPLETE %f %s:%d" % (t.time, sysvals.ftracefile, count))
  					inthepipe = False
  					break
  				continue
  			# create a callgraph object for the data
  			if(pid not in ftemp):
  				ftemp[pid] = FTraceCallGraph()
  			# when the call is finished, see which device matches it
  			if(ftemp[pid].addLine(t, m)):
  				if(not ftemp[pid].sanityCheck()):
  					id = "task %s cpu %s" % (pid, m.group("cpu"))
  					data.vprint("Sanity check failed for "+id+", ignoring this callback")
  					continue
  				callstart = ftemp[pid].start
  				callend = ftemp[pid].end
  				for p in data.phases:
  					if(data.dmesg[p]['start'] <= callstart and callstart <= data.dmesg[p]['end']):
  						list = data.dmesg[p]['list']
  						for devname in list:
  							dev = list[devname]
  							if(pid == dev['pid'] and callstart <= dev['start'] and callend >= dev['end']):
  								data.vprint("%15s [%f - %f] %s(%d)" % (p, callstart, callend, devname, pid))
  								dev['ftrace'] = ftemp[pid]
  						break
  				ftemp[pid] = FTraceCallGraph()
  	tf.close()
  
  # Function: sortKernelLog
  # Description:
  #	 The dmesg output log sometimes comes with with lines that have
  #	 timestamps out of order. This could cause issues since a call
  #	 could accidentally end up in the wrong phase
  def sortKernelLog():
  	global sysvals, data
  	lf = open(sysvals.dmesgfile, 'r')
  	dmesglist = []
  	count = 0
  	for line in lf:
  		line = line.replace("\r
  ", "")
  		if(count == 0):
  			parseStamp(line)
  		elif(count == 1):
  			m = re.match(r"# fwsuspend (?P<s>[0-9]*) fwresume (?P<r>[0-9]*)$", line)
  			if(m):
  				data.fwSuspend = int(m.group("s"))
  				data.fwResume = int(m.group("r"))
  				if(data.fwSuspend > 0 or data.fwResume > 0):
  					data.fwValid = True
  		if(re.match(r".*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)", line)):
  			dmesglist.append(line)
  		count += 1
  	lf.close()
  	last = ""
  
  	# fix lines with the same time stamp and function with the call and return swapped
  	for line in dmesglist:
  		mc = re.match(r".*(\[ *)(?P<t>[0-9\.]*)(\]) calling  (?P<f>.*)\+ @ .*, parent: .*", line)
  		mr = re.match(r".*(\[ *)(?P<t>[0-9\.]*)(\]) call (?P<f>.*)\+ returned .* after (?P<dt>.*) usecs", last)
  		if(mc and mr and (mc.group("t") == mr.group("t")) and (mc.group("f") == mr.group("f"))):
  			i = dmesglist.index(last)
  			j = dmesglist.index(line)
  			dmesglist[i] = line
  			dmesglist[j] = last
  		last = line
  	return dmesglist
  
  # Function: analyzeKernelLog
  # Description:
  #	 Analyse a dmesg log output file generated from this app during
  #	 the execution phase. Create a set of device structures in memory
  #	 for subsequent formatting in the html output file
  def analyzeKernelLog():
  	global sysvals, data
  
  	print("PROCESSING DATA")
  	data.vprint("Analyzing the dmesg data...")
  	if(os.path.exists(sysvals.dmesgfile) == False):
  		print("ERROR: %s doesn't exist") % sysvals.dmesgfile
  		return False
  
  	lf = sortKernelLog()
  	phase = "suspend_runtime"
  
  	dm = {
  		'suspend_general': r"PM: Syncing filesystems.*",
  		  'suspend_early': r"PM: suspend of devices complete after.*",
  		  'suspend_noirq': r"PM: late suspend of devices complete after.*",
  		    'suspend_cpu': r"PM: noirq suspend of devices complete after.*",
  		     'resume_cpu': r"ACPI: Low-level resume complete.*",
  		   'resume_noirq': r"ACPI: Waking up from system sleep state.*",
  		   'resume_early': r"PM: noirq resume of devices complete after.*",
  		 'resume_general': r"PM: early resume of devices complete after.*",
  		'resume_complete': r".*Restarting tasks \.\.\..*",
  	}
  	if(sysvals.suspendmode == "standby"):
  		dm['resume_cpu'] = r"PM: Restoring platform NVS memory"
  	elif(sysvals.suspendmode == "disk"):
  		dm['suspend_early'] = r"PM: freeze of devices complete after.*"
  		dm['suspend_noirq'] = r"PM: late freeze of devices complete after.*"
  		dm['suspend_cpu'] = r"PM: noirq freeze of devices complete after.*"
  		dm['resume_cpu'] = r"PM: Restoring platform NVS memory"
  		dm['resume_early'] = r"PM: noirq restore of devices complete after.*"
  		dm['resume_general'] = r"PM: early restore of devices complete after.*"
  
  	action_start = 0.0
  	for line in lf:
  		# -- preprocessing --
  		# parse each dmesg line into the time and message
  		m = re.match(r".*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)", line)
  		if(m):
  			ktime = float(m.group("ktime"))
  			msg = m.group("msg")
  		else:
  			print line
  			continue
  
  		# -- phase changes --
  		# suspend_general start
  		if(re.match(dm['suspend_general'], msg)):
  			phase = "suspend_general"
  			data.dmesg[phase]['start'] = ktime
  			data.start = ktime
  			# action start: syncing filesystems
  			action_start = ktime
  		# suspend_early start
  		elif(re.match(dm['suspend_early'], msg)):
  			data.dmesg["suspend_general"]['end'] = ktime
  			phase = "suspend_early"
  			data.dmesg[phase]['start'] = ktime
  		# suspend_noirq start
  		elif(re.match(dm['suspend_noirq'], msg)):
  			data.dmesg["suspend_early"]['end'] = ktime
  			phase = "suspend_noirq"
  			data.dmesg[phase]['start'] = ktime
  		# suspend_cpu start
  		elif(re.match(dm['suspend_cpu'], msg)):
  			data.dmesg["suspend_noirq"]['end'] = ktime
  			phase = "suspend_cpu"
  			data.dmesg[phase]['start'] = ktime
  		# resume_cpu start
  		elif(re.match(dm['resume_cpu'], msg)):
  			data.tSuspended = ktime
  			data.dmesg["suspend_cpu"]['end'] = ktime
  			phase = "resume_cpu"
  			data.dmesg[phase]['start'] = ktime
  		# resume_noirq start
  		elif(re.match(dm['resume_noirq'], msg)):
  			data.dmesg["resume_cpu"]['end'] = ktime
  			phase = "resume_noirq"
  			data.dmesg[phase]['start'] = ktime
  			# action end: ACPI resume
  			data.newAction("resume_cpu", "ACPI", -1, "", action_start, ktime)
  		# resume_early start
  		elif(re.match(dm['resume_early'], msg)):
  			data.dmesg["resume_noirq"]['end'] = ktime
  			phase = "resume_early"
  			data.dmesg[phase]['start'] = ktime
  		# resume_general start
  		elif(re.match(dm['resume_general'], msg)):
  			data.dmesg["resume_early"]['end'] = ktime
  			phase = "resume_general"
  			data.dmesg[phase]['start'] = ktime
  		# resume complete start
  		elif(re.match(dm['resume_complete'], msg)):
  			data.dmesg["resume_general"]['end'] = ktime
  			data.end = ktime
  			phase = "resume_runtime"
  			break
  
  		# -- device callbacks --
  		if(phase in data.phases):
  			# device init call
  			if(re.match(r"calling  (?P<f>.*)\+ @ .*, parent: .*", msg)):
  				sm = re.match(r"calling  (?P<f>.*)\+ @ (?P<n>.*), parent: (?P<p>.*)", msg);
  				f = sm.group("f")
  				n = sm.group("n")
  				p = sm.group("p")
  				if(f and n and p):
  					data.newAction(phase, f, int(n), p, ktime, -1)
  			# device init return
  			elif(re.match(r"call (?P<f>.*)\+ returned .* after (?P<t>.*) usecs", msg)):
  				sm = re.match(r"call (?P<f>.*)\+ returned .* after (?P<t>.*) usecs(?P<a>.*)", msg);
  				f = sm.group("f")
  				t = sm.group("t")
  				list = data.dmesg[phase]['list']
  				if(f in list):
  					dev = list[f]
  					dev['length'] = int(t)
  					dev['end'] = ktime
  					data.vprint("%15s [%f - %f] %s(%d) %s" %
  						(phase, dev['start'], dev['end'], f, dev['pid'], dev['par']))
  
  		# -- phase specific actions --
  		if(phase == "suspend_general"):
  			if(re.match(r"PM: Preparing system for mem sleep.*", msg)):
  				data.newAction(phase, "filesystem-sync", -1, "", action_start, ktime)
  			elif(re.match(r"Freezing user space processes .*", msg)):
  				action_start = ktime
  			elif(re.match(r"Freezing remaining freezable tasks.*", msg)):
  				data.newAction(phase, "freeze-user-processes", -1, "", action_start, ktime)
  				action_start = ktime
  			elif(re.match(r"PM: Entering (?P<mode>[a-z,A-Z]*) sleep.*", msg)):
  				data.newAction(phase, "freeze-tasks", -1, "", action_start, ktime)
  		elif(phase == "suspend_cpu"):
  			m = re.match(r"smpboot: CPU (?P<cpu>[0-9]*) is now offline", msg)
  			if(m):
  				cpu = "CPU"+m.group("cpu")
  				data.newAction(phase, cpu, -1, "", action_start, ktime)
  				action_start = ktime
  			elif(re.match(r"ACPI: Preparing to enter system sleep state.*", msg)):
  				action_start = ktime
  			elif(re.match(r"Disabling non-boot CPUs .*", msg)):
  				data.newAction(phase, "ACPI", -1, "", action_start, ktime)
  				action_start = ktime
  		elif(phase == "resume_cpu"):
  			m = re.match(r"CPU(?P<cpu>[0-9]*) is up", msg)
  			if(m):
  				cpu = "CPU"+m.group("cpu")
  				data.newAction(phase, cpu, -1, "", action_start, ktime)
  				action_start = ktime
  			elif(re.match(r"Enabling non-boot CPUs .*", msg)):
  				action_start = ktime
  
  	# fill in any missing phases
  	lp = "suspend_general"
  	for p in data.phases:
  		if(p == "suspend_general"):
  			continue
  		if(data.dmesg[p]['start'] < 0):
  			data.dmesg[p]['start'] = data.dmesg[lp]['end']
  			if(p == "resume_cpu"):
  				data.tSuspended = data.dmesg[lp]['end']
  		if(data.dmesg[p]['end'] < 0):
  			data.dmesg[p]['end'] = data.dmesg[p]['start']
  		lp = p
  
  	data.fixupInitcallsThatDidntReturn()
  	return True
  
  # Function: setTimelineRows
  # Description:
  #	 Organize the device or thread lists into the smallest
  #	 number of rows possible, with no entry overlapping
  # Arguments:
  #	 list: the list to sort (dmesg or ftrace)
  #	 sortedkeys: sorted key list to use
  def setTimelineRows(list, sortedkeys):
  	global data
  
  	# clear all rows and set them to undefined
  	remaining = len(list)
  	rowdata = dict()
  	row = 0
  	for item in list:
  		list[item]['row'] = -1
  
  	# try to pack each row with as many ranges as possible
  	while(remaining > 0):
  		if(row not in rowdata):
  			rowdata[row] = []
  		for item in sortedkeys:
  			if(list[item]['row'] < 0):
  				s = list[item]['start']
  				e = list[item]['end']
  				valid = True
  				for ritem in rowdata[row]:
  					rs = ritem['start']
  					re = ritem['end']
  					if(not (((s <= rs) and (e <= rs)) or ((s >= re) and (e >= re)))):
  						valid = False
  						break
  				if(valid):
  					rowdata[row].append(list[item])
  					list[item]['row'] = row
  					remaining -= 1
  		row += 1
  	return row
  
  # Function: createTimeScale
  # Description:
  #	 Create timescale lines for the dmesg and ftrace timelines
  # Arguments:
  #	 t0: start time (suspend begin)
  #	 tMax: end time (resume end)
  #	 tSuspend: time when suspend occurs
  def createTimeScale(t0, tMax, tSuspended):
  	global data
  	timescale = "<div class=\"t\" style=\"right:{0}%\">{1}</div>
  "
  	output = '<div id="timescale">
  '
  
  	# set scale for timeline
  	tTotal = tMax - t0
  	tS = 0.1
  	if(tTotal <= 0):
  		return output
  	if(tTotal > 4):
  		tS = 1
  	if(tSuspended < 0):
  		for i in range(int(tTotal/tS)+1):
  			pos = "%0.3f" % (100 - ((float(i)*tS*100)/tTotal))
  			if(i > 0):
  				val = "%0.f" % (float(i)*tS*1000)
  			else:
  				val = ""
  			output += timescale.format(pos, val)
  	else:
  		tSuspend = tSuspended - t0
  		divTotal = int(tTotal/tS) + 1
  		divSuspend = int(tSuspend/tS)
  		s0 = (tSuspend - tS*divSuspend)*100/tTotal
  		for i in range(divTotal):
  			pos = "%0.3f" % (100 - ((float(i)*tS*100)/tTotal) - s0)
  			if((i == 0) and (s0 < 3)):
  				val = ""
  			elif(i == divSuspend):
  				val = "S/R"
  			else:
  				val = "%0.f" % (float(i-divSuspend)*tS*1000)
  			output += timescale.format(pos, val)
  	output += '</div>
  '
  	return output
  
  # Function: createHTML
  # Description:
  #	 Create the output html file.
  def createHTML():
  	global sysvals, data
  
  	data.normalizeTime()
  
  	# html function templates
  	headline_stamp = '<div class="stamp">{0} {1} {2} {3}</div>
  '
  	html_zoombox = '<center><button id="zoomin">ZOOM IN</button><button id="zoomout">ZOOM OUT</button><button id="zoomdef">ZOOM 1:1</button></center>
  <div id="dmesgzoombox" class="zoombox">
  '
  	html_timeline = '<div id="{0}" class="timeline" style="height:{1}px">
  '
  	html_device = '<div id="{0}" title="{1}" class="thread" style="left:{2}%;top:{3}%;height:{4}%;width:{5}%;">{6}</div>
  '
  	html_phase = '<div class="phase" style="left:{0}%;width:{1}%;top:{2}%;height:{3}%;background-color:{4}">{5}</div>
  '
  	html_legend = '<div class="square" style="left:{0}%;background-color:{1}">&nbsp;{2}</div>
  '
  	html_timetotal = '<table class="time1">
  <tr>'\
  		'<td class="gray">{2} Suspend Time: <b>{0} ms</b></td>'\
  		'<td class="gray">{2} Resume Time: <b>{1} ms</b></td>'\
  		'</tr>
  </table>
  '
  	html_timegroups = '<table class="time2">
  <tr>'\
  		'<td class="green">Kernel Suspend: {0} ms</td>'\
  		'<td class="purple">Firmware Suspend: {1} ms</td>'\
  		'<td class="purple">Firmware Resume: {2} ms</td>'\
  		'<td class="yellow">Kernel Resume: {3} ms</td>'\
  		'</tr>
  </table>
  '
  
  	# device timeline (dmesg)
  	if(data.usedmesg):
  		data.vprint("Creating Device Timeline...")
  		devtl = Timeline()
  
  		# Generate the header for this timeline
  		t0 = data.start
  		tMax = data.end
  		tTotal = tMax - t0
  		if(tTotal == 0):
  			print("ERROR: No timeline data")
  			sys.exit()
  		suspend_time = "%.0f"%(-data.start*1000)
  		resume_time = "%.0f"%(data.end*1000)
  		if data.fwValid:
  			devtl.html['timeline'] = html_timetotal.format(suspend_time, resume_time, "Total")
  			sktime = "%.3f"%((data.dmesg['suspend_cpu']['end'] - data.dmesg['suspend_general']['start'])*1000)
  			sftime = "%.3f"%(data.fwSuspend / 1000000.0)
  			rftime = "%.3f"%(data.fwResume / 1000000.0)
  			rktime = "%.3f"%((data.dmesg['resume_general']['end'] - data.dmesg['resume_cpu']['start'])*1000)
  			devtl.html['timeline'] += html_timegroups.format(sktime, sftime, rftime, rktime)
  		else:
  			devtl.html['timeline'] = html_timetotal.format(suspend_time, resume_time, "Kernel")
  
  		# determine the maximum number of rows we need to draw
  		timelinerows = 0
  		for phase in data.dmesg:
  			list = data.dmesg[phase]['list']
  			rows = setTimelineRows(list, list)
  			data.dmesg[phase]['row'] = rows
  			if(rows > timelinerows):
  				timelinerows = rows
  
  		# calculate the timeline height and create its bounding box
  		devtl.setRows(timelinerows + 1)
  		devtl.html['timeline'] += html_zoombox;
  		devtl.html['timeline'] += html_timeline.format("dmesg", devtl.height);
  
  		# draw the colored boxes for each of the phases
  		for b in data.dmesg:
  			phase = data.dmesg[b]
  			left = "%.3f" % (((phase['start']-data.start)*100)/tTotal)
  			width = "%.3f" % (((phase['end']-phase['start'])*100)/tTotal)
  			devtl.html['timeline'] += html_phase.format(left, width, "%.3f"%devtl.scaleH, "%.3f"%(100-devtl.scaleH), data.dmesg[b]['color'], "")
  
  		# draw the time scale, try to make the number of labels readable
  		devtl.html['scale'] = createTimeScale(t0, tMax, data.tSuspended)
  		devtl.html['timeline'] += devtl.html['scale']
  		for b in data.dmesg:
  			phaselist = data.dmesg[b]['list']
  			for d in phaselist:
  				name = d
  				if(d in data.altdevname):
  					name = data.altdevname[d]
  				dev = phaselist[d]
  				height = (100.0 - devtl.scaleH)/data.dmesg[b]['row']
  				top = "%.3f" % ((dev['row']*height) + devtl.scaleH)
  				left = "%.3f" % (((dev['start']-data.start)*100)/tTotal)
  				width = "%.3f" % (((dev['end']-dev['start'])*100)/tTotal)
  				len = " (%0.3f ms) " % ((dev['end']-dev['start'])*1000)
  				color = "rgba(204,204,204,0.5)"
  				devtl.html['timeline'] += html_device.format(dev['id'], name+len+b, left, top, "%.3f"%height, width, name)
  
  		# timeline is finished
  		devtl.html['timeline'] += "</div>
  </div>
  "
  
  		# draw a legend which describes the phases by color
  		devtl.html['legend'] = "<div class=\"legend\">
  "
  		pdelta = 100.0/data.phases.__len__()
  		pmargin = pdelta / 4.0
  		for phase in data.phases:
  			order = "%.2f" % ((data.dmesg[phase]['order'] * pdelta) + pmargin)
  			name = string.replace(phase, "_", " &nbsp;")
  			devtl.html['legend'] += html_legend.format(order, data.dmesg[phase]['color'], name)
  		devtl.html['legend'] += "</div>
  "
  
  	hf = open(sysvals.htmlfile, 'w')
  	thread_height = 0
  
  	# write the html header first (html head, css code, everything up to the start of body)
  	html_header = "<!DOCTYPE html>
  <html>
  <head>
  \
  	<meta http-equiv=\"content-type\" content=\"text/html; charset=UTF-8\">
  \
  	<title>AnalyzeSuspend</title>
  \
  	<style type='text/css'>
  \
  		body {overflow-y: scroll;}
  \
  		.stamp {width: 100%;text-align:center;background-color:gray;line-height:30px;color:white;font: 25px Arial;}
  \
  		.callgraph {margin-top: 30px;box-shadow: 5px 5px 20px black;}
  \
  		.callgraph article * {padding-left: 28px;}
  \
  		h1 {color:black;font: bold 30px Times;}
  \
  		table {width:100%;}
  \
  		.gray {background-color:rgba(80,80,80,0.1);}
  \
  		.green {background-color:rgba(204,255,204,0.4);}
  \
  		.purple {background-color:rgba(128,0,128,0.2);}
  \
  		.yellow {background-color:rgba(255,255,204,0.4);}
  \
  		.time1 {font: 22px Arial;border:1px solid;}
  \
  		.time2 {font: 15px Arial;border-bottom:1px solid;border-left:1px solid;border-right:1px solid;}
  \
  		td {text-align: center;}
  \
  		.tdhl {color: red;}
  \
  		.hide {display: none;}
  \
  		.pf {display: none;}
  \
  		.pf:checked + label {background: url(\'data:image/svg+xml;utf,<?xml version=\"1.0\" standalone=\"no\"?><svg xmlns=\"http://www.w3.org/2000/svg\" height=\"18\" width=\"18\" version=\"1.1\"><circle cx=\"9\" cy=\"9\" r=\"8\" stroke=\"black\" stroke-width=\"1\" fill=\"white\"/><rect x=\"4\" y=\"8\" width=\"10\" height=\"2\" style=\"fill:black;stroke-width:0\"/><rect x=\"8\" y=\"4\" width=\"2\" height=\"10\" style=\"fill:black;stroke-width:0\"/></svg>\') no-repeat left center;}
  \
  		.pf:not(:checked) ~ label {background: url(\'data:image/svg+xml;utf,<?xml version=\"1.0\" standalone=\"no\"?><svg xmlns=\"http://www.w3.org/2000/svg\" height=\"18\" width=\"18\" version=\"1.1\"><circle cx=\"9\" cy=\"9\" r=\"8\" stroke=\"black\" stroke-width=\"1\" fill=\"white\"/><rect x=\"4\" y=\"8\" width=\"10\" height=\"2\" style=\"fill:black;stroke-width:0\"/></svg>\') no-repeat left center;}
  \
  		.pf:checked ~ *:not(:nth-child(2)) {display: none;}
  \
  		.zoombox {position: relative; width: 100%; overflow-x: scroll;}
  \
  		.timeline {position: relative; font-size: 14px;cursor: pointer;width: 100%; overflow: hidden; background-color:#dddddd;}
  \
  		.thread {position: absolute; height: "+"%.3f"%thread_height+"%; overflow: hidden; line-height: 30px; border:1px solid;text-align:center;white-space:nowrap;background-color:rgba(204,204,204,0.5);}
  \
  		.thread:hover {background-color:white;border:1px solid red;z-index:10;}
  \
  		.phase {position: absolute;overflow: hidden;border:0px;text-align:center;}
  \
  		.t {position: absolute; top: 0%; height: 100%; border-right:1px solid black;}
  \
  		.legend {position: relative; width: 100%; height: 40px; text-align: center;margin-bottom:20px}
  \
  		.legend .square {position:absolute;top:10px; width: 0px;height: 20px;border:1px solid;padding-left:20px;}
  \
  		button {height:40px;width:200px;margin-bottom:20px;margin-top:20px;font-size:24px;}
  \
  	</style>
  </head>
  <body>
  "
  	hf.write(html_header)
  
  	# write the test title and general info header
  	if(data.stamp['time'] != ""):
  		hf.write(headline_stamp.format(data.stamp['host'],
  			data.stamp['kernel'], data.stamp['mode'], data.stamp['time']))
  
  	# write the dmesg data (device timeline)
  	if(data.usedmesg):
  		hf.write(devtl.html['timeline'])
  		hf.write(devtl.html['legend'])
  		hf.write('<div id="devicedetail"></div>
  ')
  		hf.write('<div id="devicetree"></div>
  ')
  
  	# write the ftrace data (callgraph)
  	if(data.useftrace):
  		hf.write('<section id="callgraphs" class="callgraph">
  ')
  		# write out the ftrace data converted to html
  		html_func_top = '<article id="{0}" class="atop" style="background-color:{1}">
  <input type="checkbox" class="pf" id="f{2}" checked/><label for="f{2}">{3} {4}</label>
  '
  		html_func_start = '<article>
  <input type="checkbox" class="pf" id="f{0}" checked/><label for="f{0}">{1} {2}</label>
  '
  		html_func_end = '</article>
  '
  		html_func_leaf = '<article>{0} {1}</article>
  '
  		num = 0
  		for p in data.phases:
  			list = data.dmesg[p]['list']
  			for devname in data.sortedDevices(p):
  				if('ftrace' not in list[devname]):
  					continue
  				name = devname
  				if(devname in data.altdevname):
  					name = data.altdevname[devname]
  				devid = list[devname]['id']
  				cg = list[devname]['ftrace']
  				flen = "(%.3f ms)" % ((cg.end - cg.start)*1000)
  				hf.write(html_func_top.format(devid, data.dmesg[p]['color'], num, name+" "+p, flen))
  				num += 1
  				for line in cg.list:
  					if(line.length < 0.000000001):
  						flen = ""
  					else:
  						flen = "(%.3f ms)" % (line.length*1000)
  					if(line.freturn and line.fcall):
  						hf.write(html_func_leaf.format(line.name, flen))
  					elif(line.freturn):
  						hf.write(html_func_end)
  					else:
  						hf.write(html_func_start.format(num, line.name, flen))
  						num += 1
  				hf.write(html_func_end)
  		hf.write("
  
      </section>
  ")
  	# write the footer and close
  	addScriptCode(hf)
  	hf.write("</body>
  </html>
  ")
  	hf.close()
  	return True
  
  def addScriptCode(hf):
  	global data
  
  	t0 = (data.start - data.tSuspended) * 1000
  	tMax = (data.end - data.tSuspended) * 1000
  	# create an array in javascript memory with the device details
  	detail = '	var bounds = [%f,%f];
  ' % (t0, tMax)
  	detail += '	var d = [];
  '
  	dfmt = '	d["%s"] = { n:"%s", p:"%s", c:[%s] };
  ';
  	for p in data.dmesg:
  		list = data.dmesg[p]['list']
  		for d in list:
  			parent = data.deviceParentID(d, p)
  			idlist = data.deviceChildrenIDs(d, p)
  			idstr = ""
  			for i in idlist:
  				if(idstr == ""):
  					idstr += '"'+i+'"'
  				else:
  					idstr += ', '+'"'+i+'"'
  			detail += dfmt % (list[d]['id'], d, parent, idstr)
  
  	# add the code which will manipulate the data in the browser
  	script_code = \
  	'<script type="text/javascript">
  '+detail+\
  	'	var filter = [];
  '\
  	'	var table = [];
  '\
  	'	function deviceParent(devid) {
  '\
  	'		var devlist = [];
  '\
  	'		if(filter.indexOf(devid) < 0) filter[filter.length] = devid;
  '\
  	'		if(d[devid].p in d)
  '\
  	'			devlist = deviceParent(d[devid].p);
  '\
  	'		else if(d[devid].p != "")
  '\
  	'			devlist = [d[devid].p];
  '\
  	'		devlist[devlist.length] = d[devid].n;
  '\
  	'		return devlist;
  '\
  	'	}
  '\
  	'	function deviceChildren(devid, column, row) {
  '\
  	'		if(!(devid in d)) return;
  '\
  	'		if(filter.indexOf(devid) < 0) filter[filter.length] = devid;
  '\
  	'		var cell = {name: d[devid].n, span: 1};
  '\
  	'		var span = 0;
  '\
  	'		if(column >= table.length) table[column] = [];
  '\
  	'		table[column][row] = cell;
  '\
  	'		for(var i = 0; i < d[devid].c.length; i++) {
  '\
  	'			var cid = d[devid].c[i];
  '\
  	'			span += deviceChildren(cid, column+1, row+span);
  '\
  	'		}
  '\
  	'		if(span == 0) span = 1;
  '\
  	'		table[column][row].span = span;
  '\
  	'		return span;
  '\
  	'	}
  '\
  	'	function deviceTree(devid, resume) {
  '\
  	'		var html = "<table border=1>";
  '\
  	'		filter = [];
  '\
  	'		table = [];
  '\
  	'		plist = deviceParent(devid);
  '\
  	'		var devidx = plist.length - 1;
  '\
  	'		for(var i = 0; i < devidx; i++)
  '\
  	'			table[i] = [{name: plist[i], span: 1}];
  '\
  	'		deviceChildren(devid, devidx, 0);
  '\
  	'		for(var i = 0; i < devidx; i++)
  '\
  	'			table[i][0].span = table[devidx][0].span;
  '\
  	'		for(var row = 0; row < table[0][0].span; row++) {
  '\
  	'			html += "<tr>";
  '\
  	'			for(var col = 0; col < table.length; col++)
  '\
  	'				if(row in table[col]) {
  '\
  	'					var cell = table[col][row];
  '\
  	'					var args = "";
  '\
  	'					if(cell.span > 1)
  '\
  	'						args += " rowspan="+cell.span;
  '\
  	'					if((col == devidx) && (row == 0))
  '\
  	'						args += " class=tdhl";
  '\
  	'					if(resume)
  '\
  	'						html += "<td"+args+">"+cell.name+" &rarr;</td>";
  '\
  	'					else
  '\
  	'						html += "<td"+args+">&larr; "+cell.name+"</td>";
  '\
  	'				}
  '\
  	'			html += "</tr>";
  '\
  	'		}
  '\
  	'		html += "</table>";
  '\
  	'		return html;
  '\
  	'	}
  '\
  	'	function zoomTimeline() {
  '\
  	'		var timescale = document.getElementById("timescale");
  '\
  	'		var dmesg = document.getElementById("dmesg");
  '\
  	'		var zoombox = document.getElementById("dmesgzoombox");
  '\
  	'		var val = parseFloat(dmesg.style.width);
  '\
  	'		var newval = 100;
  '\
  	'		var sh = window.outerWidth / 2;
  '\
  	'		if(this.id == "zoomin") {
  '\
  	'			newval = val * 1.2;
  '\
  	'			if(newval > 40000) newval = 40000;
  '\
  	'			dmesg.style.width = newval+"%";
  '\
  	'			zoombox.scrollLeft = ((zoombox.scrollLeft + sh) * newval / val) - sh;
  '\
  	'		} else if (this.id == "zoomout") {
  '\
  	'			newval = val / 1.2;
  '\
  	'			if(newval < 100) newval = 100;
  '\
  	'			dmesg.style.width = newval+"%";
  '\
  	'			zoombox.scrollLeft = ((zoombox.scrollLeft + sh) * newval / val) - sh;
  '\
  	'		} else {
  '\
  	'			zoombox.scrollLeft = 0;
  '\
  	'			dmesg.style.width = "100%";
  '\
  	'		}
  '\
  	'		var html = "";
  '\
  	'		var t0 = bounds[0];
  '\
  	'		var tMax = bounds[1];
  '\
  	'		var tTotal = tMax - t0;
  '\
  	'		var wTotal = tTotal * 100.0 / newval;
  '\
  	'		for(var tS = 1000; (wTotal / tS) < 3; tS /= 10);
  '\
  	'		if(tS < 1) tS = 1;
  '\
  	'		for(var s = ((t0 / tS)|0) * tS; s < tMax; s += tS) {
  '\
  	'			var pos = (tMax - s) * 100.0 / tTotal;
  '\
  	'			var name = (s == 0)?"S/R":(s+"ms");
  '\
  	'			html += \"<div class=\\\"t\\\" style=\\\"right:\"+pos+\"%\\\">\"+name+\"</div>\";
  '\
  	'		}
  '\
  	'		timescale.innerHTML = html;
  '\
  	'	}
  '\
  	'	function deviceDetail() {
  '\
  	'		var devtitle = document.getElementById("devicedetail");
  '\
  	'		devtitle.innerHTML = "<h1>"+this.title+"</h1>";
  '\
  	'		var devtree = document.getElementById("devicetree");
  '\
  	'		devtree.innerHTML = deviceTree(this.id, (this.title.indexOf("resume") >= 0));
  '\
  	'		var cglist = document.getElementById("callgraphs");
  '\
  	'		if(!cglist) return;
  '\
  	'		var cg = cglist.getElementsByClassName("atop");
  '\
  	'		for (var i = 0; i < cg.length; i++) {
  '\
  	'			if(filter.indexOf(cg[i].id) >= 0) {
  '\
  	'				cg[i].style.display = "block";
  '\
  	'			} else {
  '\
  	'				cg[i].style.display = "none";
  '\
  	'			}
  '\
  	'		}
  '\
  	'	}
  '\
  	'	window.addEventListener("load", function () {
  '\
  	'		var dmesg = document.getElementById("dmesg");
  '\
  	'		dmesg.style.width = "100%"
  '\
  	'		document.getElementById("zoomin").onclick = zoomTimeline;
  '\
  	'		document.getElementById("zoomout").onclick = zoomTimeline;
  '\
  	'		document.getElementById("zoomdef").onclick = zoomTimeline;
  '\
  	'		var dev = dmesg.getElementsByClassName("thread");
  '\
  	'		for (var i = 0; i < dev.length; i++) {
  '\
  	'			dev[i].onclick = deviceDetail;
  '\
  	'		}
  '\
  	'		zoomTimeline();
  '\
  	'	});
  '\
  	'</script>
  '
  	hf.write(script_code);
  
  # Function: executeSuspend
  # Description:
  #	 Execute system suspend through the sysfs interface
  def executeSuspend():
  	global sysvals, data
  
  	detectUSB()
  	pf = open(sysvals.powerfile, 'w')
  	# clear the kernel ring buffer just as we start
  	os.system("dmesg -C")
  	# start ftrace
  	if(data.useftrace):
  		print("START TRACING")
  		os.system("echo 1 > "+sysvals.tpath+"tracing_on")
  		os.system("echo SUSPEND START > "+sysvals.tpath+"trace_marker")
  	# initiate suspend
  	if(sysvals.rtcwake):
  		print("SUSPEND START")
  		os.system("rtcwake -s 10 -m "+sysvals.suspendmode)
  	else:
  		print("SUSPEND START (press a key to resume)")
  		pf.write(sysvals.suspendmode)
  	# execution will pause here
  	pf.close()
  	# return from suspend
  	print("RESUME COMPLETE")
  	# stop ftrace
  	if(data.useftrace):
  		os.system("echo RESUME COMPLETE > "+sysvals.tpath+"trace_marker")
  		os.system("echo 0 > "+sysvals.tpath+"tracing_on")
  		print("CAPTURING FTRACE")
  		os.system("echo \""+sysvals.teststamp+"\" > "+sysvals.ftracefile)
  		os.system("cat "+sysvals.tpath+"trace >> "+sysvals.ftracefile)
  	# grab a copy of the dmesg output
  	print("CAPTURING DMESG")
  	os.system("echo \""+sysvals.teststamp+"\" > "+sysvals.dmesgfile)
  	os.system("dmesg -c >> "+sysvals.dmesgfile)
  
  # Function: detectUSB
  # Description:
  #	 Detect all the USB hosts and devices currently connected
  def detectUSB():
  	global sysvals, data
  
  	for dirname, dirnames, filenames in os.walk("/sys/devices"):
  		if(re.match(r".*/usb[0-9]*.*", dirname) and
  			"idVendor" in filenames and "idProduct" in filenames):
  			vid = os.popen("cat %s/idVendor 2>/dev/null" % dirname).read().replace('
  ', '')
  			pid = os.popen("cat %s/idProduct 2>/dev/null" % dirname).read().replace('
  ', '')
  			product = os.popen("cat %s/product 2>/dev/null" % dirname).read().replace('
  ', '')
  			name = dirname.split('/')[-1]
  			if(len(product) > 0):
  				data.altdevname[name] = "%s [%s]" % (product, name)
  			else:
  				data.altdevname[name] = "%s:%s [%s]" % (vid, pid, name)
  
  def getModes():
  	global sysvals
  	modes = ""
  	if(os.path.exists(sysvals.powerfile)):
  		fp = open(sysvals.powerfile, 'r')
  		modes = string.split(fp.read())
  		fp.close()
  	return modes
  
  # Function: statusCheck
  # Description:
  #	 Verify that the requested command and options will work
  def statusCheck(dryrun):
  	global sysvals, data
  	res = dict()
  
  	if(data.notestrun):
  		print("SUCCESS: The command should run!")
  		return
  
  	# check we have root access
  	check = "YES"
  	if(os.environ['USER'] != "root"):
  		if(not dryrun):
  			doError("root access is required", False)
  		check = "NO"
  	res["    have root access:     "] = check
  
  	# check sysfs is mounted
  	check = "YES"
  	if(not os.path.exists(sysvals.powerfile)):
  		if(not dryrun):
  			doError("sysfs must be mounted", False)
  		check = "NO"
  	res["    is sysfs mounted:     "] = check
  
  	# check target mode is a valid mode
  	check = "YES"
  	modes = getModes()
  	if(sysvals.suspendmode not in modes):
  		if(not dryrun):
  			doError("%s is not a value power mode" % sysvals.suspendmode, False)
  		check = "NO"
  	res["    is "+sysvals.suspendmode+" a power mode: "] = check
  
  	# check if ftrace is available
  	if(data.useftrace):
  		check = "YES"
  		if(not verifyFtrace()):
  			if(not dryrun):
  				doError("ftrace is not configured", False)
  			check = "NO"
  		res["    is ftrace usable:     "] = check
  
  	# check if rtcwake
  	if(sysvals.rtcwake):
  		check = "YES"
  		version = os.popen("rtcwake -V 2>/dev/null").read()
  		if(not version.startswith("rtcwake")):
  			if(not dryrun):
  				doError("rtcwake is not installed", False)
  			check = "NO"
  		res["    is rtcwake usable:    "] = check
  
  	if(dryrun):
  		status = True
  		print("Checking if system can run the current command:")
  		for r in res:
  			print("%s\t%s" % (r, res[r]))
  			if(res[r] != "YES"):
  				status = False
  		if(status):
  			print("SUCCESS: The command should run!")
  		else:
  			print("FAILURE: The command won't run!")
  
  def printHelp():
  	global sysvals
  	modes = getModes()
  
  	print("")
  	print("AnalyzeSuspend")
  	print("Usage: sudo analyze_suspend.py <options>")
  	print("")
  	print("Description:")
  	print("  Initiates a system suspend/resume while capturing dmesg")
  	print("  and (optionally) ftrace data to analyze device timing")
  	print("")
  	print("  Generates output files in subdirectory: suspend-mmddyy-HHMMSS")
  	print("   HTML output:                    <hostname>_<mode>.html")
  	print("   raw dmesg output:               <hostname>_<mode>_dmesg.txt")
  	print("   raw ftrace output (with -f):    <hostname>_<mode>_ftrace.txt")
  	print("")
  	print("Options:")
  	print("  [general]")
  	print("    -h        Print this help text")
  	print("    -verbose  Print extra information during execution and analysis")
  	print("    -status   Test to see if the system is enabled to run this tool")
  	print("    -modes    List available suspend modes")
  	print("    -m mode   Mode to initiate for suspend %s (default: %s)") % (modes, sysvals.suspendmode)
  	print("    -rtcwake  Use rtcwake to autoresume after 10 seconds (default: disabled)")
  	print("    -f        Use ftrace to create device callgraphs (default: disabled)")
  	print("  [re-analyze data from previous runs]")
  	print("    -dmesg dmesgfile      Create HTML timeline from dmesg file")
  	print("    -ftrace ftracefile    Create HTML callgraph from ftrace file")
  	print("")
  	return True
  
  def doError(msg, help):
  	print("ERROR: %s") % msg
  	if(help == True):
  		printHelp()
  	sys.exit()
  
  # -- script main --
  # loop through the command line arguments
  cmd = ""
  args = iter(sys.argv[1:])
  for arg in args:
  	if(arg == "-m"):
  		try:
  			val = args.next()
  		except:
  			doError("No mode supplied", True)
  		sysvals.suspendmode = val
  	elif(arg == "-f"):
  		data.useftrace = True
  	elif(arg == "-modes"):
  		cmd = "modes"
  	elif(arg == "-status"):
  		cmd = "status"
  	elif(arg == "-verbose"):
  		data.verbose = True
  	elif(arg == "-rtcwake"):
  		sysvals.rtcwake = True
  	elif(arg == "-dmesg"):
  		try:
  			val = args.next()
  		except:
  			doError("No dmesg file supplied", True)
  		data.notestrun = True
  		data.usedmesg = True
  		sysvals.dmesgfile = val
  	elif(arg == "-ftrace"):
  		try:
  			val = args.next()
  		except:
  			doError("No ftrace file supplied", True)
  		data.notestrun = True
  		data.useftrace = True
  		sysvals.ftracefile = val
  	elif(arg == "-h"):
  		printHelp()
  		sys.exit()
  	else:
  		doError("Invalid argument: "+arg, True)
  
  # just run a utility command and exit
  if(cmd != ""):
  	if(cmd == "status"):
  		statusCheck(True)
  	elif(cmd == "modes"):
  		modes = getModes()
  		print modes
  	sys.exit()
  
  data.initialize()
  
  # if instructed, re-analyze existing data files
  if(data.notestrun):
  	sysvals.setOutputFile()
  	data.vprint("Output file: %s" % sysvals.htmlfile)
  	if(sysvals.dmesgfile != ""):
  		analyzeKernelLog()
  	if(sysvals.ftracefile != ""):
  		analyzeTraceLog()
  	createHTML()
  	sys.exit()
  
  # verify that we can run a test
  data.usedmesg = True
  statusCheck(False)
  
  # prepare for the test
  if(data.useftrace):
  	initFtrace()
  sysvals.initTestOutput()
  
  data.vprint("Output files:
      %s" % sysvals.dmesgfile)
  if(data.useftrace):
  	data.vprint("    %s" % sysvals.ftracefile)
  data.vprint("    %s" % sysvals.htmlfile)
  
  # execute the test
  executeSuspend()
  analyzeKernelLog()
  if(data.useftrace):
  	analyzeTraceLog()
  createHTML()