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

Pull power management updates from Rafael Wysocki:
 "The majority of changes go into the Operating Performance Points (OPP)
  framework and cpufreq this time, followed by devfreq and some
  scattered updates all over.

  The OPP changes are mostly related to switching over from RCU-based
  synchronization, that turned out to be overly complicated and
  problematic, to reference counting using krefs.

  In the cpufreq land there are core cleanups, documentation updates, a
  new driver for Broadcom BMIPS SoCs, a new cpufreq-dt sub-driver for TI
  SoCs that require special handling, ARM64 SoCs support for the qoriq
  driver, intel_pstate updates, powernv driver update and assorted
  fixes.

  The devfreq changes are mostly fixes related to the sysfs interface
  and some Exynos drivers updates.

  Apart from that, the cpuidle menu governor will support per-CPU PM QoS
  constraints for the wakeup latency now, some bugs in the wakeup IRQs
  framework are fixed, the generic power domains framework should handle
  asynchronous invocations of *noirq suspend/resume callbacks from now
  on, the analyze_suspend.py script is updated and there is a new tool
  for intel_pstate diagnostics.

  Specifics:

   - Operating Performance Points (OPP) framework fixes, cleanups and
     switch over from RCU-based synchronization to reference counting
     using krefs (Viresh Kumar, Wei Yongjun, Dave Gerlach)

   - cpufreq core cleanups and documentation updates (Viresh Kumar,
     Rafael Wysocki)

   - New cpufreq driver for Broadcom BMIPS SoCs (Markus Mayer)

   - New cpufreq-dt sub-driver for TI SoCs requiring special handling,
     like in the AM335x, AM437x, DRA7x, and AM57x families, along with
     new DT bindings for it (Dave Gerlach, Paul Gortmaker)

   - ARM64 SoCs support for the qoriq cpufreq driver (Tang Yuantian)

   - intel_pstate driver updates including a new sysfs knob to control
     the driver's operation mode and fixes related to the no_turbo sysfs
     knob and the hardware-managed P-states feature support (Rafael
     Wysocki, Srinivas Pandruvada)

   - New interface to export ultra-turbo frequencies for the powernv
     cpufreq driver (Shilpasri Bhat)

   - Assorted fixes for cpufreq drivers (Arnd Bergmann, Dan Carpenter,
     Wei Yongjun)

   - devfreq core fixes, mostly related to the sysfs interface exported
     by it (Chanwoo Choi, Chris Diamand)

   - Updates of the exynos-bus and exynos-ppmu devfreq drivers (Chanwoo
     Choi)

   - Device PM QoS extension to support CPUs and support for per-CPU
     wakeup (device resume) latency constraints in the cpuidle menu
     governor (Alex Shi)

   - Wakeup IRQs framework fixes (Grygorii Strashko)

   - Generic power domains framework update including a fix to make it
     handle asynchronous invocations of *noirq suspend/resume callbacks
     correctly (Ulf Hansson, Geert Uytterhoeven)

   - Assorted fixes and cleanups in the core suspend/hibernate code, PM
     QoS framework and x86 ACPI idle support code (Corentin Labbe, Geert
     Uytterhoeven, Geliang Tang, John Keeping, Nick Desaulniers)

   - Update of the analyze_suspend.py script is updated to version 4.5
     offering multiple improvements (Todd Brandt)

   - New tool for intel_pstate diagnostics using the pstate_sample
     tracepoint (Doug Smythies)"

* tag 'pm-4.11-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm: (85 commits)
  MAINTAINERS: cpufreq: add bmips-cpufreq.c
  PM / QoS: Fix memory leak on resume_latency.notifiers
  PM / Documentation: Spelling s/wrtie/write/
  PM / sleep: Fix test_suspend after sleep state rework
  cpufreq: CPPC: add ACPI_PROCESSOR dependency
  cpufreq: make ti-cpufreq explicitly non-modular
  cpufreq: Do not clear real_cpus mask on policy init
  tools/power/x86: Debug utility for intel_pstate driver
  AnalyzeSuspend: fix drag and zoom bug in javascript
  PM / wakeirq: report a wakeup_event on dedicated wekup irq
  PM / wakeirq: Fix spurious wake-up events for dedicated wakeirqs
  PM / wakeirq: Enable dedicated wakeirq for suspend
  cpufreq: dt: Don't use generic platdev driver for ti-cpufreq platforms
  cpufreq: ti: Add cpufreq driver to determine available OPPs at runtime
  Documentation: dt: add bindings for ti-cpufreq
  PM / OPP: Expose _of_get_opp_desc_node as dev_pm_opp API
  cpufreq: qoriq: Don't look at clock implementation details
  cpufreq: qoriq: add ARM64 SoCs support
  PM / Domains: Provide dummy governors if CONFIG_PM_GENERIC_DOMAINS=n
  cpufreq: brcmstb-avs-cpufreq: remove unnecessary platform_set_drvdata()
  ...

1 files changed, 1135 insertions, 798 deletions

diff --git a/scripts/analyze_suspend.py b/scripts/analyze_suspend.py
index a0ba48fa2c5e..20cdb2bc1dae 100755
--- a/scripts/analyze_suspend.py
+++ b/scripts/analyze_suspend.py
@@ -24,11 +24,6 @@
 #	   https://01.org/suspendresume
 #	 Source repo
 #	   https://github.com/01org/suspendresume
-#	 Documentation
-#	   Getting Started
-#	     https://01.org/suspendresume/documentation/getting-started
-#	   Command List:
-#	     https://01.org/suspendresume/documentation/command-list
 #
 # Description:
 #	 This tool is designed to assist kernel and OS developers in optimizing
@@ -66,6 +61,8 @@ import platform
 from datetime import datetime
 import struct
 import ConfigParser
+from threading import Thread
+from subprocess import call, Popen, PIPE
 
 # ----------------- CLASSES --------------------
 
@@ -75,11 +72,15 @@ import ConfigParser
 #	 store system values and test parameters
 class SystemValues:
 	ansi = False
-	version = '4.2'
+	version = '4.5'
 	verbose = False
 	addlogs = False
-	mindevlen = 0.001
-	mincglen = 1.0
+	mindevlen = 0.0
+	mincglen = 0.0
+	cgphase = ''
+	cgtest = -1
+	callloopmaxgap = 0.0001
+	callloopmaxlen = 0.005
 	srgap = 0
 	cgexp = False
 	outdir = ''
@@ -92,6 +93,7 @@ class SystemValues:
 		'device_pm_callback_end',
 		'device_pm_callback_start'
 	]
+	logmsg = ''
 	testcommand = ''
 	mempath = '/dev/mem'
 	powerfile = '/sys/power/state'
@@ -117,19 +119,19 @@ class SystemValues:
 	usetracemarkers = True
 	usekprobes = True
 	usedevsrc = False
+	useprocmon = False
 	notestrun = False
+	mixedphaseheight = True
 	devprops = dict()
-	postresumetime = 0
+	predelay = 0
+	postdelay = 0
+	procexecfmt = 'ps - (?P<ps>.*)$'
 	devpropfmt = '# Device Properties: .*'
 	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>.*)$'
-	kprobecolor = 'rgba(204,204,204,0.5)'
-	synccolor = 'rgba(204,204,204,0.5)'
-	debugfuncs = []
 	tracefuncs = {
 		'sys_sync': dict(),
 		'pm_prepare_console': dict(),
@@ -152,44 +154,66 @@ class SystemValues:
 		'CPU_OFF': {
 			'func':'_cpu_down',
 			'args_x86_64': {'cpu':'%di:s32'},
-			'format': 'CPU_OFF[{cpu}]',
-			'mask': 'CPU_.*_DOWN'
+			'format': 'CPU_OFF[{cpu}]'
 		},
 		'CPU_ON': {
 			'func':'_cpu_up',
 			'args_x86_64': {'cpu':'%di:s32'},
-			'format': 'CPU_ON[{cpu}]',
-			'mask': 'CPU_.*_UP'
+			'format': 'CPU_ON[{cpu}]'
 		},
 	}
 	dev_tracefuncs = {
 		# general wait/delay/sleep
-		'msleep': { 'args_x86_64': {'time':'%di:s32'} },
-		'udelay': { 'func':'__const_udelay', 'args_x86_64': {'loops':'%di:s32'} },
-		'acpi_os_stall': dict(),
+		'msleep': { 'args_x86_64': {'time':'%di:s32'}, 'ub': 1 },
+		'schedule_timeout_uninterruptible': { 'args_x86_64': {'timeout':'%di:s32'}, 'ub': 1 },
+		'schedule_timeout': { 'args_x86_64': {'timeout':'%di:s32'}, 'ub': 1 },
+		'udelay': { 'func':'__const_udelay', 'args_x86_64': {'loops':'%di:s32'}, 'ub': 1 },
+		'usleep_range': { 'args_x86_64': {'min':'%di:s32', 'max':'%si:s32'}, 'ub': 1 },
+		'mutex_lock_slowpath': { 'func':'__mutex_lock_slowpath', 'ub': 1 },
+		'acpi_os_stall': {'ub': 1},
 		# ACPI
 		'acpi_resume_power_resources': dict(),
 		'acpi_ps_parse_aml': dict(),
 		# filesystem
 		'ext4_sync_fs': dict(),
+		# 80211
+		'iwlagn_mac_start': dict(),
+		'iwlagn_alloc_bcast_station': dict(),
+		'iwl_trans_pcie_start_hw': dict(),
+		'iwl_trans_pcie_start_fw': dict(),
+		'iwl_run_init_ucode': dict(),
+		'iwl_load_ucode_wait_alive': dict(),
+		'iwl_alive_start': dict(),
+		'iwlagn_mac_stop': dict(),
+		'iwlagn_mac_suspend': dict(),
+		'iwlagn_mac_resume': dict(),
+		'iwlagn_mac_add_interface': dict(),
+		'iwlagn_mac_remove_interface': dict(),
+		'iwlagn_mac_change_interface': dict(),
+		'iwlagn_mac_config': dict(),
+		'iwlagn_configure_filter': dict(),
+		'iwlagn_mac_hw_scan': dict(),
+		'iwlagn_bss_info_changed': dict(),
+		'iwlagn_mac_channel_switch': dict(),
+		'iwlagn_mac_flush': dict(),
 		# ATA
 		'ata_eh_recover': { 'args_x86_64': {'port':'+36(%di):s32'} },
 		# i915
-		'i915_gem_restore_gtt_mappings': dict(),
+		'i915_gem_resume': dict(),
+		'i915_restore_state': dict(),
 		'intel_opregion_setup': dict(),
+		'g4x_pre_enable_dp': dict(),
+		'vlv_pre_enable_dp': dict(),
+		'chv_pre_enable_dp': dict(),
+		'g4x_enable_dp': dict(),
+		'vlv_enable_dp': dict(),
+		'intel_hpd_init': dict(),
+		'intel_opregion_register': dict(),
 		'intel_dp_detect': dict(),
 		'intel_hdmi_detect': dict(),
 		'intel_opregion_init': dict(),
+		'intel_fbdev_set_suspend': dict(),
 	}
-	kprobes_postresume = [
-		{
-			'name': 'ataportrst',
-			'func': 'ata_eh_recover',
-			'args': {'port':'+36(%di):s32'},
-			'format': 'ata{port}_port_reset',
-			'mask': 'ata.*_port_reset'
-		}
-	]
 	kprobes = dict()
 	timeformat = '%.3f'
 	def __init__(self):
@@ -198,6 +222,7 @@ class SystemValues:
 			self.embedded = True
 			self.addlogs = True
 			self.htmlfile = os.environ['LOG_FILE']
+		self.archargs = 'args_'+platform.machine()
 		self.hostname = platform.node()
 		if(self.hostname == ''):
 			self.hostname = 'localhost'
@@ -214,6 +239,13 @@ class SystemValues:
 		if num < 0 or num > 6:
 			return
 		self.timeformat = '%.{0}f'.format(num)
+	def setOutputFolder(self, value):
+		args = dict()
+		n = datetime.now()
+		args['date'] = n.strftime('%y%m%d')
+		args['time'] = n.strftime('%H%M%S')
+		args['hostname'] = self.hostname
+		self.outdir = value.format(**args)
 	def setOutputFile(self):
 		if((self.htmlfile == '') and (self.dmesgfile != '')):
 			m = re.match('(?P<name>.*)_dmesg\.txt$', self.dmesgfile)
@@ -253,10 +285,14 @@ class SystemValues:
 			self.testdir+'/'+self.prefix+'_'+self.suspendmode+'.html'
 		if not os.path.isdir(self.testdir):
 			os.mkdir(self.testdir)
-	def setDeviceFilter(self, devnames):
-		self.devicefilter = string.split(devnames)
+	def setDeviceFilter(self, value):
+		self.devicefilter = []
+		if value:
+			value = value.split(',')
+		for i in value:
+			self.devicefilter.append(i.strip())
 	def rtcWakeAlarmOn(self):
-		os.system('echo 0 > '+self.rtcpath+'/wakealarm')
+		call('echo 0 > '+self.rtcpath+'/wakealarm', shell=True)
 		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)
@@ -272,12 +308,12 @@ class SystemValues:
 			# 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))
+		call('echo %d > %s/wakealarm' % (alarm, self.rtcpath), shell=True)
 	def rtcWakeAlarmOff(self):
-		os.system('echo 0 > %s/wakealarm' % self.rtcpath)
+		call('echo 0 > %s/wakealarm' % self.rtcpath, shell=True)
 	def initdmesg(self):
 		# get the latest time stamp from the dmesg log
-		fp = os.popen('dmesg')
+		fp = Popen('dmesg', stdout=PIPE).stdout
 		ktime = '0'
 		for line in fp:
 			line = line.replace('\r\n', '')
@@ -291,7 +327,7 @@ class SystemValues:
 		self.dmesgstart = float(ktime)
 	def getdmesg(self):
 		# store all new dmesg lines since initdmesg was called
-		fp = os.popen('dmesg')
+		fp = Popen('dmesg', stdout=PIPE).stdout
 		op = open(self.dmesgfile, 'a')
 		for line in fp:
 			line = line.replace('\r\n', '')
@@ -317,25 +353,18 @@ class SystemValues:
 	def getFtraceFilterFunctions(self, current):
 		rootCheck(True)
 		if not current:
-			os.system('cat '+self.tpath+'available_filter_functions')
+			call('cat '+self.tpath+'available_filter_functions', shell=True)
 			return
 		fp = open(self.tpath+'available_filter_functions')
 		master = fp.read().split('\n')
 		fp.close()
-		if len(self.debugfuncs) > 0:
-			for i in self.debugfuncs:
-				if i in master:
-					print i
-				else:
-					print self.colorText(i)
-		else:
-			for i in self.tracefuncs:
-				if 'func' in self.tracefuncs[i]:
-					i = self.tracefuncs[i]['func']
-				if i in master:
-					print i
-				else:
-					print self.colorText(i)
+		for i in self.tracefuncs:
+			if 'func' in self.tracefuncs[i]:
+				i = self.tracefuncs[i]['func']
+			if i in master:
+				print i
+			else:
+				print self.colorText(i)
 	def setFtraceFilterFunctions(self, list):
 		fp = open(self.tpath+'available_filter_functions')
 		master = fp.read().split('\n')
@@ -351,22 +380,15 @@ class SystemValues:
 		fp = open(self.tpath+'set_graph_function', 'w')
 		fp.write(flist)
 		fp.close()
-	def kprobeMatch(self, name, target):
-		if name not in self.kprobes:
-			return False
-		if re.match(self.kprobes[name]['mask'], target):
-			return True
-		return False
 	def basicKprobe(self, name):
-		self.kprobes[name] = {'name': name,'func': name,'args': dict(),'format': name,'mask': name}
+		self.kprobes[name] = {'name': name,'func': name,'args': dict(),'format': name}
 	def defaultKprobe(self, name, kdata):
 		k = kdata
-		for field in ['name', 'format', 'mask', 'func']:
+		for field in ['name', 'format', 'func']:
 			if field not in k:
 				k[field] = name
-		archargs = 'args_'+platform.machine()
-		if archargs in k:
-			k['args'] = k[archargs]
+		if self.archargs in k:
+			k['args'] = k[self.archargs]
 		else:
 			k['args'] = dict()
 			k['format'] = name
@@ -403,49 +425,80 @@ class SystemValues:
 		out = fmt.format(**arglist)
 		out = out.replace(' ', '_').replace('"', '')
 		return out
-	def kprobeText(self, kprobe):
-		name, fmt, func, args = kprobe['name'], kprobe['format'], kprobe['func'], kprobe['args']
+	def kprobeText(self, kname, kprobe):
+		name = fmt = func = kname
+		args = dict()
+		if 'name' in kprobe:
+			name = kprobe['name']
+		if 'format' in kprobe:
+			fmt = kprobe['format']
+		if 'func' in kprobe:
+			func = kprobe['func']
+		if self.archargs in kprobe:
+			args = kprobe[self.archargs]
+		if 'args' in kprobe:
+			args = kprobe['args']
 		if re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', func):
-			doError('Kprobe "%s" has format info in the function name "%s"' % (name, func), False)
+			doError('Kprobe "%s" has format info in the function name "%s"' % (name, func))
 		for arg in re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', fmt):
 			if arg not in args:
-				doError('Kprobe "%s" is missing argument "%s"' % (name, arg), False)
+				doError('Kprobe "%s" is missing argument "%s"' % (name, arg))
 		val = 'p:%s_cal %s' % (name, func)
 		for i in sorted(args):
 			val += ' %s=%s' % (i, args[i])
 		val += '\nr:%s_ret %s $retval\n' % (name, func)
 		return val
-	def addKprobes(self):
+	def addKprobes(self, output=False):
+		if len(sysvals.kprobes) < 1:
+			return
+		if output:
+			print('    kprobe functions in this kernel:')
 		# first test each kprobe
-		print('INITIALIZING KPROBES...')
 		rejects = []
+		# sort kprobes: trace, ub-dev, custom, dev
+		kpl = [[], [], [], []]
 		for name in sorted(self.kprobes):
-			if not self.testKprobe(self.kprobes[name]):
+			res = self.colorText('YES', 32)
+			if not self.testKprobe(name, self.kprobes[name]):
+				res = self.colorText('NO')
 				rejects.append(name)
+			else:
+				if name in self.tracefuncs:
+					kpl[0].append(name)
+				elif name in self.dev_tracefuncs:
+					if 'ub' in self.dev_tracefuncs[name]:
+						kpl[1].append(name)
+					else:
+						kpl[3].append(name)
+				else:
+					kpl[2].append(name)
+			if output:
+				print('         %s: %s' % (name, res))
+		kplist = kpl[0] + kpl[1] + kpl[2] + kpl[3]
 		# remove all failed ones from the list
 		for name in rejects:
-			vprint('Skipping KPROBE: %s' % name)
 			self.kprobes.pop(name)
+		# set the kprobes all at once
 		self.fsetVal('', 'kprobe_events')
 		kprobeevents = ''
-		# set the kprobes all at once
-		for kp in self.kprobes:
-			val = self.kprobeText(self.kprobes[kp])
-			vprint('Adding KPROBE: %s\n%s' % (kp, val.strip()))
-			kprobeevents += self.kprobeText(self.kprobes[kp])
+		for kp in kplist:
+			kprobeevents += self.kprobeText(kp, self.kprobes[kp])
 		self.fsetVal(kprobeevents, 'kprobe_events')
 		# verify that the kprobes were set as ordered
 		check = self.fgetVal('kprobe_events')
-		linesout = len(kprobeevents.split('\n'))
-		linesack = len(check.split('\n'))
-		if linesack < linesout:
-			# if not, try appending the kprobes 1 by 1
-			for kp in self.kprobes:
-				kprobeevents = self.kprobeText(self.kprobes[kp])
-				self.fsetVal(kprobeevents, 'kprobe_events', 'a')
+		linesout = len(kprobeevents.split('\n')) - 1
+		linesack = len(check.split('\n')) - 1
+		if output:
+			res = '%d/%d' % (linesack, linesout)
+			if linesack < linesout:
+				res = self.colorText(res, 31)
+			else:
+				res = self.colorText(res, 32)
+			print('    working kprobe functions enabled: %s' % res)
 		self.fsetVal('1', 'events/kprobes/enable')
-	def testKprobe(self, kprobe):
-		kprobeevents = self.kprobeText(kprobe)
+	def testKprobe(self, kname, kprobe):
+		self.fsetVal('0', 'events/kprobes/enable')
+		kprobeevents = self.kprobeText(kname, kprobe)
 		if not kprobeevents:
 			return False
 		try:
@@ -463,8 +516,9 @@ class SystemValues:
 		if not os.path.exists(file):
 			return False
 		try:
-			fp = open(file, mode)
+			fp = open(file, mode, 0)
 			fp.write(val)
+			fp.flush()
 			fp.close()
 		except:
 			pass
@@ -491,21 +545,17 @@ class SystemValues:
 		for name in self.dev_tracefuncs:
 			self.defaultKprobe(name, self.dev_tracefuncs[name])
 	def isCallgraphFunc(self, name):
-		if len(self.debugfuncs) < 1 and self.suspendmode == 'command':
-			return True
-		if name in self.debugfuncs:
+		if len(self.tracefuncs) < 1 and self.suspendmode == 'command':
 			return True
-		funclist = []
 		for i in self.tracefuncs:
 			if 'func' in self.tracefuncs[i]:
-				funclist.append(self.tracefuncs[i]['func'])
+				f = self.tracefuncs[i]['func']
 			else:
-				funclist.append(i)
-		if name in funclist:
-			return True
+				f = i
+			if name == f:
+				return True
 		return False
 	def initFtrace(self, testing=False):
-		tp = self.tpath
 		print('INITIALIZING FTRACE...')
 		# turn trace off
 		self.fsetVal('0', 'tracing_on')
@@ -518,18 +568,7 @@ class SystemValues:
 		# go no further if this is just a status check
 		if testing:
 			return
-		if self.usekprobes:
-			# add tracefunc kprobes so long as were not using full callgraph
-			if(not self.usecallgraph or len(self.debugfuncs) > 0):
-				for name in self.tracefuncs:
-					self.defaultKprobe(name, self.tracefuncs[name])
-				if self.usedevsrc:
-					for name in self.dev_tracefuncs:
-						self.defaultKprobe(name, self.dev_tracefuncs[name])
-			else:
-				self.usedevsrc = False
-			self.addKprobes()
-		# initialize the callgraph trace, unless this is an x2 run
+		# initialize the callgraph trace
 		if(self.usecallgraph):
 			# set trace type
 			self.fsetVal('function_graph', 'current_tracer')
@@ -545,20 +584,24 @@ class SystemValues:
 			self.fsetVal('context-info', 'trace_options')
 			self.fsetVal('graph-time', 'trace_options')
 			self.fsetVal('0', 'max_graph_depth')
-			if len(self.debugfuncs) > 0:
-				self.setFtraceFilterFunctions(self.debugfuncs)
-			elif self.suspendmode == 'command':
-				self.fsetVal('', 'set_graph_function')
-			else:
-				cf = ['dpm_run_callback']
-				if(self.usetraceeventsonly):
-					cf += ['dpm_prepare', 'dpm_complete']
-				for fn in self.tracefuncs:
-					if 'func' in self.tracefuncs[fn]:
-						cf.append(self.tracefuncs[fn]['func'])
-					else:
-						cf.append(fn)
-				self.setFtraceFilterFunctions(cf)
+			cf = ['dpm_run_callback']
+			if(self.usetraceeventsonly):
+				cf += ['dpm_prepare', 'dpm_complete']
+			for fn in self.tracefuncs:
+				if 'func' in self.tracefuncs[fn]:
+					cf.append(self.tracefuncs[fn]['func'])
+				else:
+					cf.append(fn)
+			self.setFtraceFilterFunctions(cf)
+		# initialize the kprobe trace
+		elif self.usekprobes:
+			for name in self.tracefuncs:
+				self.defaultKprobe(name, self.tracefuncs[name])
+			if self.usedevsrc:
+				for name in self.dev_tracefuncs:
+					self.defaultKprobe(name, self.dev_tracefuncs[name])
+			print('INITIALIZING KPROBES...')
+			self.addKprobes(self.verbose)
 		if(self.usetraceevents):
 			# turn trace events on
 			events = iter(self.traceevents)
@@ -590,10 +633,10 @@ class SystemValues:
 			if(os.path.exists(tp+f) == False):
 				return False
 		return True
-	def colorText(self, str):
+	def colorText(self, str, color=31):
 		if not self.ansi:
 			return str
-		return '\x1B[31;40m'+str+'\x1B[m'
+		return '\x1B[%d;40m%s\x1B[m' % (color, str)
 
 sysvals = SystemValues()
 
@@ -625,8 +668,8 @@ class DevProps:
 		if self.xtraclass:
 			return ' '+self.xtraclass
 		if self.async:
-			return ' async'
-		return ' sync'
+			return ' async_device'
+		return ' sync_device'
 
 # Class: DeviceNode
 # Description:
@@ -646,8 +689,6 @@ class DeviceNode:
 #	 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
@@ -658,7 +699,7 @@ class DeviceNode:
 #					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
+#						optionally includes dev/ps data
 #				}
 #			}
 #		}
@@ -671,19 +712,24 @@ class Data:
 	end = 0.0   # test end
 	tSuspended = 0.0 # low-level suspend start
 	tResumed = 0.0   # low-level resume start
+	tKernSus = 0.0   # kernel level suspend start
+	tKernRes = 0.0   # kernel level resume end
 	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
+	pstl = 0         # process timeline
 	testnumber = 0
 	idstr = ''
 	html_device_id = 0
 	stamp = 0
 	outfile = ''
-	dev_ubiquitous = ['msleep', 'udelay']
+	devpids = []
+	kerror = False
 	def __init__(self, num):
-		idchar = 'abcdefghijklmnopqrstuvwxyz'
+		idchar = 'abcdefghij'
+		self.pstl = dict()
 		self.testnumber = num
 		self.idstr = idchar[num]
 		self.dmesgtext = []
@@ -714,16 +760,39 @@ class Data:
 		self.devicegroups = []
 		for phase in self.phases:
 			self.devicegroups.append([phase])
-	def getStart(self):
-		return self.dmesg[self.phases[0]]['start']
+		self.errorinfo = {'suspend':[],'resume':[]}
+	def extractErrorInfo(self, dmesg):
+		error = ''
+		tm = 0.0
+		for i in range(len(dmesg)):
+			if 'Call Trace:' in dmesg[i]:
+				m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) .*', dmesg[i])
+				if not m:
+					continue
+				tm = float(m.group('ktime'))
+				if tm < self.start or tm > self.end:
+					continue
+				for j in range(i-10, i+1):
+					error += dmesg[j]
+				continue
+			if error:
+				m = re.match('[ \t]*\[ *[0-9\.]*\]  \[\<[0-9a-fA-F]*\>\] .*', dmesg[i])
+				if m:
+					error += dmesg[i]
+				else:
+					if tm < self.tSuspended:
+						dir = 'suspend'
+					else:
+						dir = 'resume'
+					error = error.replace('<', '&lt').replace('>', '&gt')
+					vprint('kernel error found in %s at %f' % (dir, tm))
+					self.errorinfo[dir].append((tm, error))
+					self.kerror = True
+					error = ''
 	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']
@@ -733,39 +802,67 @@ class Data:
 					time < d['end']):
 					return False
 		return True
-	def targetDevice(self, phaselist, start, end, pid=-1):
+	def sourcePhase(self, start):
+		for phase in self.phases:
+			pend = self.dmesg[phase]['end']
+			if start <= pend:
+				return phase
+		return 'resume_complete'
+	def sourceDevice(self, phaselist, start, end, pid, type):
 		tgtdev = ''
 		for phase in phaselist:
 			list = self.dmesg[phase]['list']
 			for devname in list:
 				dev = list[devname]
-				if(pid >= 0 and dev['pid'] != pid):
+				# pid must match
+				if dev['pid'] != pid:
 					continue
 				devS = dev['start']
 				devE = dev['end']
-				if(start < devS or start >= devE or end <= devS or end > devE):
-					continue
+				if type == 'device':
+					# device target event is entirely inside the source boundary
+					if(start < devS or start >= devE or end <= devS or end > devE):
+						continue
+				elif type == 'thread':
+					# thread target event will expand the source boundary
+					if start < devS:
+						dev['start'] = start
+					if end > devE:
+						dev['end'] = end
 				tgtdev = dev
 				break
 		return tgtdev
 	def addDeviceFunctionCall(self, displayname, kprobename, proc, pid, start, end, cdata, rdata):
-		machstart = self.dmesg['suspend_machine']['start']
-		machend = self.dmesg['resume_machine']['end']
-		tgtdev = self.targetDevice(self.phases, start, end, pid)
-		if not tgtdev and start >= machstart and end < machend:
-			# device calls in machine phases should be serial
-			tgtdev = self.targetDevice(['suspend_machine', 'resume_machine'], start, end)
+		# try to place the call in a device
+		tgtdev = self.sourceDevice(self.phases, start, end, pid, 'device')
+		# calls with device pids that occur outside device bounds are dropped
+		# TODO: include these somehow
+		if not tgtdev and pid in self.devpids:
+			return False
+		# try to place the call in a thread
 		if not tgtdev:
-			if 'scsi_eh' in proc:
-				self.newActionGlobal(proc, start, end, pid)
-				self.addDeviceFunctionCall(displayname, kprobename, proc, pid, start, end, cdata, rdata)
+			tgtdev = self.sourceDevice(self.phases, start, end, pid, 'thread')
+		# create new thread blocks, expand as new calls are found
+		if not tgtdev:
+			if proc == '<...>':
+				threadname = 'kthread-%d' % (pid)
 			else:
-				vprint('IGNORE: %s[%s](%d) [%f - %f] | %s | %s | %s' % (displayname, kprobename,
-					pid, start, end, cdata, rdata, proc))
+				threadname = '%s-%d' % (proc, pid)
+			tgtphase = self.sourcePhase(start)
+			self.newAction(tgtphase, threadname, pid, '', start, end, '', ' kth', '')
+			return self.addDeviceFunctionCall(displayname, kprobename, proc, pid, start, end, cdata, rdata)
+		# this should not happen
+		if not tgtdev:
+			vprint('[%f - %f] %s-%d %s %s %s' % \
+				(start, end, proc, pid, kprobename, cdata, rdata))
 			return False
-		# detail block fits within tgtdev
+		# place the call data inside the src element of the tgtdev
 		if('src' not in tgtdev):
 			tgtdev['src'] = []
+		dtf = sysvals.dev_tracefuncs
+		ubiquitous = False
+		if kprobename in dtf and 'ub' in dtf[kprobename]:
+			ubiquitous = True
 		title = cdata+' '+rdata
 		mstr = '\(.*\) *(?P<args>.*) *\((?P<caller>.*)\+.* arg1=(?P<ret>.*)'
 		m = re.match(mstr, title)
@@ -777,14 +874,81 @@ class Data:
 				r = ''
 			else:
 				r = 'ret=%s ' % r
-			l = '%0.3fms' % ((end - start) * 1000)
-			if kprobename in self.dev_ubiquitous:
-				title = '%s(%s) <- %s, %s(%s)' % (displayname, a, c, r, l)
-			else:
-				title = '%s(%s) %s(%s)' % (displayname, a, r, l)
-		e = TraceEvent(title, kprobename, start, end - start)
+			if ubiquitous and c in dtf and 'ub' in dtf[c]:
+				return False
+		color = sysvals.kprobeColor(kprobename)
+		e = DevFunction(displayname, a, c, r, start, end, ubiquitous, proc, pid, color)
 		tgtdev['src'].append(e)
 		return True
+	def overflowDevices(self):
+		# get a list of devices that extend beyond the end of this test run
+		devlist = []
+		for phase in self.phases:
+			list = self.dmesg[phase]['list']
+			for devname in list:
+				dev = list[devname]
+				if dev['end'] > self.end:
+					devlist.append(dev)
+		return devlist
+	def mergeOverlapDevices(self, devlist):
+		# merge any devices that overlap devlist
+		for dev in devlist:
+			devname = dev['name']
+			for phase in self.phases:
+				list = self.dmesg[phase]['list']
+				if devname not in list:
+					continue
+				tdev = list[devname]
+				o = min(dev['end'], tdev['end']) - max(dev['start'], tdev['start'])
+				if o <= 0:
+					continue
+				dev['end'] = tdev['end']
+				if 'src' not in dev or 'src' not in tdev:
+					continue
+				dev['src'] += tdev['src']
+				del list[devname]
+	def usurpTouchingThread(self, name, dev):
+		# the caller test has priority of this thread, give it to him
+		for phase in self.phases:
+			list = self.dmesg[phase]['list']
+			if name in list:
+				tdev = list[name]
+				if tdev['start'] - dev['end'] < 0.1:
+					dev['end'] = tdev['end']
+					if 'src' not in dev:
+						dev['src'] = []
+					if 'src' in tdev:
+						dev['src'] += tdev['src']
+					del list[name]
+				break
+	def stitchTouchingThreads(self, testlist):
+		# merge any threads between tests that touch
+		for phase in self.phases:
+			list = self.dmesg[phase]['list']
+			for devname in list:
+				dev = list[devname]
+				if 'htmlclass' not in dev or 'kth' not in dev['htmlclass']:
+					continue
+				for data in testlist:
+					data.usurpTouchingThread(devname, dev)
+	def optimizeDevSrc(self):
+		# merge any src call loops to reduce timeline size
+		for phase in self.phases:
+			list = self.dmesg[phase]['list']
+			for dev in list:
+				if 'src' not in list[dev]:
+					continue
+				src = list[dev]['src']
+				p = 0
+				for e in sorted(src, key=lambda event: event.time):
+					if not p or not e.repeat(p):
+						p = e
+						continue
+					# e is another iteration of p, move it into p
+					p.end = e.end
+					p.length = p.end - p.time
+					p.count += 1
+					src.remove(e)
 	def trimTimeVal(self, t, t0, dT, left):
 		if left:
 			if(t > t0):
@@ -804,6 +968,8 @@ class Data:
 		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.tKernSus = self.trimTimeVal(self.tKernSus, t0, dT, left)
+		self.tKernRes = self.trimTimeVal(self.tKernRes, t0, dT, left)
 		self.end = self.trimTimeVal(self.end, t0, dT, left)
 		for phase in self.phases:
 			p = self.dmesg[phase]
@@ -832,36 +998,6 @@ class Data:
 			else:
 				self.trimTime(self.tSuspended, \
 					self.tResumed-self.tSuspended, False)
-	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()
-		self.devicegroups.append([phasename])
 	def setPhase(self, phase, ktime, isbegin):
 		if(isbegin):
 			self.dmesg[phase]['start'] = ktime
@@ -881,7 +1017,7 @@ class Data:
 		for t in sorted(tmp):
 			slist.append(tmp[t])
 		return slist
-	def fixupInitcalls(self, phase, end):
+	def fixupInitcalls(self, phase):
 		# if any calls never returned, clip them at system resume end
 		phaselist = self.dmesg[phase]['list']
 		for devname in phaselist:
@@ -893,37 +1029,23 @@ class Data:
 						break
 				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):
+				keep = False
+				for filter in devicefilter:
+					if filter in name or \
+						('drv' in list[name] and filter in list[name]['drv']):
+						keep = True
+				if not keep:
 					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.getEnd())
-	def isInsideTimeline(self, start, end):
-		if(self.start <= start and self.end > start):
-			return True
-		return False
+			self.fixupInitcalls(phase)
 	def phaseOverlap(self, phases):
 		rmgroups = []
 		newgroup = []
@@ -940,30 +1062,35 @@ class Data:
 			self.devicegroups.remove(group)
 		self.devicegroups.append(newgroup)
 	def newActionGlobal(self, name, start, end, pid=-1, color=''):
-		# if event starts before timeline start, expand timeline
-		if(start < self.start):
-			self.setStart(start)
-		# if event ends after timeline end, expand the timeline
-		if(end > self.end):
-			self.setEnd(end)
-		# which phase is this device callback or action "in"
-		targetphase = "none"
+		# which phase is this device callback or action in
+		targetphase = 'none'
 		htmlclass = ''
 		overlap = 0.0
 		phases = []
 		for phase in self.phases:
 			pstart = self.dmesg[phase]['start']
 			pend = self.dmesg[phase]['end']
+			# see if the action overlaps this phase
 			o = max(0, min(end, pend) - max(start, pstart))
 			if o > 0:
 				phases.append(phase)
+			# set the target phase to the one that overlaps most
 			if o > overlap:
 				if overlap > 0 and phase == 'post_resume':
 					continue
 				targetphase = phase
 				overlap = o
+		# if no target phase was found, pin it to the edge
+		if targetphase == 'none':
+			p0start = self.dmesg[self.phases[0]]['start']
+			if start <= p0start:
+				targetphase = self.phases[0]
+			else:
+				targetphase = self.phases[-1]
 		if pid == -2:
 			htmlclass = ' bg'
+		elif pid == -3:
+			htmlclass = ' ps'
 		if len(phases) > 1:
 			htmlclass = ' bg'
 			self.phaseOverlap(phases)
@@ -985,29 +1112,13 @@ class Data:
 			while(name in list):
 				name = '%s[%d]' % (origname, i)
 				i += 1
-		list[name] = {'start': start, 'end': end, 'pid': pid, 'par': parent,
-					  'length': length, 'row': 0, 'id': devid, 'drv': drv }
+		list[name] = {'name': name, 'start': start, 'end': end, 'pid': pid,
+			'par': parent, 'length': length, 'row': 0, 'id': devid, 'drv': drv }
 		if htmlclass:
 			list[name]['htmlclass'] = htmlclass
 		if color:
 			list[name]['color'] = color
 		return name
-	def deviceIDs(self, devlist, phase):
-		idlist = []
-		list = self.dmesg[phase]['list']