diff options
| -rwxr-xr-x | scripts/analyze_suspend.py | 591 |
1 files changed, 272 insertions, 319 deletions
diff --git a/scripts/analyze_suspend.py b/scripts/analyze_suspend.py index 01268593b7e3..383df79a13a6 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 @@ -77,11 +72,13 @@ from subprocess import call, Popen, PIPE # store system values and test parameters class SystemValues: ansi = False - version = '4.4' + 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 @@ -96,6 +93,7 @@ class SystemValues: 'device_pm_callback_end', 'device_pm_callback_start' ] + logmsg = '' testcommand = '' mempath = '/dev/mem' powerfile = '/sys/power/state' @@ -166,18 +164,38 @@ class SystemValues: } dev_tracefuncs = { # general wait/delay/sleep - 'msleep': { 'args_x86_64': {'time':'%di:s32'} }, - 'schedule_timeout_uninterruptible': { 'args_x86_64': {'timeout':'%di:s32'} }, - 'schedule_timeout': { 'args_x86_64': {'timeout':'%di:s32'} }, - 'udelay': { 'func':'__const_udelay', 'args_x86_64': {'loops':'%di:s32'} }, - 'usleep_range': { 'args_x86_64': {'min':'%di:s32', 'max':'%si:s32'} }, - 'mutex_lock_slowpath': { 'func':'__mutex_lock_slowpath' }, - '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 @@ -196,14 +214,6 @@ class SystemValues: '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' - } - ] kprobes = dict() timeformat = '%.3f' def __init__(self): @@ -429,45 +439,65 @@ class SystemValues: 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): + 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(kp, self.kprobes[kp]) - vprint('Adding KPROBE: %s\n%s' % (kp, val.strip())) + 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(kp, 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, kname, kprobe): + self.fsetVal('0', 'events/kprobes/enable') kprobeevents = self.kprobeText(kname, kprobe) if not kprobeevents: return False @@ -486,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 @@ -525,7 +556,6 @@ class SystemValues: return True return False def initFtrace(self, testing=False): - tp = self.tpath print('INITIALIZING FTRACE...') # turn trace off self.fsetVal('0', 'tracing_on') @@ -570,7 +600,8 @@ class SystemValues: if self.usedevsrc: for name in self.dev_tracefuncs: self.defaultKprobe(name, self.dev_tracefuncs[name]) - self.addKprobes() + print('INITIALIZING KPROBES...') + self.addKprobes(self.verbose) if(self.usetraceevents): # turn trace events on events = iter(self.traceevents) @@ -602,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() @@ -658,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 @@ -670,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 # } # } # } @@ -697,16 +726,9 @@ class Data: stamp = 0 outfile = '' devpids = [] - dev_ubiquitous = [ - 'msleep', - 'schedule_timeout_uninterruptible', - 'schedule_timeout', - 'udelay', - 'usleep_range', - 'mutex_lock_slowpath' - ] + kerror = False def __init__(self, num): - idchar = 'abcdefghijklmnopqrstuvwxyz' + idchar = 'abcdefghij' self.pstl = dict() self.testnumber = num self.idstr = idchar[num] @@ -738,6 +760,35 @@ class Data: self.devicegroups = [] for phase in self.phases: self.devicegroups.append([phase]) + 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('<', '<').replace('>', '>') + 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 def setEnd(self, time): @@ -751,9 +802,8 @@ class Data: time < d['end']): return False return True - def sourcePhase(self, start, end): + def sourcePhase(self, start): for phase in self.phases: - pstart = self.dmesg[phase]['start'] pend = self.dmesg[phase]['end'] if start <= pend: return phase @@ -798,7 +848,7 @@ class Data: threadname = 'kthread-%d' % (pid) else: threadname = '%s-%d' % (proc, pid) - tgtphase = self.sourcePhase(start, end) + 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 @@ -809,8 +859,9 @@ class Data: # 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 self.dev_ubiquitous: + if kprobename in dtf and 'ub' in dtf[kprobename]: ubiquitous = True title = cdata+' '+rdata mstr = '\(.*\) *(?P<args>.*) *\((?P<caller>.*)\+.* arg1=(?P<ret>.*)' @@ -823,7 +874,7 @@ class Data: r = '' else: r = 'ret=%s ' % r - if ubiquitous and c in self.dev_ubiquitous: + 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) @@ -917,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] @@ -964,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: @@ -976,8 +1029,6 @@ class Data: break vprint('%s (%s): callback didnt return' % (devname, phase)) def deviceFilter(self, devicefilter): - # check each device name & driver name - # remove it if it does not include one of the filter strings for phase in self.phases: list = self.dmesg[phase]['list'] rmlist = [] @@ -994,7 +1045,7 @@ class Data: def fixupInitcallsThatDidntReturn(self): # if any calls never returned, clip them at system resume end for phase in self.phases: - self.fixupInitcalls(phase, self.end) + self.fixupInitcalls(phase) def phaseOverlap(self, phases): rmgroups = [] newgroup = [] @@ -1068,22 +1119,6 @@ class Data: if color: list[name]['color'] = color return name - 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'] @@ -1091,15 +1126,6 @@ class Data: 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('Timeline Details:') vprint(' test start: %f' % self.start) @@ -1418,7 +1444,6 @@ class FTraceLine: print('%s -- %f (%02d): %s() { (%.3f us)' % (dev, self.time, \ self.depth, self.name, self.length*1000000)) def startMarker(self): - global sysvals # Is this the starting line of a suspend? if not self.fevent: return False @@ -1721,8 +1746,9 @@ class Timeline: rows = 0 # total timeline rows rowlines = dict() rowheight = dict() - def __init__(self, rowheight): + def __init__(self, rowheight, scaleheight): self.rowH = rowheight + self.scaleH = scaleheight self.html = { 'header': '', 'timeline': '', @@ -1921,7 +1947,6 @@ class Timeline: # A list of values describing the properties of these test runs class TestProps: stamp = '' - tracertype = '' S0i3 = False fwdata = [] ftrace_line_fmt_fg = \ @@ -1939,14 +1964,13 @@ class TestProps: def __init__(self): self.ktemp = dict() def setTracerType(self, tracer): - self.tracertype = tracer if(tracer == 'function_graph'): self.cgformat = True self.ftrace_line_fmt = self.ftrace_line_fmt_fg elif(tracer == 'nop'): self.ftrace_line_fmt = self.ftrace_line_fmt_nop else: - doError('Invalid tracer format: [%s]' % tracer, False) + doError('Invalid tracer format: [%s]' % tracer) # Class: TestRun # Description: @@ -1995,7 +2019,6 @@ class ProcessMonitor: out += '%s-%s %d' % (val['name'], pid, jiffies) return 'ps - '+out def processMonitor(self, tid): - global sysvals while self.running: out = self.procstat() if out: @@ -2015,7 +2038,7 @@ class ProcessMonitor: # Arguments: # msg: the debug/log message to print def vprint(msg): - global sysvals + sysvals.logmsg += msg+'\n' if(sysvals.verbose): print(msg) @@ -2026,8 +2049,6 @@ def vprint(msg): # Arguments: # m: the valid re.match output for the stamp line def parseStamp(line, data): - global sysvals - m = re.match(sysvals.stampfmt, line) data.stamp = {'time': '', 'host': '', 'mode': ''} dt = datetime(int(m.group('y'))+2000, int(m.group('m')), @@ -2076,8 +2097,6 @@ def diffStamp(stamp1, stamp2): # required for primary parsing. Set the usetraceevents and/or # usetraceeventsonly flags in the global sysvals object def doesTraceLogHaveTraceEvents(): - global sysvals - # check for kprobes sysvals.usekprobes = False out = call('grep -q "_cal: (" '+sysvals.ftracefile, shell=True) @@ -2120,8 +2139,6 @@ def doesTraceLogHaveTraceEvents(): # Arguments: # testruns: the array of Data objects obtained from parseKernelLog def appendIncompleteTraceLog(testruns): - global sysvals - # create TestRun vessels for ftrace parsing testcnt = len(testruns) testidx = 0 @@ -2312,8 +2329,7 @@ def appendIncompleteTraceLog(testruns): dev['ftrace'] = cg break - if(sysvals.verbose): - test.data.printDetails() + test.data.printDetails() # Function: parseTraceLog # Description: @@ -2324,11 +2340,9 @@ def appendIncompleteTraceLog(testruns): # Output: # An array of Data objects def parseTraceLog(): - global sysvals - vprint('Analyzing the ftrace data...') if(os.path.exists(sysvals.ftracefile) == False): - doError('%s does not exist' % sysvals.ftracefile, False) + doError('%s does not exist' % sysvals.ftracefile) sysvals.setupAllKprobes() tracewatch = [] @@ -2398,10 +2412,6 @@ def parseTraceLog(): testrun = TestRun(data) testruns.append(testrun) parseStamp(tp.stamp, data) - if sysvals.suspendmode == 'mem' and len(tp.fwdata) > data.testnumber: - data.fwSuspend, data.fwResume = tp.fwdata[data.testnumber] - if(data.fwSuspend > 0 or data.fwResume > 0): - data.fwValid = True data.setStart(t.time) data.tKernSus = t.time continue @@ -2427,6 +2437,11 @@ def parseTraceLog(): data.tKernRes = t.time if data.dmesg['resume_complete']['end'] < 0: data.dmesg['resume_complete']['end'] = t.time + if sysvals.suspendmode == 'mem' and len(tp.fwdata) > data.testnumber: + data.fwSuspend, data.fwResume = tp.fwdata[data.testnumber] + if(data.tSuspended != 0 and data.tResumed != 0 and \ + (data.fwSuspend > 0 or data.fwResume > 0)): + data.fwValid = True if(not sysvals.usetracemarkers): # no trace markers? then quit and be sure to finish recording # the event we used to trigger resume end @@ -2713,9 +2728,8 @@ def parseTraceLog(): cg.newActionFromFunction(data) if sysvals.suspendmode == 'command': - if(sysvals.verbose): - for data in testdata: - data.printDetails() + for data in testdata: + data.printDetails() return testdata # fill in any missing phases @@ -2723,7 +2737,7 @@ def parseTraceLog(): lp = data.phases[0] for p in data.phases: if(data.dmesg[p]['start'] < 0 and data.dmesg[p]['end'] < 0): - print('WARNING: phase "%s" is missing!' % p) + vprint('WARNING: phase "%s" is missing!' % p) if(data.dmesg[p]['start'] < 0): data.dmesg[p]['start'] = data.dmesg[lp]['end'] if(p == 'resume_machine'): @@ -2732,6 +2746,8 @@ def parseTraceLog(): data.tLow = 0 if(data.dmesg[p]['end'] < 0): data.dmesg[p]['end'] = data.dmesg[p]['start'] + if(p != lp and not ('machine' in p and 'machine' in lp)): + data.dmesg[lp]['end'] = data.dmesg[p]['start'] lp = p if(len(sysvals.devicefilter) > 0): @@ -2739,8 +2755,7 @@ def parseTraceLog(): data.fixupInitcallsThatDidntReturn() if sysvals.usedevsrc: data.optimizeDevSrc() - if sysvals.verbose: - data.printDetails() + data.printDetails() # x2: merge any overlapping devices between test runs if sysvals.usedevsrc and len(testdata) > 1: @@ -2752,50 +2767,6 @@ def parseTraceLog(): testdata[0].stitchTouchingThreads(testdata[1:]) return testdata -# Function: loadRawKernelLog -# Description: -# Load a raw kernel log that wasn't created by this tool, it might be -# possible to extract a valid suspend/resume log -def loadRawKernelLog(dmesgfile): - global sysvals - - stamp = {'time': '', 'host': '', 'mode': 'mem', 'kernel': ''} - stamp['time'] = datetime.now().strftime('%B %d %Y, %I:%M:%S %p') - stamp['host'] = sysvals.hostname - - testruns = [] - data = 0 - lf = open(dmesgfile, 'r') - for line in lf: - line = line.replace('\r\n', '') - idx = line.find('[') - if idx > 1: - line = line[idx:] - m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line) - if(not m): - continue - msg = m.group("msg") - m = re.match('PM: Syncing filesystems.*', msg) - if(m): - if(data): - testruns.append(data) - data = Data(len(testruns)) - data.stamp = stamp - if(data): - m = re.match('.* *(?P<k>[0-9]\.[0-9]{2}\.[0-9]-.*) .*', msg) - if(m): - stamp['kernel'] = m.group('k') - m = re.match('PM: Preparing system for (?P<m>.*) sleep', msg) - if(m): - stamp['mode'] = m.group('m') - data.dmesgtext.append(line) - if(data): - testruns.append(data) - sysvals.stamp = stamp - sysvals.suspendmode = stamp['mode'] - lf.close() - return testruns - # Function: loadKernelLog # Description: # [deprecated for kernel 3.15.0 or newer] @@ -2803,15 +2774,16 @@ def loadRawKernelLog(dmesgfile): # The dmesg filename is taken from sysvals # Output: # An array of empty Data objects with only their dmesgtext attributes set -def loadKernelLog(): - global sysvals - +def loadKernelLog(justtext=False): vprint('Analyzing the dmesg data...') if(os.path.exists(sysvals.dmesgfile) == False): - doError('%s does not exist' % sysvals.dmesgfile, False) + doError('%s does not exist' % sysvals.dmesgfile) + if justtext: + dmesgtext = [] # there can be multiple test runs in a single file tp = TestProps() + tp.stamp = datetime.now().strftime('# suspend-%m%d%y-%H%M%S localhost mem unknown') testruns = [] data = 0 lf = open(sysvals.dmesgfile, 'r') @@ -2832,6 +2804,9 @@ def loadKernelLog(): if(not m): continue msg = m.group("msg") + if justtext: + dmesgtext.append(line) + continue if(re.match('PM: Syncing filesystems.*', msg)): if(data): testruns.append(data) @@ -2841,24 +2816,24 @@ def loadKernelLog(): data.fwSuspend, data.fwResume = tp.fwdata[data.testnumber] if(data.fwSuspend > 0 or data.fwResume > 0): data.fwValid = True - if(re.match('ACPI: resume from mwait', msg)): - print('NOTE: This suspend appears to be freeze rather than'+\ - ' %s, it will be treated as such' % sysvals.suspendmode) - sysvals.suspendmode = 'freeze' if(not data): continue + m = re.match('.* *(?P<k>[0-9]\.[0-9]{2}\.[0-9]-.*) .*', msg) + if(m): + sysvals.stamp['kernel'] = m.group('k') + m = re.match('PM: Preparing system for (?P<m>.*) sleep', msg) + if(m): + sysvals.stamp['mode'] = sysvals.suspendmode = m.group('m') data.dmesgtext.append(line) - if(data): - testruns.append(data) lf.close() - if(len(testruns) < 1): - # bad log, but see if you can extract something meaningful anyway - testruns = loadRawKernelLog(sysvals.dmesgfile) - - if(len(testruns) < 1): - doError(' dmesg log is completely unreadable: %s' \ - % sysvals.dmesgfile, False) + if justtext: + return dmesgtext + if data: + testruns.append(data) + if len(testruns) < 1: + doError(' dmesg log has no suspend/resume data: %s' \ + % sysvals.dmesgfile) # fix lines with same timestamp/function with the call and return swapped for data in testruns: @@ -2890,8 +2865,6 @@ def loadKernelLog(): # Output: # The filled Data object def parseKernelLog(data): - global sysvals - phase = 'suspend_runtime' if(data.fwValid): @@ -2949,7 +2922,6 @@ def parseKernelLog(data): prevktime = -1.0 actions = dict() for line in data.dmesgtext: - # -- preprocessing -- # parse each dmesg line into the time and message m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line) if(m): @@ -2957,8 +2929,6 @@ def parseKernelLog(data): try: ktime = float(val) except: - doWarning('INVALID DMESG LINE: '+\ - line.replace('\n', ''), 'dmesg') continue msg = m.group('msg') # initialize data start to first line time @@ -2976,12 +2946,12 @@ def parseKernelLog(data): phase = 'resume_noirq' data.dmesg[phase]['start'] = ktime - # -- phase changes -- # suspend start if(re.match(dm['suspend_prepare'], msg)): phase = 'suspend_prepare' data.dmesg[phase]['start'] = ktime data.setStart(ktime) + data.tKernSus = ktime # suspend start elif(re.match(dm['suspend'], msg)): data.dmesg['suspend_prepare']['end'] = ktime @@ -3038,7 +3008,7 @@ def parseKernelLog(data): elif(re.match(dm['post_resume'], msg)): data.dmesg['resume_complete']['end'] = ktime data.setEnd(ktime) - phase = 'post_resume' + data.tKernRes = ktime break # -- device callbacks -- @@ -3065,7 +3035,6 @@ def parseKernelLog(data): dev['length'] = int(t) dev['end'] = ktime - # -- non-devicecallback actions -- # if trace events are not available, these are better than nothing if(not sysvals.usetraceevents): # look for known actions @@ -3125,8 +3094,7 @@ def parseKernelLog(data): for event in actions[name]: data.newActionGlobal(name, event['begin'], event['end']) - if(sysvals.verbose): - data.printDetails() + data.printDetails() if(len(sysvals.devicefilter) > 0): data.deviceFilter(sysvals.devicefilter) data.fixupInitcallsThatDidntReturn() @@ -3138,8 +3106,6 @@ def parseKernelLog(data): # Arguments: # testruns: array of Data objects from parseTraceLog def createHTMLSummarySimple(testruns, htmlfile): - global sysvals - # print out the basic summary of all the tests hf = open(htmlfile, 'w') @@ -3264,7 +3230,6 @@ def createHTMLSummarySimple(testruns, htmlfile): hf.close() def htmlTitle(): - global sysvals modename = { 'freeze': 'Freeze (S0)', 'standby': 'Standby (S1)', @@ -3297,13 +3262,14 @@ def ordinal(value): # Output: # True if the html file was created, false if it failed def createHTML(testruns): - global sysvals - if len(testruns) < 1: print('ERROR: Not enough test data to build a timeline') return + kerror = False for data in testruns: + if data.kerror: + kerror = True data.normalizeTime(testruns[-1].tSuspended) x2changes = ['', 'absolute'] @@ -3318,6 +3284,7 @@ def createHTML(testruns): html_timeline = '<div id="dmesgzoombox" class="zoombox">\n<div id="{0}" class="timeline" style="height:{1}px">\n' html_tblock = '<div id="block{0}" class="tblock" style="left:{1}%;width:{2}%;"><div class="tback" style="height:{3}px"></div>\n' html_device = '<div id="{0}" title="{1}" class="thread{7}" style="left:{2}%;top:{3}px;height:{4}px;width:{5}%;{8}">{6}</div>\n' + html_error = '<div id="{1}" title="kernel error/warning" class="err" style="right:{0}%">ERROR→</div>\n' html_traceevent = '<div title="{0}" class="traceevent{6}" style="left:{1}%;top:{2}px;height:{3}px;width:{4}%;line-height:{3}px;{7}">{5}</div>\n' html_cpuexec = '<div class="jiffie" style="left:{0}%;top:{1}px;height:{2}px;width:{3}%;background:{4};"></div>\n' html_phase = '<div class="phase" style="left:{0}%;width:{1}%;top:{2}px;height:{3}px;background-color:{4}">{5}</div>\n' @@ -3347,11 +3314,16 @@ def createHTML(testruns): hoverZ = 'z-index:8;' if sysvals.usedevsrc: hoverZ = '' + scaleH = 20 + scaleTH = 20 + if kerror: + scaleH = 40 + scaleTH = 60 # device timeline vprint('Creating Device Timeline...') - devtl = Timeline(30) + devtl = Timeline(30, scaleH) # Generate the header for this timeline for data in testruns: @@ -3415,7 +3387,6 @@ def createHTML(testruns): # time scale for potentially multiple datasets t0 = testruns[0].start tMax = testruns[-1].end - tSuspended = testruns[-1].tSuspended tTotal = tMax - t0 # determine the maximum number of rows we need to draw @@ -3507,6 +3478,11 @@ def createHTML(testruns): devtl.html['timeline'] += html_phase.format(left, width, \ '%.3f'%devtl.scaleH, '%.3f'%devtl.bodyH, \ data.dmesg[b]['color'], '') + for e in data.errorinfo[dir]: + # draw red lines for any kernel errors found + t, err = e + right = '%f' % (((mMax-t)*100.0)/mTotal) + devtl.html['timeline'] += html_error.format(right, err) for b in sorted(phases[dir]): # draw the devices for this phase phaselist = data.dmesg[b]['list'] @@ -3623,8 +3599,7 @@ def createHTML(testruns): t2 {color:black;font:25px Times;}\n\ t3 {color:black;font:20px Times;white-space:nowrap;}\n\ t4 {color:black;font:bold 30px Times;line-height:60px;white-space:nowrap;}\n\ - cS {color:blue;font:bold 11px Times;}\n\ - cR {color:red;font:bold 11px Times;}\n\ + cS {font:bold 13px Times;}\n\ table {width:100%;}\n\ .gray {background-color:rgba(80,80,80,0.1);}\n\ .green {background-color:rgba(204,255,204,0.4);}\n\ @@ -3655,7 +3630,8 @@ def createHTML(testruns): .traceevent:hover {color:white;font-weight:bold;border:1px solid white;}\n\ .phase {position:absolute;overflow:hidden;border:0px;text-align:center;}\n\ .phaselet {position:absolute;overflow:hidden;border:0px;text-align:center;height:100px;font-size:24px;}\n\ - .t {position:absolute;pointer-events:none;top:0%;height:100%;border-right:1px solid black;z-index:6;}\n\ + .t {position:absolute;line-height:'+('%d'%scaleTH)+'px;pointer-events:none;top:0;height:100%;border-right:1px solid black;z-index:6;}\n\ + .err {position:absolute;top:0%;height:100%;border-right:3px solid red;color:red;font:bold 14px Times;line-height:18px;}\n\ .legend {position:relative; width:100%; height:40px; text-align:center;margin-bottom:20px}\n\ .legend .square {position:absolute;cursor:pointer;top:10px; width:0px;height:20px;border:1px solid;padding-left:20px;}\n\ button {height:40px;width:200px;margin-bottom:20px;margin-top:20px;font-size:24px;}\n\ @@ -3683,6 +3659,8 @@ def createHTML(testruns): # write the test title and general info header if(sysvals.stamp['time'] != ""): hf.write(headline_version) + if sysvals.logmsg: + hf.write('<button id="showtest" class="logbtn">log</button>') if sysvals.addlogs and sysvals.dmesgfile: hf.write('<button id="showdmesg" class="logbtn">dmesg</button>') if sysvals.addlogs and sysvals.ftracefile: @@ -3718,7 +3696,10 @@ def createHTML(testruns): hf.write('</div>\n') # write the ftrace data (callgraph) - data = testruns[-1] + if sysvals.cgtest >= 0 and len(testruns) > sysvals.cgtest: + data = testruns[sysvals.cgtest] + else: + data = testruns[-1] if(sysvals.usecallgraph and not sysvals.embedded): hf.write('<section id="callgraphs" class="callgraph">\n') # write out the ftrace data converted to html @@ -3728,6 +3709,8 @@ def createHTML(testruns): html_func_leaf = '<article>{0} {1}</article>\n' num = 0 for p in data.phases: + if sysvals.cgphase and p != sysvals.cgphase: + continue list = data.dmesg[p]['list'] for devname in data.sortedDevices(p): if('ftrace' not in list[devname]): @@ -3765,11 +3748,15 @@ def createHTML(testruns): hf.write(html_func_end) hf.write('\n\n </section>\n') + # add the test log as a hidden div + if sysvals.logmsg: + hf.write('<div id="testlog" style="display:none;">\n'+sysvals.logmsg+'</div>\n') # add the dmesg log as a hidden div if sysvals.addlogs and sysvals.dmesgfile: hf.write('<div id="dmesglog" style="display:none;">\n') lf = open(sysvals.dmesgfile, 'r') for line in lf: + line = line.replace('<', '<').replace('>', '>') hf.write(line) lf.close() hf.write('</div>\n') @@ -3822,7 +3809,7 @@ def addScriptCode(hf, testruns): ' var resolution = -1;\n'\ ' var dragval = [0, 0];\n'\ ' function redrawTimescale(t0, tMax, tS) {\n'\ - ' var rline = \'<div class="t" style="left:0;border-left:1px solid black;border-right:0;"><cR><-R</cR></div>\';\n'\ + ' var rline = \'<div class="t" style="left:0;border-left:1px solid black;border-right:0;"><cS>←R</cS></div>\';\n'\ ' var tTotal = tMax - t0;\n'\ ' var list = document.getElementsByClassName("tblock");\n'\ ' for (var i = 0; i < list.length; i++) {\n'\ @@ -3847,7 +3834,7 @@ def addScriptCode(hf, testruns): ' pos = 100 - (((j)*tS*100)/mTotal) - divEdge;\n'\ ' val = (j-divTotal+1)*tS;\n'\ ' if(j == divTotal - 1)\n'\ - ' htmlline = \'<div class="t" style="right:\'+pos+\'%"><cS>S-></cS></div>\';\n'\ + ' htmlline = \'<div class="t" style="right:\'+pos+\'%"><cS>S→</cS></div>\';\n'\ ' else\n'\ ' htmlline = \'<div class="t" style="right:\'+pos+\'%">\'+val+\'ms</div>\';\n'\ ' }\n'\ @@ -4027,12 +4014,7 @@ def addScriptCode(hf, testruns): ' }\n'\ ' }\n'\ ' function devListWindow(e) {\n'\ - ' var sx = e.clientX;\n'\ - ' if(sx > window.innerWidth - 440)\n'\ - ' sx = window.innerWidth - 440;\n'\ - ' var cfg="top="+e.screenY+", left="+sx+", width=440, height=720, scrollbars=yes";\n'\ - ' var win = window.open("", "_blank", cfg);\n'\ - ' if(window.chrome) win.moveBy(sx, 0);\n'\ + ' var win = window.open();\n'\ ' var html = "<title>"+e.target.innerHTML+"</title>"+\n'\ ' "<style type=\\"text/css\\">"+\n'\ ' " ul {list-style-type:circle;padding-left:10px;margin-left:10px;}"+\n'\ @@ -4042,6 +4024,12 @@ def addScriptCode(hf, testruns): ' dt = devtable[1];\n'\ ' win.document.write(html+dt);\n'\ ' }\n'\ + ' function errWindow() {\n'\ + ' var text = this.id;\n'\ + ' var win = window.open();\n'\ + ' win.document.write("<pre>"+text+"</pre>");\n'\ + ' win.document.close();\n'\ + ' }\n'\ ' function logWindow(e) {\n'\ ' var name = e.target.id.slice(4);\n'\ ' var win = window.open();\n'\ @@ -4089,6 +4077,9 @@ def addScriptCode(hf, testruns): ' var list = document.getElementsByClassName("square");\n'\ ' for (var i = 0; i < list.length; i++)\n'\ ' list[i].onclick = onClickPhase;\n'\ + ' var list = document.getElementsByClassName("err");\n'\ + ' for (var i = 0; i < list.length; i++)\n'\ + ' list[i].onclick = errWindow;\n'\ ' var list = document.getElementsByClassName("logbtn");\n'\ ' for (var i = 0; i < list.length; i++)\n'\ ' list[i].onclick = logWindow;\n'\ @@ -4111,8 +4102,6 @@ def addScriptCode(hf, testruns): # Execute system suspend through the sysfs interface, then copy the output # dmesg and ftrace files to the test output directory. def executeSuspend(): - global sysvals - pm = ProcessMonitor() tp = sysvals.tpath fwdata = [] @@ -4128,7 +4117,9 @@ def executeSuspend(): for count in range(1,sysvals.execcount+1): # x2delay in between test runs if(count > 1 and sysvals.x2delay > 0): + sysvals.fsetVal('WAIT %d' % sysvals.x2delay, 'trace_marker') time.sleep(sysvals.x2delay/1000.0) + sysvals.fsetVal('WAIT END', 'trace_marker') # start message if sysvals.testcommand != '': print('COMMAND START') @@ -4146,7 +4137,9 @@ def executeSuspend(): sysvals.fsetVal('SUSPEND START', 'trace_marker') # predelay delay if(count == 1 and sysvals.predelay > 0): + sysvals.fsetVal('WAIT %d' % sysvals.predelay, 'trace_marker') time.sleep(sysvals.predelay/1000.0) + sysvals.fsetVal('WAIT END', 'trace_marker') # initiate suspend or command if sysvals.testcommand != '': call(sysvals.testcommand+' 2>&1', shell=True); @@ -4162,7 +4155,9 @@ def executeSuspend(): sysvals.rtcWakeAlarmOff() # postdelay delay if(count == sysvals.execcount and sysvals.postdelay > 0): + sysvals.fsetVal('WAIT %d' % sysvals.postdelay, 'trace_marker') time.sleep(sysvals.postdelay/1000.0) + sysvals.fsetVal('WAIT END', 'trace_marker') # return from suspend print('RESUME COMPLETE') if(sysvals.usecallgraph or sysvals.usetraceevents): @@ -4185,8 +4180,6 @@ def executeSuspend(): sysvals.getdmesg() def writeDatafileHeader(filename, fwdata): - global sysvals - fp = open(filename, 'a') fp.write(sysvals.teststamp+'\n') if(sysvals.suspendmode == 'mem' or sysvals.suspendmode == 'command'): @@ -4202,8 +4195,6 @@ def writeDatafileHeader(filename, fwdata): # to always-on since the kernel cant determine if the device can # properly autosuspend def setUSBDevicesAuto(): - global sysvals - rootCheck(True) for dirname, dirnames, filenames in os.walk('/sys/devices'): if(re.match('.*/usb[0-9]*.*', dirname) and @@ -4250,8 +4241,6 @@ def ms2nice(val): # Detect all the USB hosts and devices currently connected and add # a list of USB device names to sysvals for better timeline readability def detectUSB(): - global sysvals - field = {'idVendor':'', 'idProduct':'', 'product':'', 'speed':''} power = {'async':'', 'autosuspend':'', 'autosuspend_delay_ms':'', 'control':'', 'persist':'', 'runtime_enabled':'', @@ -4306,7 +4295,6 @@ def detectUSB(): # Description: # Retrieve a list of properties for all devices in the trace log def devProps(data=0): - global sysvals props = dict() if data: @@ -4331,7 +4319,7 @@ def devProps(data=0): return if(os.path.exists(sysvals.ftracefile) == False): - doError('%s does not exist' % sysvals.ftracefile, False) + doError('%s does not exist' % sysvals.ftracefile) # first get the list of devices we need properties for msghead = 'Additional data added by AnalyzeSuspend' @@ -4354,7 +4342,7 @@ def devProps(data=0): m = re.match('.*: (?P<drv>.*) (?P<d>.*), parent: *(?P<p>.*), .*', m.group('msg')); if(not m): continue - drv, dev, par = m.group('drv'), m.group('d'), m.group('p') + dev = m.group('d') if dev not in props: props[dev] = DevProps() tf.close() @@ -4430,7 +4418,6 @@ def devProps(data=0): # Output: # A string list of the available modes def getModes(): - global sysvals modes = '' if(os.path.exists(sysvals.powerfile)): fp = open(sysvals.powerfile, 'r') @@ -4444,8 +4431,6 @@ def getModes(): # Arguments: # output: True to output the info to stdout, False otherwise def getFPDT(output): - global sysvals - rectype = {} rectype[0] = 'Firmware Basic Boot Performance Record' rectype[1] = 'S3 Performance Table Record' @@ -4456,19 +4441,19 @@ def getFPDT(output): rootCheck(True) if(not os.path.exists(sysvals.fpdtpath)): if(output): - doError('file does not exist: %s' % sysvals.fpdtpath, False) + doError('file does not exist: %s' % sysvals.fpdtpath) return False if(not os.access(sysvals.fpdtpath, os.R_OK)): if(output): - doError('file is not readable: %s' % sysvals.fpdtpath, False) + doError('file is not readable: %s' % sysvals.fpdtpath) return False if(not os.path.exists(sysvals.mempath)): if(output): - doError('file does not exist: %s' % sysvals.mempath, False) + doError('file does not exist: %s' % sysvals.mempath) return False if(not os.access(sysvals.mempath, os.R_OK)): if(output): - doError('file is not readable: %s' % sysvals.mempath, False) + doError('file is not readable: %s' % sysvals.mempath) return False fp = open(sysvals.fpdtpath, 'rb') @@ -4478,7 +4463,7 @@ def getFPDT(output): if(len(buf) < 36): if(output): doError('Invalid FPDT table data, should '+\ - 'be at least 36 bytes', False) + 'be at least 36 bytes') return False table = struct.unpack('4sIBB6s8sI4sI', buf[0:36]) @@ -4577,7 +4562,6 @@ def getFPDT(output): # Output: # True if the test will work, False if not def statusCheck(probecheck=False): - global sysvals status = True print('Checking this system (%s)...' % platform.node()) @@ -4661,20 +4645,13 @@ def statusCheck(probecheck=False): return status # verify kprobes - if sysvals.usekprobes and len(sysvals.tracefuncs) > 0: - print(' verifying timeline kprobes work:') - for name in sorted(sysvals.tracefuncs): - res = sysvals.colorText('NO') - if sysvals.testKprobe(name, sysvals.tracefuncs[name]): - res = 'YES' - print(' %s: %s' % (name, res)) - if sysvals.usedevsrc and sysvals.usekprobes and len(sysvals.dev_tracefuncs) > 0: - print(' verifying dev kprobes work:') - for name in sorted(sysvals.dev_tracefuncs): - res = sysvals.colorText('NO') - if sysvals.testKprobe(name, sysvals.dev_tracefuncs[name]): - res = 'YES' - print(' %s: %s' % (name, res)) + if sysvals.usekprobes: + for name in sysvals.tracefuncs: + sysvals.defaultKprobe(name, sysvals.tracefuncs[name]) + if sysvals.usedevsrc: + for name in sysvals.dev_tracefuncs: + sysvals.defaultKprobe(name, sysvals.dev_tracefuncs[name]) + sysvals.addKprobes(True) return status @@ -4684,33 +4661,20 @@ def statusCheck(probecheck=False): # Arguments: # msg: the error message to print # help: True if printHelp should be called after, False otherwise -def doError(msg, help): +def doError(msg, help=False): if(help == True): printHelp() print('ERROR: %s\n') % msg sys.exit() -# Function: doWarning -# Description: -# generic warning function for non-catastrophic anomalies -# Arguments: -# msg: the warning message to print -# file: If not empty, a filename to request be sent to the owner for debug -def doWarning(msg, file=''): - print('/* %s */') % msg - if(file): - print('/* For a fix, please send this'+\ - ' %s file to <todd.e.brandt@intel.com> */' % file) - # Function: rootCheck # Description: # quick check to see if we have root access def rootCheck(fatal): - global sysvals if(os.access(sysvals.powerfile, os.W_OK)): return True if fatal: - doError('This command must be run as root', False) + doError('This command must be run as root') return False # Function: getArgInt @@ -4751,66 +4715,51 @@ def getArgFloat(name, args, min, max, main=True): doError(name+': value should be between %f and %f' % (min, max), True) return val -# Function: rerunTest -# Description: -# generate an output from an existing set of ftrace/dmesg logs -def rerunTest(): - global sysvals - - if(sysvals.ftracefile != ''): - doesTraceLogHaveTraceEvents() - if(sysvals.dmesgfile == '' and not sysvals.usetraceeventsonly): - doError('recreating this html output '+\ - 'requires a dmesg file', False) - sysvals.setOutputFile() - vprint('Output file: %s' % sysvals.htmlfile) - if(os.path.exists(sysvals.htmlfile) and not os.access(sysvals.htmlfile, os.W_OK)): - doError('missing permission to write to %s' % sysvals.htmlfile, False) +def processData(): print('PROCESSING DATA') if(sysvals.usetraceeventsonly): testruns = parseTraceLog() + if sysvals.dmesgfile: + dmesgtext = loadKernelLog(True) + for data in testruns: + data.extractErrorInfo(dmesgtext) else: testruns = loadKernelLog() for data in testruns: parseKernelLog(data) - if(sysvals.ftracefile != ''): + if(sysvals.ftracefile and (sysvals.usecallgraph or sysvals.usetraceevents)): appendIncompleteTraceLog(testruns) createHTML(testruns) +# Function: rerunTest +# Description: +# generate an output from an existing set of ftrace/dmesg logs +def rerunTest(): + if sysvals.ftracefile: + doesTraceLogHaveTraceEvents() + if not sysvals.dmesgfile and not sysvals.usetraceeventsonly: + doError('recreating this html output requires a dmesg file') + sysvals.setOutputFile() + vprint('Output file: %s' % sysvals.htmlfile) + if(os.path.exists(sysvals.htmlfile) and not os.access(sysvals.htmlfile, os.W_OK)): + doError('missing permission to write to %s' % sysvals.htmlfile) + processData() + # Function: runTest # Description: # execute a suspend/resume, gather the logs, and generate the output def runTest(subdir, testpath=''): - global sysvals - # prepare for the test sysvals.initFtrace() sysvals.initTestOutput(subdir, testpath) - - vprint('Output files:\n %s' % sysvals.dmesgfile) - if(sysvals.usecallgraph or - sysvals.usetraceevents or - sysvals.usetraceeventsonly): - vprint(' %s' % sysvals.ftracefile) - vprint(' %s' % sysvals.htmlfile) + vprint('Output files:\n\t%s\n\t%s\n\t%s' % \ + (sysvals.dmesgfile, sysvals.ftracefile, sysvals.htmlfile)) # execute the test executeSuspend() sysvals.cleanupFtrace() + processData() - # analyze the data and create the html output - print('PROCESSING DATA') - if(sysvals.usetraceeventsonly): - # data for kernels 3.15 or newer is entirely in ftrace - testruns = parseTraceLog() - else: - # data for kernels older than 3.15 is primarily in dmesg - testruns = loadKernelLog() - for data in testruns: - parseKernelLog(data) - if(sysvals.usecallgraph or sysvals.usetraceevents): - appendIncompleteTraceLog(testruns) - createHTML(testruns) # if running as root, change output dir owner to sudo_user if os.path.isdir(sysvals.testdir) and os.getuid() == 0 and \ 'SUDO_USER' in os.environ: @@ -4821,8 +4770,6 @@ def runTest(subdir, testpath=''): # Description: # create a summary of tests in a sub-directory def runSummary(subdir, output): - global sysvals - # get a list of ftrace output files files = [] for dirname, dirnames, filenames in os.walk(subdir): @@ -4878,7 +4825,6 @@ def checkArgBool(value): # Description: # Configure the script via the info in a config file def configFromFile(file): - global sysvals Config = ConfigParser.ConfigParser() Config.read(file) @@ -4939,15 +4885,13 @@ def configFromFile(file): sysvals.setOutputFolder(value) if sysvals.suspendmode == 'command' and not sysvals.testcommand: - doError('No command supplied for mode "command"', False) + doError('No command supplied for mode "command"') # compatibility errors if sysvals.usedevsrc and sysvals.usecallgraph: - doError('-dev is not compatible with -f', False) - if sysvals.usecallgraph and sysvals.execcount > 1: - doError('-x2 is not compatible with -f', False) + doError('-dev is not compatible with -f') if sysvals.usecallgraph and sysvals.useprocmon: - doError('-proc is not compatible with -f', False) + doError('-proc is not compatible with -f') if overridekprobes: sysvals.tracefuncs = dict() @@ -4964,7 +4908,7 @@ def configFromFile(file): if kprobesec in sections: for name in Config.options(kprobesec): if name in kprobes: - doError('Duplicate timeline function found "%s"' % (name), False) + doError('Duplicate timeline function found "%s"' % (name)) text = Config.get(kprobesec, name) kprobes[name] = (text, False) @@ -4997,12 +4941,12 @@ def configFromFile(file): args[d[0]] = d[1] i += 1 if not function or not format: - doError('Invalid kprobe: %s' % name, False) + doError('Invalid kprobe: %s' % name) for arg in re.findall('{(?P<n>[a-z,A-Z,0-9]*)}', format): if arg not in args: - doError('Kprobe "%s" is missing argument "%s"' % (name, arg), False) + doError('Kprobe "%s" is missing argument "%s"' % (name, arg)) if (dev and name in sysvals.dev_tracefuncs) or (not dev and name in sysvals.tracefuncs): - doError('Duplicate timeline function found "%s"' % (name), False) + doError('Duplicate timeline function found "%s"' % (name)) kp = { 'name': name, @@ -5021,7 +4965,6 @@ def configFromFile(file): # Description: # print out the help text def printHelp(): - global sysvals modes = getModes() print('') @@ -5074,6 +5017,8 @@ def printHelp(): print(' -fadd file Add functions to be graphed in the timeline from a list in a text file') print(' -filter "d1,d2,..." Filter out all but this comma-delimited list of device names') print(' -mincg ms Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)') + print(' -cgphase P Only show callgraph data for phase P (e.g. suspend_late)') + print(' -cgtest N Only show callgraph data for test N (e.g. 0 or 1 in an x2 run)') print(' -timeprec N Number of significant digits in timestamps (0:S, [3:ms], 6:us)') print(' [utilities]') print(' -fpdt Print out the contents of the ACPI Firmware Performance Data Table') @@ -5139,6 +5084,17 @@ if __name__ == '__main__': sysvals.mindevlen = getArgFloat('-mindev', args, 0.0, 10000.0) elif(arg == '-mincg'): sysvals.mincglen = getArgFloat('-mincg', args, 0.0, 10000.0) + elif(arg == '-cgtest'): + sysvals.cgtest = getArgInt('-cgtest', args, 0, 1) + elif(arg == '-cgphase'): + try: + val = args.next() + except: + doError('No phase name supplied', True) + d = Data(0) + if val not in d.phases: + doError('Invalid phase, valid phaess are %s' % d.phases, True) + sysvals.cgphase = val elif(arg == '-callloop-maxgap'): sysvals.callloopmaxgap = getArgFloat('-callloop-maxgap', args, 0.0, 1.0) elif(arg == '-callloop-maxlen'): @@ -5170,7 +5126,7 @@ if __name__ == '__main__': except: doError('No text file supplied', True) if(os.path.exists(val) == False): - doError('%s does not exist' % val, False) + doError('%s does not exist' % val) configFromFile(val) elif(arg == '-fadd'): try: @@ -5178,7 +5134,7 @@ if __name__ == '__main__': except: doError('No text file supplied', True) if(os.path.exists(val) == False): - doError('%s does not exist' % val, False) + doError('%s does not exist' % val) sysvals.addFtraceFilterFunctions(val) elif(arg == '-dmesg'): try: @@ -5188,7 +5144,7 @@ if __name__ == '__main__': sysvals.notestrun = True sysvals.dmesgfile = val if(os.path.exists(sysvals.dmesgfile) == False): - doError('%s does not exist' % sysvals.dmesgfile, False) + doError('%s does not exist' % sysvals.dmesgfile) elif(arg == '-ftrace'): try: val = args.next() @@ -5197,7 +5153,7 @@ if __name__ == '__main__': sysvals.notestrun = True sysvals.ftracefile = val if(os.path.exists(sysvals.ftracefile) == False): - doError('%s does not exist' % sysvals.ftracefile, False) + doError('%s does not exist' % sysvals.ftracefile) elif(arg == '-summary'): try: val = args.next() @@ -5207,7 +5163,7 @@ if __name__ == '__main__': cmdarg = val sysvals.notestrun = True if(os.path.isdir(val) == False): - doError('%s is not accesible' % val, False) + doError('%s is not accesible' % val) elif(arg == '-filter'): try: val = args.next() @@ -5218,12 +5174,10 @@ if __name__ == '__main__': doError('Invalid argument: '+arg, True) # compatibility errors - if(sysvals.usecallgraph and sysvals.execcount > 1): - doError('-x2 is not compatible with -f', False) if(sysvals.usecallgraph and sysvals.usedevsrc): - doError('-dev is not compatible with -f', False) + doError('-dev is not compatible with -f') if(sysvals.usecallgraph and sysvals.useprocmon): - doError('-proc is not compatible with -f', False) + doError('-proc is not compatible with -f') # callgraph size cannot exceed device size if sysvals.mincglen < sysvals.mindevlen: @@ -5238,8 +5192,7 @@ if __name__ == '__main__': elif(cmd == 'usbtopo'): detectUSB() elif(cmd == 'modes'): - modes = getModes() - print modes + print getModes() elif(cmd == 'flist'): sysvals.getFtraceFilterFunctions(True) elif(cmd == 'flistall'): |