#!/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## 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 sysimport timeimport osimport stringimport reimport platformfrom datetime import datetimeimport struct # ----------------- CLASSES -------------------- # Class: SystemValues# Description:# A global, single-instance container used to# store system values and test parametersclass SystemValues: 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('(?P<name>.*)_dmesg\.txt$', self.dmesgfile) if(m): 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, 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: 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': '#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': '#FF9900', 'order': 6}, 'resume_early': {'list': dict(), 'start': -1.0, 'end': -1.0, '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 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: p = self.dmesg[phase] 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'] = 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 = self.trimTimeVal(cg.start, t0, dT, left) cg.end = self.trimTimeVal(cg.end, t0, dT, left) for line in cg.list: 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): 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 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.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, 'drv': drv } def deviceIDs(self, devlist, phase):Lines 1–500 of 3591. Load more
#!/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 # # 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 platform from datetime import datetime import struct # ----------------- CLASSES -------------------- # Class: SystemValues # Description: # A global, single-instance container used to # store system values and test parameters class SystemValues: 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('(?P<name>.*)_dmesg\.txt$', self.dmesgfile) if(m): 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, 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: 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': '#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': '#FF9900', 'order': 6}, 'resume_early': {'list': dict(), 'start': -1.0, 'end': -1.0, '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 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: p = self.dmesg[phase] 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'] = 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 = self.trimTimeVal(cg.start, t0, dT, left) cg.end = self.trimTimeVal(cg.end, t0, dT, left) for line in cg.list: 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): 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 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.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, 'drv': drv } def deviceIDs(self, devlist, phase):