Merge tag 'pm+acpi-3.14-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm

Pull ACPI and power management updates from Rafael Wysocki:
 "As far as the number of commits goes, the top spot belongs to ACPI
  this time with cpufreq in the second position and a handful of PM
  core, PNP and cpuidle updates.  They are fixes and cleanups mostly, as
  usual, with a couple of new features in the mix.

  The most visible change is probably that we will create struct
  acpi_device objects (visible in sysfs) for all devices represented in
  the ACPI tables regardless of their status and there will be a new
  sysfs attribute under those objects allowing user space to check that
  status via _STA.

  Consequently, ACPI device eject or generally hot-removal will not
  delete those objects, unless the table containing the corresponding
  namespace nodes is unloaded, which is extremely rare.  Also ACPI
  container hotplug will be handled quite a bit differently and cpufreq
  will support CPU boost ("turbo") generically and not only in the
  acpi-cpufreq driver.

  Specifics:

   - ACPI core changes to make it create a struct acpi_device object for
     every device represented in the ACPI tables during all namespace
     scans regardless of the current status of that device.  In
     accordance with this, ACPI hotplug operations will not delete those
     objects, unless the underlying ACPI tables go away.

   - On top of the above, new sysfs attribute for ACPI device objects
     allowing user space to check device status by triggering the
     execution of _STA for its ACPI object.  From Srinivas Pandruvada.

   - ACPI core hotplug changes reducing code duplication, integrating
     the PCI root hotplug with the core and reworking container hotplug.

   - ACPI core simplifications making it use ACPI_COMPANION() in the
     code "glueing" ACPI device objects to "physical" devices.

   - ACPICA update to upstream version 20131218.  This adds support for
     the DBG2 and PCCT tables to ACPICA, fixes some bugs and improves
     debug facilities.  From Bob Moore, Lv Zheng and Betty Dall.

   - Init code change to carry out the early ACPI initialization
     earlier.  That should allow us to use ACPI during the timekeeping
     initialization and possibly to simplify the EFI initialization too.
     From Chun-Yi Lee.

   - Clenups of the inclusions of ACPI headers in many places all over
     from Lv Zheng and Rashika Kheria (work in progress).

   - New helper for ACPI _DSM execution and rework of the code in
     drivers that uses _DSM to execute it via the new helper.  From
     Jiang Liu.

   - New Win8 OSI blacklist entries from Takashi Iwai.

   - Assorted ACPI fixes and cleanups from Al Stone, Emil Goode, Hanjun
     Guo, Lan Tianyu, Masanari Iida, Oliver Neukum, Prarit Bhargava,
     Rashika Kheria, Tang Chen, Zhang Rui.

   - intel_pstate driver updates, including proper Baytrail support,
     from Dirk Brandewie and intel_pstate documentation from Ramkumar
     Ramachandra.

   - Generic CPU boost ("turbo") support for cpufreq from Lukasz
     Majewski.

   - powernow-k6 cpufreq driver fixes from Mikulas Patocka.

   - cpufreq core fixes and cleanups from Viresh Kumar, Jane Li, Mark
     Brown.

   - Assorted cpufreq drivers fixes and cleanups from Anson Huang, John
     Tobias, Paul Bolle, Paul Walmsley, Sachin Kamat, Shawn Guo, Viresh
     Kumar.

   - cpuidle cleanups from Bartlomiej Zolnierkiewicz.

   - Support for hibernation APM events from Bin Shi.

   - Hibernation fix to avoid bringing up nonboot CPUs with ACPI EC
     disabled during thaw transitions from Bjørn Mork.

   - PM core fixes and cleanups from Ben Dooks, Leonardo Potenza, Ulf
     Hansson.

   - PNP subsystem fixes and cleanups from Dmitry Torokhov, Levente
     Kurusa, Rashika Kheria.

   - New tool for profiling system suspend from Todd E Brandt and a
     cpupower tool cleanup from One Thousand Gnomes"

* tag 'pm+acpi-3.14-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm: (153 commits)
  thermal: exynos: boost: Automatic enable/disable of BOOST feature (at Exynos4412)
  cpufreq: exynos4x12: Change L0 driver data to CPUFREQ_BOOST_FREQ
  Documentation: cpufreq / boost: Update BOOST documentation
  cpufreq: exynos: Extend Exynos cpufreq driver to support boost
  cpufreq / boost: Kconfig: Support for software-managed BOOST
  acpi-cpufreq: Adjust the code to use the common boost attribute
  cpufreq: Add boost frequency support in core
  intel_pstate: Add trace point to report internal state.
  cpufreq: introduce cpufreq_generic_get() routine
  ARM: SA1100: Create dummy clk_get_rate() to avoid build failures
  cpufreq: stats: create sysfs entries when cpufreq_stats is a module
  cpufreq: stats: free table and remove sysfs entry in a single routine
  cpufreq: stats: remove hotplug notifiers
  cpufreq: stats: handle cpufreq_unregister_driver() and suspend/resume properly
  cpufreq: speedstep: remove unused speedstep_get_state
  platform: introduce OF style 'modalias' support for platform bus
  PM / tools: new tool for suspend/resume performance optimization
  ACPI: fix module autoloading for ACPI enumerated devices
  ACPI: add module autoloading support for ACPI enumerated devices
  ACPI: fix create_modalias() return value handling
  ...

1 files changed, 1446 insertions, 0 deletions

diff --git a/scripts/analyze_suspend.py b/scripts/analyze_suspend.py
new file mode 100755
index 000000000000..4f2cc12dc7c7
--- /dev/null
+++ b/scripts/analyze_suspend.py
@@ -0,0 +1,1446 @@
+#!/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)\n" % (l.time, l.depth, l.name, l.length*1000000))
+				elif(l.freturn):
+					fp.write("%f (%02d): %s} (%.3f us)\n" % (l.time, l.depth, l.name, l.length*1000000))
+				else:
+					fp.write("%f (%02d): %s() { (%.3f us)\n" % (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\n", "")
+		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>\n"
+	output = '<div id="timescale">\n'
+
+	# 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>\n'
+	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>\n'
+	html_zoombox = '<center><button id="zoomin">ZOOM IN</button><button id="zoomout">ZOOM OUT</button><button id="zoomdef">ZOOM 1:1</button></center>\n<div id="dmesgzoombox" class="zoombox">\n'
+	html_timeline = '<div id="{0}" class="timeline" style="height:{1}px">\n'
+	html_device = '<div id="{0}" title="{1}" class="thread" style="left:{2}%;top:{3}%;height:{4}%;width:{5}%;">{6}</div>\n'
+	html_phase = '<div class="phase" style="left:{0}%;width:{1}%;top:{2}%;height:{3}%;background-color:{4}">{5}</div>\n'
+	html_legend = '<div class="square" style="left:{0}%;background-color:{1}">&nbsp;{2}</div>\n'
+	html_timetotal = '<table class="time1">\n<tr>'\
+		'<td class="gray">{2} Suspend Time: <b>{0} ms</b></td>'\
+		'<td class="gray">{2} Resume Time: <b>{1} ms</b></td>'\
+		'</tr>\n</table>\n'
+	html_timegroups = '<table class="time2">\n<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>\n</table>\n'
+
+	# 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>\n</div>\n"
+
+		# draw a legend which describes the phases by color
+		devtl.html['legend'] = "<div class=\"legend\">\n"
+		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>\n"
+
+	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>\n<html>\n<head>\n\
+	<meta http-equiv=\"content-type\" content=\"text/html; charset=UTF-8\">\n\
+	<title>AnalyzeSuspend</title>\n\
+	<style type='text/css'>\n\
+		body {overflow-y: scroll;}\n\
+		.stamp {width: 100%;text-align:center;background-color:gray;line-height:30px;color:white;font: 25px Arial;}\n\
+		.callgraph {margin-top: 30px;box-shadow: 5px 5px 20px black;}\n\
+		.callgraph article * {padding-left: 28px;}\n\
+		h1 {color:black;font: bold 30px Times;}\n\
+		table {width:100%;}\n\
+		.gray {background-color:rgba(80,80,80,0.1);}\n\
+		.green {background-color:rgba(204,255,204,0.4);}\n\
+		.purple {background-color:rgba(128,0,128,0.2);}\n\
+		.yellow {background-color:rgba(255,255,204,0.4);}\n\
+		.time1 {font: 22px Arial;border:1px solid;}\n\
+		.time2 {font: 15px Arial;border-bottom:1px solid;border-left:1px solid;border-right:1px solid;}\n\
+		td {text-align: center;}\n\
+		.tdhl {color: red;}\n\
+		.hide {display: none;}\n\
+		.pf {display: none;}\n\
+		.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;}\n\
+		.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;}\n\
+		.pf:checked ~ *:not(:nth-child(2)) {display: none;}\n\
+		.zoombox {position: relative; width: 100%; overflow-x: scroll;}\n\
+		.timeline {position: relative; font-size: 14px;cursor: pointer;width: 100%; overflow: hidden; background-color:#dddddd;}\n\
+		.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);}\n\
+		.thread:hover {background-color:white;border:1px solid red;z-index:10;}\n\
+		.phase {position: absolute;overflow: hidden;border:0px;text-align:center;}\n\
+		.t {position: absolute; top: 0%; height: 100%; border-right:1px solid black;}\n\
+		.legend {position: relative; width: 100%; height: 40px; text-align: center;margin-bottom:20px}\n\
+		.legend .square {position:absolute;top:10px; width: 0px;height: 20px;border:1px solid;padding-left:20px;}\n\
+		button {height:40px;width:200px;margin-bottom:20px;margin-top:20px;font-size:24px;}\n\
+	</style>\n</head>\n<body>\n"
+	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>\n')
+		hf.write('<div id="devicetree"></div>\n')
+
+	# write the ftrace data (callgraph)
+	if(data.useftrace):
+		hf.write('<section id="callgraphs" class="callgraph">\n')
+		# write out the ftrace data converted to html
+		html_func_top = '<article id="{0}" class="atop" style="background-color:{1}">\n<input type="checkbox" class="pf" id="f{2}" checked/><label for="f{2}">{3} {4}</label>\n'
+		html_func_start = '<article>\n<input type="checkbox" class="pf" id="f{0}" checked/><label for="f{0}">{1} {2}</label>\n'
+		html_func_end = '</article>\n'
+		html_func_leaf = '<article>{0} {1}</article>\n'
+		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("\n\n    </section>\n")
+	# write the footer and close
+	addScriptCode(hf)
+	hf.write("</body>\n</html>\n")
+	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];\n' % (t0, tMax)
+	detail += '	var d = [];\n'
+	dfmt = '	d["%s"] = { n:"%s", p:"%s", c:[%s] };\n';
+	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">\n'+detail+\
+	'	var filter = [];\n'\
+	'	var table = [];\n'\
+	'	function deviceParent(devid) {\n'\
+	'		var devlist = [];\n'\
+	'		if(filter.indexOf(devid) < 0) filter[filter.length] = devid;\n'\
+	'		if(d[devid].p in d)\n'\
+	'			devlist = deviceParent(d[devid].p);\n'\
+	'		else if(d[devid].p != "")\n'\
+	'			devlist = [d[devid].p];\n'\
+	'		devlist[devlist.length] = d[devid].n;\n'\
+	'		return devlist;\n'\
+	'	}\n'\
+	'	function deviceChildren(devid, column, row) {\n'\
+	'		if(!(devid in d)) return;\n'\
+	'		if(filter.indexOf(devid) < 0) filter[filter.length] = devid;\n'\
+	'		var cell = {name: d[devid].n, span: 1};\n'\
+	'		var span = 0;\n'\
+	'		if(column >= table.length) table[column] = [];\n'\
+	'		table[column][row] = cell;\n'\
+	'		for(var i = 0; i < d[devid].c.length; i++) {\n'\
+	'			var cid = d[devid].c[i];\n'\
+	'			span += deviceChildren(cid, column+1, row+span);\n'\
+	'		}\n'\
+	'		if(span == 0) span = 1;\n'\
+	'		table[column][row].span = span;\n'\
+	'		return span;\n'\
+	'	}\n'\
+	'	function deviceTree(devid, resume) {\n'\
+	'		var html = "<table border=1>";\n'\
+	'		filter = [];\n'\
+	'		table = [];\n'\
+	'		plist = deviceParent(devid);\n'\
+	'		var devidx = plist.length - 1;\n'\
+	'		for(var i = 0; i < devidx; i++)\n'\
+	'			table[i] = [{name: plist[i], span: 1}];\n'\
+	'		deviceChildren(devid, devidx, 0);\n'\
+	'		for(var i = 0; i < devidx; i++)\n'\
+	'			table[i][0].span = table[devidx][0].span;\n'\
+	'		for(var row = 0; row < table[0][0].span; row++) {\n'\
+	'			html += "<tr>";\n'\
+	'			for(var col = 0; col < table.length; col++)\n'\
+	'				if(row in table[col]) {\n'\
+	'					var cell = table[col][row];\n'\
+	'					var args = "";\n'\
+	'					if(cell.span > 1)\n'\
+	'						args += " rowspan="+cell.span;\n'\
+	'					if((col == devidx) && (row == 0))\n'\
+	'						args += " class=tdhl";\n'\
+	'					if(resume)\n'\
+	'						html += "<td"+args+">"+cell.name+" &rarr;</td>";\n'\
+	'					else\n'\
+	'						html += "<td"+args+">&larr; "+cell.name+"</td>";\n'\
+	'				}\n'\
+	'			html += "</tr>";\n'\
+	'		}\n'\
+	'		html += "</table>";\n'\
+	'		return html;\n'\
+	'	}\n'\
+	'	function zoomTimeline() {\n'\
+	'		var timescale = document.getElementById("timescale");\n'\
+	'		var dmesg = document.getElementById("dmesg");\n'\
+	'		var zoombox = document.getElementById("dmesgzoombox");\n'\
+	'		var val = parseFloat(dmesg.style.width);\n'\
+	'		var newval = 100;\n'\
+	'		var sh = window.outerWidth / 2;\n'\
+	'		if(this.id == "zoomin") {\n'\
+	'			newval = val * 1.2;\n'\
+	'			if(newval > 40000) newval = 40000;\n'\
+	'			dmesg.style.width = newval+"%";\n'\
+	'			zoombox.scrollLeft = ((zoombox.scrollLeft + sh) * newval / val) - sh;\n'\
+	'		} else if (this.id == "zoomout") {\n'\
+	'			newval = val / 1.2;\n'\
+	'			if(newval < 100) newval = 100;\n'\
+	'			dmesg.style.width = newval+"%";\n'\
+	'			zoombox.scrollLeft = ((zoombox.scrollLeft + sh) * newval / val) - sh;\n'\
+	'		} else {\n'\
+	'			zoombox.scrollLeft = 0;\n'\
+	'			dmesg.style.width = "100%";\n'\
+	'		}\n'\
+	'		var html = "";\n'\
+	'		var t0 = bounds[0];\n'\
+	'		var tMax = bounds[1];\n'\
+	'		var tTotal = tMax - t0;\n'\
+	'		var wTotal = tTotal * 100.0 / newval;\n'\
+	'		for(var tS = 1000; (wTotal / tS) < 3; tS /= 10);\n'\
+	'		if(tS < 1) tS = 1;\n'\
+	'		for(var s = ((t0 / tS)|0) * tS; s < tMax; s += tS) {\n'\
+	'			var pos = (tMax - s) * 100.0 / tTotal;\n'\
+	'			var name = (s == 0)?"S/R":(s+"ms");\n'\
+	'			html += \"<div class=\\\"t\\\" style=\\\"right:\"+pos+\"%\\\">\"+name+\"</div>\";\n'\
+	'		}\n'\
+	'		timescale.innerHTML = html;\n'\
+	'	}\n'\
+	'	function deviceDetail() {\n'\
+	'		var devtitle = document.getElementById("devicedetail");\n'\
+	'		devtitle.innerHTML = "<h1>"+this.title+"</h1>";\n'\
+	'		var devtree = document.getElementById("devicetree");\n'\
+	'		devtree.innerHTML = deviceTree(this.id, (this.title.indexOf("resume") >= 0));\n'\
+	'		var cglist = document.getElementById("callgraphs");\n'\
+	'		if(!cglist) return;\n'\
+	'		var cg = cglist.getElementsByClassName("atop");\n'\
+	'		for (var i = 0; i < cg.length; i++) {\n'\
+	'			if(filter.indexOf(cg[i].id) >= 0) {\n'\
+	'				cg[i].style.display = "block";\n'\
+	'			} else {\n'\
+	'				cg[i].style.display = "none";\n'\
+	'			}\n'\
+	'		}\n'\
+	'	}\n'\
+	'	window.addEventListener("load", function () {\n'\
+	'		var dmesg = document.getElementById("dmesg");\n'\
+	'		dmesg.style.width = "100%"\n'\
+	'		document.getElementById("zoomin").onclick = zoomTimeline;\n'\
+	'		document.getElementById("zoomout").onclick = zoomTimeline;\n'\
+	'		document.getElementById("zoomdef").onclick = zoomTimeline;\n'\
+	'		var dev = dmesg.getElementsByClassName("thread");\n'\
+	'		for (var i = 0; i < dev.length; i++) {\n'\
+	'			dev[i].onclick = deviceDetail;\n'\
+	'		}\n'\
+	'		zoomTimeline();\n'\
+	'	});\n'\
+	'</script>\n'
+	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('\n', '')
+			pid = os.popen("cat %s/idProduct 2>/dev/null" % dirname).read().replace('\n', '')
+			product = os.popen("cat %s/product 2>/dev/null" % dirname).read().replace('\n', '')
+			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:\n    %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()