Merge branch 'pm-tools'

* pm-tools:
  PM / tools: analyze_suspend.py: update to v3.0

1 files changed, 2981 insertions, 836 deletions

diff --git a/scripts/analyze_suspend.py b/scripts/analyze_suspend.py
index 4f2cc12dc7c7..93e1fd40f430 100755
--- a/scripts/analyze_suspend.py
+++ b/scripts/analyze_suspend.py
@@ -36,146 +36,392 @@
 #		 CONFIG_FUNCTION_TRACER=y
 #		 CONFIG_FUNCTION_GRAPH_TRACER=y
 #
+#	 For kernel versions older than 3.15:
 #	 The following additional kernel parameters are required:
 #		 (e.g. in file /etc/default/grub)
 #		 GRUB_CMDLINE_LINUX_DEFAULT="... initcall_debug log_buf_len=16M ..."
 #
 
+# ----------------- LIBRARIES --------------------
+
 import sys
 import time
 import os
 import string
 import re
-import array
 import platform
-import datetime
+from datetime import datetime
 import struct
 
-# -- classes --
+# ----------------- CLASSES --------------------
 
+# Class: SystemValues
+# Description:
+#	 A global, single-instance container used to
+#	 store system values and test parameters
 class SystemValues:
-	testdir = "."
-	tpath = "/sys/kernel/debug/tracing/"
-	mempath = "/dev/mem"
-	powerfile = "/sys/power/state"
-	suspendmode = "mem"
-	prefix = "test"
-	teststamp = ""
-	dmesgfile = ""
-	ftracefile = ""
-	htmlfile = ""
+	version = 3.0
+	verbose = False
+	testdir = '.'
+	tpath = '/sys/kernel/debug/tracing/'
+	fpdtpath = '/sys/firmware/acpi/tables/FPDT'
+	epath = '/sys/kernel/debug/tracing/events/power/'
+	traceevents = [
+		'suspend_resume',
+		'device_pm_callback_end',
+		'device_pm_callback_start'
+	]
+	modename = {
+		'freeze': 'Suspend-To-Idle (S0)',
+		'standby': 'Power-On Suspend (S1)',
+		'mem': 'Suspend-to-RAM (S3)',
+		'disk': 'Suspend-to-disk (S4)'
+	}
+	mempath = '/dev/mem'
+	powerfile = '/sys/power/state'
+	suspendmode = 'mem'
+	hostname = 'localhost'
+	prefix = 'test'
+	teststamp = ''
+	dmesgfile = ''
+	ftracefile = ''
+	htmlfile = ''
 	rtcwake = False
+	rtcwaketime = 10
+	rtcpath = ''
+	android = False
+	adb = 'adb'
+	devicefilter = []
+	stamp = 0
+	execcount = 1
+	x2delay = 0
+	usecallgraph = False
+	usetraceevents = False
+	usetraceeventsonly = False
+	notestrun = False
+	altdevname = dict()
+	postresumetime = 0
+	tracertypefmt = '# tracer: (?P<t>.*)'
+	firmwarefmt = '# fwsuspend (?P<s>[0-9]*) fwresume (?P<r>[0-9]*)$'
+	postresumefmt = '# post resume time (?P<t>[0-9]*)$'
+	stampfmt = '# 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>.*)$'
+	def __init__(self):
+		self.hostname = platform.node()
+		if(self.hostname == ''):
+			self.hostname = 'localhost'
+		rtc = "rtc0"
+		if os.path.exists('/dev/rtc'):
+			rtc = os.readlink('/dev/rtc')
+		rtc = '/sys/class/rtc/'+rtc
+		if os.path.exists(rtc) and os.path.exists(rtc+'/date') and \
+			os.path.exists(rtc+'/time') and os.path.exists(rtc+'/wakealarm'):
+			self.rtcpath = rtc
 	def setOutputFile(self):
-		if((self.htmlfile == "") and (self.dmesgfile != "")):
-			m = re.match(r"(?P<name>.*)_dmesg\.txt$", self.dmesgfile)
+		if((self.htmlfile == '') and (self.dmesgfile != '')):
+			m = re.match('(?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)
+				self.htmlfile = m.group('name')+'.html'
+		if((self.htmlfile == '') and (self.ftracefile != '')):
+			m = re.match('(?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"
+				self.htmlfile = m.group('name')+'.html'
+		if(self.htmlfile == ''):
+			self.htmlfile = 'output.html'
+	def initTestOutput(self, subdir):
+		if(not self.android):
+			self.prefix = self.hostname
+			v = open('/proc/version', 'r').read().strip()
+			kver = string.split(v)[2]
+		else:
+			self.prefix = 'android'
+			v = os.popen(self.adb+' shell cat /proc/version').read().strip()
+			kver = string.split(v)[2]
+		testtime = datetime.now().strftime('suspend-%m%d%y-%H%M%S')
+		if(subdir != "."):
+			self.testdir = subdir+"/"+testtime
+		else:
+			self.testdir = testtime
+		self.teststamp = \
+			'# '+testtime+' '+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)
+	def setDeviceFilter(self, devnames):
+		self.devicefilter = string.split(devnames)
+	def rtcWakeAlarm(self):
+		os.system('echo 0 > '+self.rtcpath+'/wakealarm')
+		outD = open(self.rtcpath+'/date', 'r').read().strip()
+		outT = open(self.rtcpath+'/time', 'r').read().strip()
+		mD = re.match('^(?P<y>[0-9]*)-(?P<m>[0-9]*)-(?P<d>[0-9]*)', outD)
+		mT = re.match('^(?P<h>[0-9]*):(?P<m>[0-9]*):(?P<s>[0-9]*)', outT)
+		if(mD and mT):
+			# get the current time from hardware
+			utcoffset = int((datetime.now() - datetime.utcnow()).total_seconds())
+			dt = datetime(\
+				int(mD.group('y')), int(mD.group('m')), int(mD.group('d')),
+				int(mT.group('h')), int(mT.group('m')), int(mT.group('s')))
+			nowtime = int(dt.strftime('%s')) + utcoffset
+		else:
+			# if hardware time fails, use the software time
+			nowtime = int(datetime.now().strftime('%s'))
+		alarm = nowtime + self.rtcwaketime
+		os.system('echo %d > %s/wakealarm' % (alarm, self.rtcpath))
 
+sysvals = SystemValues()
+
+# Class: DeviceNode
+# Description:
+#	 A container used to create a device hierachy, with a single root node
+#	 and a tree of child nodes. Used by Data.deviceTopology()
+class DeviceNode:
+	name = ''
+	children = 0
+	depth = 0
+	def __init__(self, nodename, nodedepth):
+		self.name = nodename
+		self.children = []
+		self.depth = nodedepth
+
+# Class: Data
+# Description:
+#	 The primary container for suspend/resume test data. There is one for
+#	 each test run. The data is organized into a cronological hierarchy:
+#	 Data.dmesg {
+#		root structure, started as dmesg & ftrace, but now only ftrace
+#		contents: times for suspend start/end, resume start/end, fwdata
+#		phases {
+#			10 sequential, non-overlapping phases of S/R
+#			contents: times for phase start/end, order/color data for html
+#			devlist {
+#				device callback or action list for this phase
+#				device {
+#					a single device callback or generic action
+#					contents: start/stop times, pid/cpu/driver info
+#						parents/children, html id for timeline/callgraph
+#						optionally includes an ftrace callgraph
+#						optionally includes intradev trace events
+#				}
+#			}
+#		}
+#	}
+#
 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},
+	dmesg = {}  # root data structure
+	phases = [] # ordered list of phases
+	start = 0.0 # test start
+	end = 0.0   # test end
+	tSuspended = 0.0 # low-level suspend start
+	tResumed = 0.0   # low-level resume start
+	tLow = 0.0       # time spent in low-level suspend (standby/freeze)
+	fwValid = False  # is firmware data available
+	fwSuspend = 0    # time spent in firmware suspend
+	fwResume = 0     # time spent in firmware resume
+	dmesgtext = []   # dmesg text file in memory
+	testnumber = 0
+	idstr = ''
+	html_device_id = 0
+	stamp = 0
+	outfile = ''
+	def __init__(self, num):
+		idchar = 'abcdefghijklmnopqrstuvwxyz'
+		self.testnumber = num
+		self.idstr = idchar[num]
+		self.dmesgtext = []
+		self.phases = []
+		self.dmesg = { # fixed list of 10 phases
+			'suspend_prepare': {'list': dict(), 'start': -1.0, 'end': -1.0,
+								'row': 0, 'color': '#CCFFCC', 'order': 0},
+			        'suspend': {'list': dict(), 'start': -1.0, 'end': -1.0,
+								'row': 0, 'color': '#88FF88', 'order': 1},
+			   'suspend_late': {'list': dict(), 'start': -1.0, 'end': -1.0,
+								'row': 0, 'color': '#00AA00', 'order': 2},
 			  '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},
+								'row': 0, 'color': '#008888', 'order': 3},
+		    'suspend_machine': {'list': dict(), 'start': -1.0, 'end': -1.0,
+								'row': 0, 'color': '#0000FF', 'order': 4},
+			 'resume_machine': {'list': dict(), 'start': -1.0, 'end': -1.0,
+								'row': 0, 'color': '#FF0000', 'order': 5},
 			   'resume_noirq': {'list': dict(), 'start': -1.0, 'end': -1.0,
-								'row': 0, 'color': "orange", 'order': 5},
+								'row': 0, 'color': '#FF9900', 'order': 6},
 			   '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}
+								'row': 0, 'color': '#FFCC00', 'order': 7},
+			         'resume': {'list': dict(), 'start': -1.0, 'end': -1.0,
+								'row': 0, 'color': '#FFFF88', 'order': 8},
+			'resume_complete': {'list': dict(), 'start': -1.0, 'end': -1.0,
+								'row': 0, 'color': '#FFFFCC', 'order': 9}
 		}
 		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
+	def getStart(self):
+		return self.dmesg[self.phases[0]]['start']
+	def setStart(self, time):
+		self.start = time
+		self.dmesg[self.phases[0]]['start'] = time
+	def getEnd(self):
+		return self.dmesg[self.phases[-1]]['end']
+	def setEnd(self, time):
+		self.end = time
+		self.dmesg[self.phases[-1]]['end'] = time
+	def isTraceEventOutsideDeviceCalls(self, pid, time):
+		for phase in self.phases:
+			list = self.dmesg[phase]['list']
+			for dev in list:
+				d = list[dev]
+				if(d['pid'] == pid and time >= d['start'] and
+					time <= d['end']):
+					return False
+		return True
+	def addIntraDevTraceEvent(self, action, name, pid, time):
+		if(action == 'mutex_lock_try'):
+			color = 'red'
+		elif(action == 'mutex_lock_pass'):
+			color = 'green'
+		elif(action == 'mutex_unlock'):
+			color = 'blue'
+		else:
+			# create separate colors based on the name
+			v1 = len(name)*10 % 256
+			v2 = string.count(name, 'e')*100 % 256
+			v3 = ord(name[0])*20 % 256
+			color = '#%06X' % ((v1*0x10000) + (v2*0x100) + v3)
+		for phase in self.phases:
+			list = self.dmesg[phase]['list']
+			for dev in list:
+				d = list[dev]
+				if(d['pid'] == pid and time >= d['start'] and
+					time <= d['end']):
+					e = TraceEvent(action, name, color, time)
+					if('traceevents' not in d):
+						d['traceevents'] = []
+					d['traceevents'].append(e)
+					return d
+					break
+		return 0
+	def capIntraDevTraceEvent(self, action, name, pid, time):
+		for phase in self.phases:
+			list = self.dmesg[phase]['list']
+			for dev in list:
+				d = list[dev]
+				if(d['pid'] == pid and time >= d['start'] and
+					time <= d['end']):
+					if('traceevents' not in d):
+						return
+					for e in d['traceevents']:
+						if(e.action == action and
+							e.name == name and not e.ready):
+							e.length = time - e.time
+							e.ready = True
+							break
+					return
+	def trimTimeVal(self, t, t0, dT, left):
+		if left:
+			if(t > t0):
+				if(t - dT < t0):
+					return t0
+				return t - dT
+			else:
+				return t
+		else:
+			if(t < t0 + dT):
+				if(t > t0):
+					return t0 + dT
+				return t + dT
+			else:
+				return t
+	def trimTime(self, t0, dT, left):
+		self.tSuspended = self.trimTimeVal(self.tSuspended, t0, dT, left)
+		self.tResumed = self.trimTimeVal(self.tResumed, t0, dT, left)
+		self.start = self.trimTimeVal(self.start, t0, dT, left)
+		self.end = self.trimTimeVal(self.end, t0, dT, left)
 		for phase in self.phases:
-			zero = tRes
-			if "suspend" in phase:
-				zero = tSus
 			p = self.dmesg[phase]
-			p['start'] -= zero
-			p['end'] -= zero
+			p['start'] = self.trimTimeVal(p['start'], t0, dT, left)
+			p['end'] = self.trimTimeVal(p['end'], t0, dT, left)
 			list = p['list']
 			for name in list:
 				d = list[name]
-				d['start'] -= zero
-				d['end'] -= zero
+				d['start'] = self.trimTimeVal(d['start'], t0, dT, left)
+				d['end'] = self.trimTimeVal(d['end'], t0, dT, left)
 				if('ftrace' in d):
 					cg = d['ftrace']
-					cg.start -= zero
-					cg.end -= zero
+					cg.start = self.trimTimeVal(cg.start, t0, dT, left)
+					cg.end = self.trimTimeVal(cg.end, t0, dT, left)
 					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)
+						line.time = self.trimTimeVal(line.time, t0, dT, left)
+				if('traceevents' in d):
+					for e in d['traceevents']:
+						e.time = self.trimTimeVal(e.time, t0, dT, left)
+	def normalizeTime(self, tZero):
+		# first trim out any standby or freeze clock time
+		if(self.tSuspended != self.tResumed):
+			if(self.tResumed > tZero):
+				self.trimTime(self.tSuspended, \
+					self.tResumed-self.tSuspended, True)
+			else:
+				self.trimTime(self.tSuspended, \
+					self.tResumed-self.tSuspended, False)
+		# shift the timeline so that tZero is the new 0
+		self.tSuspended -= tZero
+		self.tResumed -= tZero
+		self.start -= tZero
+		self.end -= tZero
+		for phase in self.phases:
+			p = self.dmesg[phase]
+			p['start'] -= tZero
+			p['end'] -= tZero
+			list = p['list']
+			for name in list:
+				d = list[name]
+				d['start'] -= tZero
+				d['end'] -= tZero
+				if('ftrace' in d):
+					cg = d['ftrace']
+					cg.start -= tZero
+					cg.end -= tZero
+					for line in cg.list:
+						line.time -= tZero
+				if('traceevents' in d):
+					for e in d['traceevents']:
+						e.time -= tZero
+	def newPhaseWithSingleAction(self, phasename, devname, start, end, color):
+		for phase in self.phases:
+			self.dmesg[phase]['order'] += 1
+		self.html_device_id += 1
+		devid = '%s%d' % (self.idstr, self.html_device_id)
+		list = dict()
+		list[devname] = \
+			{'start': start, 'end': end, 'pid': 0, 'par': '',
+			'length': (end-start), 'row': 0, 'id': devid, 'drv': '' };
+		self.dmesg[phasename] = \
+			{'list': list, 'start': start, 'end': end,
+			'row': 0, 'color': color, 'order': 0}
+		self.phases = self.sortedPhases()
+	def newPhase(self, phasename, start, end, color, order):
+		if(order < 0):
+			order = len(self.phases)
+		for phase in self.phases[order:]:
+			self.dmesg[phase]['order'] += 1
+		if(order > 0):
+			p = self.phases[order-1]
+			self.dmesg[p]['end'] = start
+		if(order < len(self.phases)):
+			p = self.phases[order]
+			self.dmesg[p]['start'] = end
+		list = dict()
+		self.dmesg[phasename] = \
+			{'list': list, 'start': start, 'end': end,
+			'row': 0, 'color': color, 'order': order}
+		self.phases = self.sortedPhases()
+	def setPhase(self, phase, ktime, isbegin):
+		if(isbegin):
+			self.dmesg[phase]['start'] = ktime
+		else:
+			self.dmesg[phase]['end'] = ktime
 	def dmesgSortVal(self, phase):
 		return self.dmesg[phase]['order']
 	def sortedPhases(self):
@@ -197,59 +443,180 @@ class Data:
 			dev = phaselist[devname]
 			if(dev['end'] < 0):
 				dev['end'] = end
-				self.vprint("%s (%s): callback didn't return" % (devname, phase))
+				vprint('%s (%s): callback didnt return' % (devname, phase))
+	def deviceFilter(self, devicefilter):
+		# remove all by the relatives of the filter devnames
+		filter = []
+		for phase in self.phases:
+			list = self.dmesg[phase]['list']
+			for name in devicefilter:
+				dev = name
+				while(dev in list):
+					if(dev not in filter):
+						filter.append(dev)
+					dev = list[dev]['par']
+				children = self.deviceDescendants(name, phase)
+				for dev in children:
+					if(dev not in filter):
+						filter.append(dev)
+		for phase in self.phases:
+			list = self.dmesg[phase]['list']
+			rmlist = []
+			for name in list:
+				pid = list[name]['pid']
+				if(name not in filter and pid >= 0):
+					rmlist.append(name)
+			for name in rmlist:
+				del list[name]
 	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
+			self.fixupInitcalls(phase, self.getEnd())
+	def newActionGlobal(self, name, start, end):
+		# which phase is this device callback or action "in"
+		targetphase = "none"
+		overlap = 0.0
+		for phase in self.phases:
+			pstart = self.dmesg[phase]['start']
+			pend = self.dmesg[phase]['end']
+			o = max(0, min(end, pend) - max(start, pstart))
+			if(o > overlap):
+				targetphase = phase
+				overlap = o
+		if targetphase in self.phases:
+			self.newAction(targetphase, name, -1, '', start, end, '')
+			return True
+		return False
+	def newAction(self, phase, name, pid, parent, start, end, drv):
+		# new device callback for a specific phase
+		self.html_device_id += 1
+		devid = '%s%d' % (self.idstr, self.html_device_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 }
+					  'length': length, 'row': 0, 'id': devid, 'drv': drv }
 	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'])
+		list = self.dmesg[phase]['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']
+		pdev = ''
+		pdevid = ''
+		list = self.dmesg[phase]['list']
+		if devname in list:
+			pdev = list[devname]['par']
+		if pdev in list:
+			return list[pdev]['id']
 		return pdev
-	def deviceChildrenIDs(self, devname, phase):
+	def deviceChildren(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)
+		list = self.dmesg[phase]['list']
+		for child in list:
+			if(list[child]['par'] == devname):
+				devlist.append(child)
+		return devlist
+	def deviceDescendants(self, devname, phase):
+		children = self.deviceChildren(devname, phase)
+		family = children
+		for child in children:
+			family += self.deviceDescendants(child, phase)
+		return family
+	def deviceChildrenIDs(self, devname, phase):
+		devlist = self.deviceChildren(devname, phase)
 		return self.deviceIDs(devlist, phase)
-
+	def printDetails(self):
+		vprint('          test start: %f' % self.start)
+		for phase in self.phases:
+			dc = len(self.dmesg[phase]['list'])
+			vprint('    %16s: %f - %f (%d devices)' % (phase, \
+				self.dmesg[phase]['start'], self.dmesg[phase]['end'], dc))
+		vprint('            test end: %f' % self.end)
+	def masterTopology(self, name, list, depth):
+		node = DeviceNode(name, depth)
+		for cname in list:
+			clist = self.deviceChildren(cname, 'resume')
+			cnode = self.masterTopology(cname, clist, depth+1)
+			node.children.append(cnode)
+		return node
+	def printTopology(self, node):
+		html = ''
+		if node.name:
+			info = ''
+			drv = ''
+			for phase in self.phases:
+				list = self.dmesg[phase]['list']
+				if node.name in list:
+					s = list[node.name]['start']
+					e = list[node.name]['end']
+					if list[node.name]['drv']:
+						drv = ' {'+list[node.name]['drv']+'}'
+					info += ('<li>%s: %.3fms</li>' % (phase, (e-s)*1000))
+			html += '<li><b>'+node.name+drv+'</b>'
+			if info:
+				html += '<ul>'+info+'</ul>'
+			html += '</li>'
+		if len(node.children) > 0:
+			html += '<ul>'
+			for cnode in node.children:
+				html += self.printTopology(cnode)
+			html += '</ul>'
+		return html
+	def rootDeviceList(self):
+		# list of devices graphed
+		real = []
+		for phase in self.dmesg:
+			list = self.dmesg[phase]['list']
+			for dev in list:
+				if list[dev]['pid'] >= 0 and dev not in real:
+					real.append(dev)
+		# list of top-most root devices
+		rootlist = []
+		for phase in self.dmesg:
+			list = self.dmesg[phase]['list']
+			for dev in list:
+				pdev = list[dev]['par']
+				if(re.match('[0-9]*-[0-9]*\.[0-9]*[\.0-9]*\:[\.0-9]*$', pdev)):
+					continue
+				if pdev and pdev not in real and pdev not in rootlist:
+					rootlist.append(pdev)
+		return rootlist
+	def deviceTopology(self):
+		rootlist = self.rootDeviceList()
+		master = self.masterTopology('', rootlist, 0)
+		return self.printTopology(master)
+
+# Class: TraceEvent
+# Description:
+#	 A container for trace event data found in the ftrace file
+class TraceEvent:
+	ready = False
+	name = ''
+	time = 0.0
+	color = '#FFFFFF'
+	length = 0.0
+	action = ''
+	def __init__(self, a, n, c, t):
+		self.action = a
+		self.name = n
+		self.color = c
+		self.time = t
+
+# Class: FTraceLine
+# Description:
+#	 A container for a single line of ftrace data. There are six basic types:
+#		 callgraph line:
+#			  call: "  dpm_run_callback() {"
+#			return: "  }"
+#			  leaf: " dpm_run_callback();"
+#		 trace event:
+#			 tracing_mark_write: SUSPEND START or RESUME COMPLETE
+#			 suspend_resume: phase or custom exec block data
+#			 device_pm_callback: device callback info
 class FTraceLine:
 	time = 0.0
 	length = 0.0
@@ -257,20 +624,33 @@ class FTraceLine:
 	freturn = False
 	fevent = False
 	depth = 0
-	name = ""
+	name = ''
+	type = ''
 	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")
+		# is this a trace event
+		if(d == 'traceevent' or re.match('^ *\/\* *(?P<msg>.*) \*\/ *$', m)):
+			if(d == 'traceevent'):
+				# nop format trace event
+				msg = m
+			else:
+				# function_graph format trace event
+				em = re.match('^ *\/\* *(?P<msg>.*) \*\/ *$', m)
+				msg = em.group('msg')
+
+			emm = re.match('^(?P<call>.*?): (?P<msg>.*)', msg)
+			if(emm):
+				self.name = emm.group('msg')
+				self.type = emm.group('call')
+			else:
+				self.name = 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)
+		match = re.match('^(?P<d> *)(?P<o>.*)$', m)
 		if(not match):
 			return
 		self.depth = self.getDepth(match.group('d'))
@@ -280,7 +660,7 @@ class FTraceLine:
 			self.freturn = True
 			if(len(m) > 1):
 				# includes comment with function name
-				match = re.match(r"^} *\/\* *(?P<n>.*) *\*\/$", m)
+				match = re.match('^} *\/\* *(?P<n>.*) *\*\/$', m)
 				if(match):
 					self.name = match.group('n')
 		# function call
@@ -288,13 +668,13 @@ class FTraceLine:
 			self.fcall = True
 			# function call with children
 			if(m[-1] == '{'):
-				match = re.match(r"^(?P<n>.*) *\(.*", m)
+				match = re.match('^(?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)
+				match = re.match('^(?P<n>.*) *\(.*', m)
 				if(match):
 					self.name = match.group('n')
 			# something else (possibly a trace marker)
@@ -302,7 +682,23 @@ class FTraceLine:
 				self.name = m
 	def getDepth(self, str):
 		return len(str)/2
+	def debugPrint(self, dev):
+		if(self.freturn and self.fcall):
+			print('%s -- %f (%02d): %s(); (%.3f us)' % (dev, self.time, \
+				self.depth, self.name, self.length*1000000))
+		elif(self.freturn):
+			print('%s -- %f (%02d): %s} (%.3f us)' % (dev, self.time, \
+				self.depth, self.name, self.length*1000000))
+		else:
+			print('%s -- %f (%02d): %s() { (%.3f us)' % (dev, self.time, \
+				self.depth, self.name, self.length*1000000))
 
+# Class: FTraceCallGraph
+# Description:
+#	 A container for the ftrace callgraph of a single recursive function.
+#	 This can be a dpm_run_callback, dpm_prepare, or dpm_complete callgraph
+#	 Each instance is tied to a single device in a single phase, and is
+#	 comprised of an ordered list of FTraceLine objects
 class FTraceCallGraph:
 	start = -1.0
 	end = -1.0
@@ -327,24 +723,53 @@ class FTraceCallGraph:
 		if(not self.invalid):
 			self.setDepth(line)
 		if(line.depth == 0 and line.freturn):
+			if(self.start < 0):
+				self.start = line.time
 			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
+			if(len(self.list) > 0):
+				first = self.list[0]
+				self.list = []
+				self.list.append(first)
+			self.invalid = True
+			if(not match):
+				return False
+			id = 'task %s cpu %s' % (match.group('pid'), match.group('cpu'))
+			window = '(%f - %f)' % (self.start, line.time)
+			if(self.depth < 0):
+				print('Too much data for '+id+\
+					' (buffer overflow), ignoring this callback')
+			else:
+				print('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 slice(self, t0, tN):
+		minicg = FTraceCallGraph()
+		count = -1
+		firstdepth = 0
+		for l in self.list:
+			if(l.time < t0 or l.time > tN):
+				continue
+			if(count < 0):
+				if(not l.fcall or l.name == 'dev_driver_string'):
+					continue
+				firstdepth = l.depth
+				count = 0
+			l.depth -= firstdepth
+			minicg.addLine(l, 0)
+			if((count == 0 and l.freturn and l.fcall) or
+				(count > 0 and l.depth <= 0)):
+				break
+			count += 1
+		return minicg
 	def sanityCheck(self):
 		stack = dict()
 		cnt = 0
@@ -353,7 +778,7 @@ class FTraceCallGraph:
 				stack[l.depth] = l
 				cnt += 1
 			elif(l.freturn and not l.fcall):
-				if(not stack[l.depth]):
+				if(l.depth not in stack):
 					return False
 				stack[l.depth].length = l.length
 				stack[l.depth] = 0
@@ -363,40 +788,51 @@ class FTraceCallGraph:
 			return True
 		return False
 	def debugPrint(self, filename):
-		if(filename == "stdout"):
-			print("[%f - %f]") % (self.start, self.end)
+		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))
+					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))
+					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(" ")
+					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))
+					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))
+					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.write('%f (%02d): %s() { (%.3f us)\n' % (l.time, \
+						l.depth, l.name, l.length*1000000))
 			fp.close()
 
+# Class: Timeline
+# Description:
+#	 A container for a suspend/resume html timeline. In older versions
+#	 of the script there were multiple timelines, but in the latest
+#	 there is only one.
 class Timeline:
 	html = {}
-	scaleH = 0.0 # height of the timescale row as a percent of the timeline height
+	scaleH = 0.0 # height of the 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': ""
+			'timeline': '',
+			'legend': '',
+			'scale': ''
 		}
 	def setRows(self, rows):
 		self.maxrows = int(rows)
@@ -407,104 +843,261 @@ class Timeline:
 			r = 1.0
 		self.rowH = (100.0 - self.scaleH)/r
 
-# -- global objects --
+# Class: TestRun
+# Description:
+#	 A container for a suspend/resume test run. This is necessary as
+#	 there could be more than one, and they need to be separate.
+class TestRun:
+	ftrace_line_fmt_fg = \
+		'^ *(?P<time>[0-9\.]*) *\| *(?P<cpu>[0-9]*)\)'+\
+		' *(?P<proc>.*)-(?P<pid>[0-9]*) *\|'+\
+		'[ +!]*(?P<dur>[0-9\.]*) .*\|  (?P<msg>.*)'
+	ftrace_line_fmt_nop = \
+		' *(?P<proc>.*)-(?P<pid>[0-9]*) *\[(?P<cpu>[0-9]*)\] *'+\
+		'(?P<flags>.{4}) *(?P<time>[0-9\.]*): *'+\
+		'(?P<msg>.*)'
+	ftrace_line_fmt = ftrace_line_fmt_nop
+	cgformat = False
+	ftemp = dict()
+	ttemp = dict()
+	inthepipe = False
+	tracertype = ''
+	data = 0
+	def __init__(self, dataobj):
+		self.data = dataobj
+		self.ftemp = dict()
+		self.ttemp = dict()
+	def isReady(self):
+		if(tracertype == '' or not data):
+			return False
+		return True
+	def setTracerType(self, tracer):
+		self.tracertype = tracer
+		if(tracer == 'function_graph'):
+			self.cgformat = True
+			self.ftrace_line_fmt = self.ftrace_line_fmt_fg
+		elif(tracer == 'nop'):
+			self.ftrace_line_fmt = self.ftrace_line_fmt_nop
+		else:
+			doError('Invalid tracer format: [%s]' % tracer, False)
 
-sysvals = SystemValues()
-data = Data()
+# ----------------- FUNCTIONS --------------------
 
-# -- functions --
+# Function: vprint
+# Description:
+#	 verbose print (prints only with -verbose option)
+# Arguments:
+#	 msg: the debug/log message to print
+def vprint(msg):
+	global sysvals
+	if(sysvals.verbose):
+		print(msg)
 
 # Function: initFtrace
 # Description:
-#	 Configure ftrace to capture a function trace during suspend/resume
+#	 Configure ftrace to use trace events and/or a callgraph
 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")
+	tp = sysvals.tpath
+	cf = 'dpm_run_callback'
+	if(sysvals.usetraceeventsonly):
+		cf = '-e dpm_prepare -e dpm_complete -e dpm_run_callback'
+	if(sysvals.usecallgraph or sysvals.usetraceevents):
+		print('INITIALIZING FTRACE...')
+		# turn trace off
+		os.system('echo 0 > '+tp+'tracing_on')
+		# set the trace clock to global
+		os.system('echo global > '+tp+'trace_clock')
+		# set trace buffer to a huge value
+		os.system('echo nop > '+tp+'current_tracer')
+		os.system('echo 100000 > '+tp+'buffer_size_kb')
+		# initialize the callgraph trace, unless this is an x2 run
+		if(sysvals.usecallgraph and sysvals.execcount == 1):
+			# set trace type
+			os.system('echo function_graph > '+tp+'current_tracer')
+			os.system('echo "" > '+tp+'set_ftrace_filter')
+			# set trace format options
+			os.system('echo funcgraph-abstime > '+tp+'trace_options')
+			os.system('echo funcgraph-proc > '+tp+'trace_options')
+			# focus only on device suspend and resume
+			os.system('cat '+tp+'available_filter_functions | grep '+\
+				cf+' > '+tp+'set_graph_function')
+		if(sysvals.usetraceevents):
+			# turn trace events on
+			events = iter(sysvals.traceevents)
+			for e in events:
+				os.