From 57f0f512b273f60d52568b8c6b77e17f5636edc0 Mon Sep 17 00:00:00 2001 From: André Fabian Silva Delgado Date: Wed, 5 Aug 2015 17:04:01 -0300 Subject: Initial import --- scripts/analyze_suspend.py | 3591 ++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 3591 insertions(+) create mode 100755 scripts/analyze_suspend.py (limited to 'scripts/analyze_suspend.py') diff --git a/scripts/analyze_suspend.py b/scripts/analyze_suspend.py new file mode 100755 index 000000000..93e1fd40f --- /dev/null +++ b/scripts/analyze_suspend.py @@ -0,0 +1,3591 @@ +#!/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 +# +# 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.*)' + firmwarefmt = '# fwsuspend (?P[0-9]*) fwresume (?P[0-9]*)$' + postresumefmt = '# post resume time (?P[0-9]*)$' + stampfmt = '# suspend-(?P[0-9]{2})(?P[0-9]{2})(?P[0-9]{2})-'+\ + '(?P[0-9]{2})(?P[0-9]{2})(?P[0-9]{2})'+\ + ' (?P.*) (?P.*) (?P.*)$' + 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.*)_dmesg\.txt$', self.dmesgfile) + if(m): + self.htmlfile = m.group('name')+'.html' + if((self.htmlfile == '') and (self.ftracefile != '')): + m = re.match('(?P.*)_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[0-9]*)-(?P[0-9]*)-(?P[0-9]*)', outD) + mT = re.match('^(?P[0-9]*):(?P[0-9]*):(?P[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): + idlist = [] + 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 = '' + list = self.dmesg[phase]['list'] + if devname in list: + pdev = list[devname]['par'] + if pdev in list: + return list[pdev]['id'] + return pdev + def deviceChildren(self, devname, phase): + devlist = [] + 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 += ('
  • %s: %.3fms
  • ' % (phase, (e-s)*1000)) + html += '
  • '+node.name+drv+'' + if info: + html += '
      '+info+'
    ' + html += '
  • ' + if len(node.children) > 0: + html += '
      ' + for cnode in node.children: + html += self.printTopology(cnode) + html += '
    ' + 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 + fcall = False + freturn = False + fevent = False + depth = 0 + name = '' + type = '' + def __init__(self, t, m, d): + self.time = float(t) + # is this a trace event + if(d == 'traceevent' or re.match('^ *\/\* *(?P.*) \*\/ *$', m)): + if(d == 'traceevent'): + # nop format trace event + msg = m + else: + # function_graph format trace event + em = re.match('^ *\/\* *(?P.*) \*\/ *$', m) + msg = em.group('msg') + + emm = re.match('^(?P.*?): (?P.*)', 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('^(?P *)(?P.*)$', m) + if(not match): + return + self.depth = self.getDepth(match.group('d')) + m = match.group('o') + # function return + if(m[0] == '}'): + self.freturn = True + if(len(m) > 1): + # includes comment with function name + match = re.match('^} *\/\* *(?P.*) *\*\/$', m) + if(match): + self.name = match.group('n') + # function call + else: + self.fcall = True + # function call with children + if(m[-1] == '{'): + match = re.match('^(?P.*) *\(.*', m) + if(match): + self.name = match.group('n') + # function call with no children (leaf) + elif(m[-1] == ';'): + self.freturn = True + match = re.match('^(?P.*) *\(.*', m) + if(match): + self.name = match.group('n') + # something else (possibly a trace marker) + else: + self.name = m + def getDepth(self, str): + return len(str)/2 + 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 + list = [] + invalid = False + depth = 0 + def __init__(self): + self.start = -1.0 + self.end = -1.0 + self.list = [] + self.depth = 0 + def setDepth(self, line): + if(line.fcall and not line.freturn): + line.depth = self.depth + self.depth += 1 + elif(line.freturn and not line.fcall): + self.depth -= 1 + line.depth = self.depth + else: + line.depth = self.depth + def addLine(self, line, match): + if(not self.invalid): + self.setDepth(line) + if(line.depth == 0 and line.freturn): + 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): + 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 + for l in self.list: + if(l.fcall and not l.freturn): + stack[l.depth] = l + cnt += 1 + elif(l.freturn and not l.fcall): + if(l.depth not in stack): + return False + stack[l.depth].length = l.length + stack[l.depth] = 0 + l.length = 0 + cnt -= 1 + if(cnt == 0): + return True + return False + def debugPrint(self, filename): + if(filename == 'stdout'): + print('[%f - %f]') % (self.start, self.end) + for l in self.list: + if(l.freturn and l.fcall): + print('%f (%02d): %s(); (%.3f us)' % (l.time, \ + l.depth, l.name, l.length*1000000)) + elif(l.freturn): + print('%f (%02d): %s} (%.3f us)' % (l.time, \ + l.depth, l.name, l.length*1000000)) + else: + print('%f (%02d): %s() { (%.3f us)' % (l.time, \ + l.depth, l.name, l.length*1000000)) + print(' ') + else: + fp = open(filename, 'w') + print(filename) + for l in self.list: + if(l.freturn and l.fcall): + fp.write('%f (%02d): %s(); (%.3f us)\n' % (l.time, \ + l.depth, l.name, l.length*1000000)) + elif(l.freturn): + fp.write('%f (%02d): %s} (%.3f us)\n' % (l.time, \ + l.depth, l.name, l.length*1000000)) + else: + fp.write('%f (%02d): %s() { (%.3f us)\n' % (l.time, \ + l.depth, l.name, l.length*1000000)) + fp.close() + +# Class: Timeline +# 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 row as a percent of the timeline height + rowH = 0.0 # height of each row in percent of the timeline height + row_height_pixels = 30 + maxrows = 0 + height = 0 + def __init__(self): + self.html = { + 'timeline': '', + 'legend': '', + 'scale': '' + } + def setRows(self, rows): + self.maxrows = int(rows) + self.scaleH = 100.0/float(self.maxrows) + self.height = self.maxrows*self.row_height_pixels + r = float(self.maxrows - 1) + if(r < 1.0): + r = 1.0 + self.rowH = (100.0 - self.scaleH)/r + +# 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