diff options
-rw-r--r-- | drivers/base/power/domain.c | 4 | ||||
-rw-r--r-- | drivers/cpufreq/intel_pstate.c | 133 | ||||
-rw-r--r-- | kernel/power/hibernate.c | 2 | ||||
-rw-r--r-- | tools/power/pm-graph/README | 12 | ||||
-rw-r--r-- | tools/power/pm-graph/sleepgraph.8 | 3 | ||||
-rwxr-xr-x | tools/power/pm-graph/sleepgraph.py | 225 |
6 files changed, 170 insertions, 209 deletions
diff --git a/drivers/base/power/domain.c b/drivers/base/power/domain.c index ead135c7044c..6471b559230e 100644 --- a/drivers/base/power/domain.c +++ b/drivers/base/power/domain.c @@ -2952,6 +2952,10 @@ static int genpd_iterate_idle_states(struct device_node *dn, np = it.node; if (!of_match_node(idle_state_match, np)) continue; + + if (!of_device_is_available(np)) + continue; + if (states) { ret = genpd_parse_state(&states[i], np); if (ret) { diff --git a/drivers/cpufreq/intel_pstate.c b/drivers/cpufreq/intel_pstate.c index fc3ebeb0bbe5..6ff73c30769f 100644 --- a/drivers/cpufreq/intel_pstate.c +++ b/drivers/cpufreq/intel_pstate.c @@ -27,6 +27,7 @@ #include <linux/pm_qos.h> #include <trace/events/power.h> +#include <asm/cpu.h> #include <asm/div64.h> #include <asm/msr.h> #include <asm/cpu_device_id.h> @@ -280,10 +281,10 @@ static struct cpudata **all_cpu_data; * structure is used to store those callbacks. */ struct pstate_funcs { - int (*get_max)(void); - int (*get_max_physical)(void); - int (*get_min)(void); - int (*get_turbo)(void); + int (*get_max)(int cpu); + int (*get_max_physical)(int cpu); + int (*get_min)(int cpu); + int (*get_turbo)(int cpu); int (*get_scaling)(void); int (*get_cpu_scaling)(int cpu); int (*get_aperf_mperf_shift)(void); @@ -398,16 +399,6 @@ static int intel_pstate_get_cppc_guaranteed(int cpu) return cppc_perf.nominal_perf; } - -static u32 intel_pstate_cppc_nominal(int cpu) -{ - u64 nominal_perf; - - if (cppc_get_nominal_perf(cpu, &nominal_perf)) - return 0; - - return nominal_perf; -} #else /* CONFIG_ACPI_CPPC_LIB */ static inline void intel_pstate_set_itmt_prio(int cpu) { @@ -531,35 +522,18 @@ static void intel_pstate_hybrid_hwp_adjust(struct cpudata *cpu) { int perf_ctl_max_phys = cpu->pstate.max_pstate_physical; int perf_ctl_scaling = cpu->pstate.perf_ctl_scaling; - int perf_ctl_turbo = pstate_funcs.get_turbo(); - int turbo_freq = perf_ctl_turbo * perf_ctl_scaling; + int perf_ctl_turbo = pstate_funcs.get_turbo(cpu->cpu); int scaling = cpu->pstate.scaling; pr_debug("CPU%d: perf_ctl_max_phys = %d\n", cpu->cpu, perf_ctl_max_phys); - pr_debug("CPU%d: perf_ctl_max = %d\n", cpu->cpu, pstate_funcs.get_max()); pr_debug("CPU%d: perf_ctl_turbo = %d\n", cpu->cpu, perf_ctl_turbo); pr_debug("CPU%d: perf_ctl_scaling = %d\n", cpu->cpu, perf_ctl_scaling); pr_debug("CPU%d: HWP_CAP guaranteed = %d\n", cpu->cpu, cpu->pstate.max_pstate); pr_debug("CPU%d: HWP_CAP highest = %d\n", cpu->cpu, cpu->pstate.turbo_pstate); pr_debug("CPU%d: HWP-to-frequency scaling factor: %d\n", cpu->cpu, scaling); - /* - * If the product of the HWP performance scaling factor and the HWP_CAP - * highest performance is greater than the maximum turbo frequency - * corresponding to the pstate_funcs.get_turbo() return value, the - * scaling factor is too high, so recompute it to make the HWP_CAP - * highest performance correspond to the maximum turbo frequency. - */ - cpu->pstate.turbo_freq = cpu->pstate.turbo_pstate * scaling; - if (turbo_freq < cpu->pstate.turbo_freq) { - cpu->pstate.turbo_freq = turbo_freq; - scaling = DIV_ROUND_UP(turbo_freq, cpu->pstate.turbo_pstate); - cpu->pstate.scaling = scaling; - - pr_debug("CPU%d: refined HWP-to-frequency scaling factor: %d\n", - cpu->cpu, scaling); - } - + cpu->pstate.turbo_freq = rounddown(cpu->pstate.turbo_pstate * scaling, + perf_ctl_scaling); cpu->pstate.max_freq = rounddown(cpu->pstate.max_pstate * scaling, perf_ctl_scaling); @@ -1740,7 +1714,7 @@ static void intel_pstate_hwp_enable(struct cpudata *cpudata) intel_pstate_update_epp_defaults(cpudata); } -static int atom_get_min_pstate(void) +static int atom_get_min_pstate(int not_used) { u64 value; @@ -1748,7 +1722,7 @@ static int atom_get_min_pstate(void) return (value >> 8) & 0x7F; } -static int atom_get_max_pstate(void) +static int atom_get_max_pstate(int not_used) { u64 value; @@ -1756,7 +1730,7 @@ static int atom_get_max_pstate(void) return (value >> 16) & 0x7F; } -static int atom_get_turbo_pstate(void) +static int atom_get_turbo_pstate(int not_used) { u64 value; @@ -1834,23 +1808,23 @@ static void atom_get_vid(struct cpudata *cpudata) cpudata->vid.turbo = value & 0x7f; } -static int core_get_min_pstate(void) +static int core_get_min_pstate(int cpu) { u64 value; - rdmsrl(MSR_PLATFORM_INFO, value); + rdmsrl_on_cpu(cpu, MSR_PLATFORM_INFO, &value); return (value >> 40) & 0xFF; } -static int core_get_max_pstate_physical(void) +static int core_get_max_pstate_physical(int cpu) { u64 value; - rdmsrl(MSR_PLATFORM_INFO, value); + rdmsrl_on_cpu(cpu, MSR_PLATFORM_INFO, &value); return (value >> 8) & 0xFF; } -static int core_get_tdp_ratio(u64 plat_info) +static int core_get_tdp_ratio(int cpu, u64 plat_info) { /* Check how many TDP levels present */ if (plat_info & 0x600000000) { @@ -1860,13 +1834,13 @@ static int core_get_tdp_ratio(u64 plat_info) int err; /* Get the TDP level (0, 1, 2) to get ratios */ - err = rdmsrl_safe(MSR_CONFIG_TDP_CONTROL, &tdp_ctrl); + err = rdmsrl_safe_on_cpu(cpu, MSR_CONFIG_TDP_CONTROL, &tdp_ctrl); if (err) return err; /* TDP MSR are continuous starting at 0x648 */ tdp_msr = MSR_CONFIG_TDP_NOMINAL + (tdp_ctrl & 0x03); - err = rdmsrl_safe(tdp_msr, &tdp_ratio); + err = rdmsrl_safe_on_cpu(cpu, tdp_msr, &tdp_ratio); if (err) return err; @@ -1883,7 +1857,7 @@ static int core_get_tdp_ratio(u64 plat_info) return -ENXIO; } -static int core_get_max_pstate(void) +static int core_get_max_pstate(int cpu) { u64 tar; u64 plat_info; @@ -1891,10 +1865,10 @@ static int core_get_max_pstate(void) int tdp_ratio; int err; - rdmsrl(MSR_PLATFORM_INFO, plat_info); + rdmsrl_on_cpu(cpu, MSR_PLATFORM_INFO, &plat_info); max_pstate = (plat_info >> 8) & 0xFF; - tdp_ratio = core_get_tdp_ratio(plat_info); + tdp_ratio = core_get_tdp_ratio(cpu, plat_info); if (tdp_ratio <= 0) return max_pstate; @@ -1903,7 +1877,7 @@ static int core_get_max_pstate(void) return tdp_ratio; } - err = rdmsrl_safe(MSR_TURBO_ACTIVATION_RATIO, &tar); + err = rdmsrl_safe_on_cpu(cpu, MSR_TURBO_ACTIVATION_RATIO, &tar); if (!err) { int tar_levels; @@ -1918,13 +1892,13 @@ static int core_get_max_pstate(void) return max_pstate; } -static int core_get_turbo_pstate(void) +static int core_get_turbo_pstate(int cpu) { u64 value; int nont, ret; - rdmsrl(MSR_TURBO_RATIO_LIMIT, value); - nont = core_get_max_pstate(); + rdmsrl_on_cpu(cpu, MSR_TURBO_RATIO_LIMIT, &value); + nont = core_get_max_pstate(cpu); ret = (value) & 255; if (ret <= nont) ret = nont; @@ -1952,50 +1926,37 @@ static int knl_get_aperf_mperf_shift(void) return 10; } -static int knl_get_turbo_pstate(void) +static int knl_get_turbo_pstate(int cpu) { u64 value; int nont, ret; - rdmsrl(MSR_TURBO_RATIO_LIMIT, value); - nont = core_get_max_pstate(); + rdmsrl_on_cpu(cpu, MSR_TURBO_RATIO_LIMIT, &value); + nont = core_get_max_pstate(cpu); ret = (((value) >> 8) & 0xFF); if (ret <= nont) ret = nont; return ret; } -#ifdef CONFIG_ACPI_CPPC_LIB -static u32 hybrid_ref_perf; - -static int hybrid_get_cpu_scaling(int cpu) +static void hybrid_get_type(void *data) { - return DIV_ROUND_UP(core_get_scaling() * hybrid_ref_perf, - intel_pstate_cppc_nominal(cpu)); + u8 *cpu_type = data; + + *cpu_type = get_this_hybrid_cpu_type(); } -static void intel_pstate_cppc_set_cpu_scaling(void) +static int hybrid_get_cpu_scaling(int cpu) { - u32 min_nominal_perf = U32_MAX; - int cpu; + u8 cpu_type = 0; - for_each_present_cpu(cpu) { - u32 nominal_perf = intel_pstate_cppc_nominal(cpu); + smp_call_function_single(cpu, hybrid_get_type, &cpu_type, 1); + /* P-cores have a smaller perf level-to-freqency scaling factor. */ + if (cpu_type == 0x40) + return 78741; - if (nominal_perf && nominal_perf < min_nominal_perf) - min_nominal_perf = nominal_perf; - } - - if (min_nominal_perf < U32_MAX) { - hybrid_ref_perf = min_nominal_perf; - pstate_funcs.get_cpu_scaling = hybrid_get_cpu_scaling; - } + return core_get_scaling(); } -#else -static inline void intel_pstate_cppc_set_cpu_scaling(void) -{ -} -#endif /* CONFIG_ACPI_CPPC_LIB */ static void intel_pstate_set_pstate(struct cpudata *cpu, int pstate) { @@ -2025,10 +1986,10 @@ static void intel_pstate_max_within_limits(struct cpudata *cpu) static void intel_pstate_get_cpu_pstates(struct cpudata *cpu) { - int perf_ctl_max_phys = pstate_funcs.get_max_physical(); + int perf_ctl_max_phys = pstate_funcs.get_max_physical(cpu->cpu); int perf_ctl_scaling = pstate_funcs.get_scaling(); - cpu->pstate.min_pstate = pstate_funcs.get_min(); + cpu->pstate.min_pstate = pstate_funcs.get_min(cpu->cpu); cpu->pstate.max_pstate_physical = perf_ctl_max_phys; cpu->pstate.perf_ctl_scaling = perf_ctl_scaling; @@ -2044,8 +2005,8 @@ static void intel_pstate_get_cpu_pstates(struct cpudata *cpu) } } else { cpu->pstate.scaling = perf_ctl_scaling; - cpu->pstate.max_pstate = pstate_funcs.get_max(); - cpu->pstate.turbo_pstate = pstate_funcs.get_turbo(); + cpu->pstate.max_pstate = pstate_funcs.get_max(cpu->cpu); + cpu->pstate.turbo_pstate = pstate_funcs.get_turbo(cpu->cpu); } if (cpu->pstate.scaling == perf_ctl_scaling) { @@ -3221,9 +3182,9 @@ static unsigned int force_load __initdata; static int __init intel_pstate_msrs_not_valid(void) { - if (!pstate_funcs.get_max() || - !pstate_funcs.get_min() || - !pstate_funcs.get_turbo()) + if (!pstate_funcs.get_max(0) || + !pstate_funcs.get_min(0) || + !pstate_funcs.get_turbo(0)) return -ENODEV; return 0; @@ -3450,7 +3411,7 @@ static int __init intel_pstate_init(void) default_driver = &intel_pstate; if (boot_cpu_has(X86_FEATURE_HYBRID_CPU)) - intel_pstate_cppc_set_cpu_scaling(); + pstate_funcs.get_cpu_scaling = hybrid_get_cpu_scaling; goto hwp_cpu_matched; } diff --git a/kernel/power/hibernate.c b/kernel/power/hibernate.c index f58a0aa92310..793c55a2becb 100644 --- a/kernel/power/hibernate.c +++ b/kernel/power/hibernate.c @@ -645,7 +645,7 @@ static void power_down(void) int error; if (hibernation_mode == HIBERNATION_SUSPEND) { - error = suspend_devices_and_enter(PM_SUSPEND_MEM); + error = suspend_devices_and_enter(mem_sleep_current); if (error) { hibernation_mode = hibernation_ops ? HIBERNATION_PLATFORM : diff --git a/tools/power/pm-graph/README b/tools/power/pm-graph/README index e6020c0d59ec..3213dbe63b74 100644 --- a/tools/power/pm-graph/README +++ b/tools/power/pm-graph/README @@ -6,22 +6,22 @@ |_| |___/ |_| pm-graph: suspend/resume/boot timing analysis tools - Version: 5.9 + Version: 5.10 Author: Todd Brandt <todd.e.brandt@intel.com> - Home Page: https://01.org/pm-graph + Home Page: https://www.intel.com/content/www/us/en/developer/topic-technology/open/pm-graph/overview.html Report bugs/issues at bugzilla.kernel.org Tools/pm-graph - https://bugzilla.kernel.org/buglist.cgi?component=pm-graph&product=Tools Full documentation available online & in man pages - Getting Started: - https://01.org/pm-graph/documentation/getting-started + https://www.intel.com/content/www/us/en/developer/articles/technical/usage.html - - Config File Format: - https://01.org/pm-graph/documentation/3-config-file-format + - Feature Summary: + https://www.intel.com/content/www/us/en/developer/topic-technology/open/pm-graph/features.html - upstream version in git: - https://github.com/intel/pm-graph/ + git clone https://github.com/intel/pm-graph/ Table of Contents - Overview diff --git a/tools/power/pm-graph/sleepgraph.8 b/tools/power/pm-graph/sleepgraph.8 index 5126271de98a..643271b6fc6f 100644 --- a/tools/power/pm-graph/sleepgraph.8 +++ b/tools/power/pm-graph/sleepgraph.8 @@ -78,6 +78,9 @@ This helps maintain the consistency of test data for better comparison. If a wifi connection is available, check that it reconnects after resume. Include the reconnect time in the total resume time calculation and treat wifi timeouts as resume failures. +.TP +\fB-wifitrace\fR +Trace through the wifi reconnect time and include it in the timeline. .SS "advanced" .TP diff --git a/tools/power/pm-graph/sleepgraph.py b/tools/power/pm-graph/sleepgraph.py index 33981adcdd68..cfe343306e08 100755 --- a/tools/power/pm-graph/sleepgraph.py +++ b/tools/power/pm-graph/sleepgraph.py @@ -86,7 +86,7 @@ def ascii(text): # store system values and test parameters class SystemValues: title = 'SleepGraph' - version = '5.9' + version = '5.10' ansi = False rs = 0 display = '' @@ -100,6 +100,7 @@ class SystemValues: ftracelog = False acpidebug = True tstat = True + wifitrace = False mindevlen = 0.0001 mincglen = 0.0 cgphase = '' @@ -124,6 +125,7 @@ class SystemValues: epath = '/sys/kernel/debug/tracing/events/power/' pmdpath = '/sys/power/pm_debug_messages' s0ixpath = '/sys/module/intel_pmc_core/parameters/warn_on_s0ix_failures' + s0ixres = '/sys/devices/system/cpu/cpuidle/low_power_idle_system_residency_us' acpipath='/sys/module/acpi/parameters/debug_level' traceevents = [ 'suspend_resume', @@ -180,6 +182,7 @@ class SystemValues: tmstart = 'SUSPEND START %Y%m%d-%H:%M:%S.%f' tmend = 'RESUME COMPLETE %Y%m%d-%H:%M:%S.%f' tracefuncs = { + 'async_synchronize_full': {}, 'sys_sync': {}, 'ksys_sync': {}, '__pm_notifier_call_chain': {}, @@ -304,6 +307,7 @@ class SystemValues: [2, 'suspendstats', 'sh', '-c', 'grep -v invalid /sys/power/suspend_stats/*'], [2, 'cpuidle', 'sh', '-c', 'grep -v invalid /sys/devices/system/cpu/cpu*/cpuidle/state*/s2idle/*'], [2, 'battery', 'sh', '-c', 'grep -v invalid /sys/class/power_supply/*/*'], + [2, 'thermal', 'sh', '-c', 'grep . /sys/class/thermal/thermal_zone*/temp'], ] cgblacklist = [] kprobes = dict() @@ -777,7 +781,7 @@ class SystemValues: return if not quiet: sysvals.printSystemInfo(False) - pprint('INITIALIZING FTRACE...') + pprint('INITIALIZING FTRACE') # turn trace off self.fsetVal('0', 'tracing_on') self.cleanupFtrace() @@ -841,7 +845,7 @@ class SystemValues: for name in self.dev_tracefuncs: self.defaultKprobe(name, self.dev_tracefuncs[name]) if not quiet: - pprint('INITIALIZING KPROBES...') + pprint('INITIALIZING KPROBES') self.addKprobes(self.verbose) if(self.usetraceevents): # turn trace events on @@ -1133,6 +1137,15 @@ class SystemValues: self.cfgdef[file] = fp.read().strip() fp.write(value) fp.close() + def s0ixSupport(self): + if not os.path.exists(self.s0ixres) or not os.path.exists(self.mempowerfile): + return False + fp = open(sysvals.mempowerfile, 'r') + data = fp.read().strip() + fp.close() + if '[s2idle]' in data: + return True + return False def haveTurbostat(self): if not self.tstat: return False @@ -1146,7 +1159,7 @@ class SystemValues: self.vprint(out) return True return False - def turbostat(self): + def turbostat(self, s0ixready): cmd = self.getExec('turbostat') rawout = keyline = valline = '' fullcmd = '%s -q -S echo freeze > %s' % (cmd, self.powerfile) @@ -1173,6 +1186,8 @@ class SystemValues: for key in keyline: idx = keyline.index(key) val = valline[idx] + if key == 'SYS%LPI' and not s0ixready and re.match('^[0\.]*$', val): + continue out.append('%s=%s' % (key, val)) return '|'.join(out) def netfixon(self, net='both'): @@ -1183,14 +1198,6 @@ class SystemValues: out = ascii(fp.read()).strip() fp.close() return out - def wifiRepair(self): - out = self.netfixon('wifi') - if not out or 'error' in out.lower(): - return '' - m = re.match('WIFI \S* ONLINE (?P<action>\S*)', out) - if not m: - return 'dead' - return m.group('action') def wifiDetails(self, dev): try: info = open('/sys/class/net/%s/device/uevent' % dev, 'r').read().strip() @@ -1220,11 +1227,6 @@ class SystemValues: return '%s reconnected %.2f' % \ (self.wifiDetails(dev), max(0, time.time() - start)) time.sleep(0.01) - if self.netfix: - res = self.wifiRepair() - if res: - timeout = max(0, time.time() - start) - return '%s %s %d' % (self.wifiDetails(dev), res, timeout) return '%s timeout %d' % (self.wifiDetails(dev), timeout) def errorSummary(self, errinfo, msg): found = False @@ -1346,6 +1348,20 @@ class SystemValues: for i in self.rslist: self.setVal(self.rstgt, i) pprint('runtime suspend settings restored on %d devices' % len(self.rslist)) + def start(self, pm): + if self.useftrace: + self.dlog('start ftrace tracing') + self.fsetVal('1', 'tracing_on') + if self.useprocmon: + self.dlog('start the process monitor') + pm.start() + def stop(self, pm): + if self.useftrace: + if self.useprocmon: + self.dlog('stop the process monitor') + pm.stop() + self.dlog('stop ftrace tracing') + self.fsetVal('0', 'tracing_on') sysvals = SystemValues() switchvalues = ['enable', 'disable', 'on', 'off', 'true', 'false', '1', '0'] @@ -1643,19 +1659,20 @@ class Data: ubiquitous = False if kprobename in dtf and 'ub' in dtf[kprobename]: ubiquitous = True - title = cdata+' '+rdata - mstr = '\(.*\) *(?P<args>.*) *\((?P<caller>.*)\+.* arg1=(?P<ret>.*)' - m = re.match(mstr, title) - if m: - c = m.group('caller') - a = m.group('args').strip() - r = m.group('ret') + mc = re.match('\(.*\) *(?P<args>.*)', cdata) + mr = re.match('\((?P<caller>\S*).* arg1=(?P<ret>.*)', rdata) + if mc and mr: + c = mr.group('caller').split('+')[0] + a = mc.group('args').strip() + r = mr.group('ret') if len(r) > 6: r = '' else: r = 'ret=%s ' % r if ubiquitous and c in dtf and 'ub' in dtf[c]: return False + else: + return False color = sysvals.kprobeColor(kprobename) e = DevFunction(displayname, a, c, r, start, end, ubiquitous, proc, pid, color) tgtdev['src'].append(e) @@ -1772,6 +1789,14 @@ class Data: e.time = self.trimTimeVal(e.time, t0, dT, left) e.end = self.trimTimeVal(e.end, t0, dT, left) e.length = e.end - e.time + if('cpuexec' in d): + cpuexec = dict() + for e in d['cpuexec']: + c0, cN = e + c0 = self.trimTimeVal(c0, t0, dT, left) + cN = self.trimTimeVal(cN, t0, dT, left) + cpuexec[(c0, cN)] = d['cpuexec'][e] + d['cpuexec'] = cpuexec for dir in ['suspend', 'resume']: list = [] for e in self.errorinfo[dir]: @@ -2086,75 +2111,43 @@ class Data: return d def addProcessUsageEvent(self, name, times): # get the start and end times for this process - maxC = 0 - tlast = 0 - start = -1 - end = -1 + cpuexec = dict() + tlast = start = end = -1 for t in sorted(times): - if tlast == 0: + if tlast < 0: tlast = t continue - if name in self.pstl[t]: - if start == -1 or tlast < start: + if name in self.pstl[t] and self.pstl[t][name] > 0: + if start < 0: start = tlast - if end == -1 or t > end: - end = t + end, key = t, (tlast, t) + maxj = (t - tlast) * 1024.0 + cpuexec[key] = min(1.0, float(self.pstl[t][name]) / maxj) tlast = t - if start == -1 or end == -1: - return 0 + if start < 0 or end < 0: + return # add a new action for this process and get the object out = self.newActionGlobal(name, start, end, -3) - if not out: - return 0 - phase, devname = out - dev = self.dmesg[phase]['list'][devname] - # get the cpu exec data - tlast = 0 - clast = 0 - cpuexec = dict() - for t in sorted(times): - if tlast == 0 or t <= start or t > end: - tlast = t - continue - list = self.pstl[t] - c = 0 - if name in list: - c = list[name] - if c > maxC: - maxC = c - if c != clast: - key = (tlast, t) - cpuexec[key] = c - tlast = t - clast = c - dev['cpuexec'] = cpuexec - return maxC + if out: + phase, devname = out + dev = self.dmesg[phase]['list'][devname] + dev['cpuexec'] = cpuexec def createProcessUsageEvents(self): - # get an array of process names - proclist = [] - for t in sorted(self.pstl): - pslist = self.pstl[t] - for ps in sorted(pslist): - if ps not in proclist: - proclist.append(ps) - # get a list of data points for suspend and resume - tsus = [] - tres = [] + # get an array of process names and times + proclist = {'sus': dict(), 'res': dict()} + tdata = {'sus': [], 'res': []} for t in sorted(self.pstl): - if t < self.tSuspended: - tsus.append(t) - else: - tres.append(t) + dir = 'sus' if t < self.tSuspended else 'res' + for ps in sorted(self.pstl[t]): + if ps not in proclist[dir]: + proclist[dir][ps] = 0 + tdata[dir].append(t) # process the events for suspend and resume - if len(proclist) > 0: + if len(proclist['sus']) > 0 or len(proclist['res']) > 0: sysvals.vprint('Process Execution:') - for ps in proclist: - c = self.addProcessUsageEvent(ps, tsus) - if c > 0: - sysvals.vprint('%25s (sus): %d' % (ps, c)) - c = self.addProcessUsageEvent(ps, tres) - if c > 0: - sysvals.vprint('%25s (res): %d' % (ps, c)) + for dir in ['sus', 'res']: + for ps in sorted(proclist[dir]): + self.addProcessUsageEvent(ps, tdata[dir]) def handleEndMarker(self, time, msg=''): dm = self.dmesg self.setEnd(time, msg) @@ -3218,7 +3211,7 @@ class ProcessMonitor: # markers, and/or kprobes required for primary parsing. def doesTraceLogHaveTraceEvents(): kpcheck = ['_cal: (', '_ret: ('] - techeck = ['suspend_resume', 'device_pm_callback'] + techeck = ['suspend_resume', 'device_pm_callback', 'tracing_mark_write'] tmcheck = ['SUSPEND START', 'RESUME COMPLETE'] sysvals.usekprobes = False fp = sysvals.openlog(sysvals.ftracefile, 'r') @@ -3241,7 +3234,7 @@ def doesTraceLogHaveTraceEvents(): check.remove(i) tmcheck = check fp.close() - sysvals.usetraceevents = True if len(techeck) < 2 else False + sysvals.usetraceevents = True if len(techeck) < 3 else False sysvals.usetracemarkers = True if len(tmcheck) == 0 else False # Function: appendIncompleteTraceLog @@ -3456,6 +3449,8 @@ def parseTraceLog(live=False): continue # process cpu exec line if t.type == 'tracing_mark_write': + if t.name == 'CMD COMPLETE' and data.tKernRes == 0: + data.tKernRes = t.time m = re.match(tp.procexecfmt, t.name) if(m): parts, msg = 1, m.group('ps') @@ -3674,6 +3669,9 @@ def parseTraceLog(live=False): e = next((x for x in reversed(tp.ktemp[key]) if x['end'] < 0), 0) if not e: continue + if (t.time - e['begin']) * 1000 < sysvals.mindevlen: + tp.ktemp[key].pop() + continue e['end'] = t.time e['rdata'] = kprobedata # end of kernel resume @@ -4213,6 +4211,8 @@ def callgraphHTML(sv, hf, num, cg, title, color, devid): fmt = '<n>(%.3f ms @ '+sv.timeformat+')</n>' flen = fmt % (line.length*1000, line.time) if line.isLeaf(): + if line.length * 1000 < sv.mincglen: + continue hf.write(html_func_leaf.format(line.name, flen)) elif line.freturn: hf.write(html_func_end) @@ -4827,14 +4827,11 @@ def createHTML(testruns, testfail): if('cpuexec' in dev): for t in sorted(dev['cpuexec']): start, end = t - j = float(dev['cpuexec'][t]) / 5 - if j > 1.0: - j = 1.0 height = '%.3f' % (rowheight/3) top = '%.3f' % (rowtop + devtl.scaleH + 2*rowheight/3) left = '%f' % (((start-m0)*100)/mTotal) width = '%f' % ((end-start)*100/mTotal) - color = 'rgba(255, 0, 0, %f)' % j + color = 'rgba(255, 0, 0, %f)' % dev['cpuexec'][t] devtl.html += \ html_cpuexec.format(left, top, height, width, color) if('src' not in dev): @@ -5453,17 +5450,9 @@ def executeSuspend(quiet=False): call('sync', shell=True) sv.dlog('read dmesg') sv.initdmesg() - # start ftrace - if sv.useftrace: - if not quiet: - pprint('START TRACING') - sv.dlog('start ftrace tracing') - sv.fsetVal('1', 'tracing_on') - if sv.useprocmon: - sv.dlog('start the process monitor') - pm.start() - sv.dlog('run the cmdinfo list before') + sv.dlog('cmdinfo before') sv.cmdinfo(True) + sv.start(pm) # execute however many s/r runs requested for count in range(1,sv.execcount+1): # x2delay in between test runs @@ -5500,6 +5489,7 @@ def executeSuspend(quiet=False): if res != 0: tdata['error'] = 'cmd returned %d' % res else: + s0ixready = sv.s0ixSupport() mode = sv.suspendmode if sv.memmode and os.path.exists(sv.mempowerfile): mode = 'mem' @@ -5509,9 +5499,10 @@ def executeSuspend(quiet=False): sv.testVal(sv.diskpowerfile, 'radio', sv.diskmode) if sv.acpidebug: sv.testVal(sv.acpipath, 'acpi', '0xe') - if mode == 'freeze' and sv.haveTurbostat(): + if ((mode == 'freeze') or (sv.memmode == 's2idle')) \ + and sv.haveTurbostat(): # execution will pause here - turbo = sv.turbostat() + turbo = sv.turbostat(s0ixready) if turbo: tdata['turbo'] = turbo else: @@ -5522,7 +5513,8 @@ def executeSuspend(quiet=False): pf.close() except Exception as e: tdata['error'] = str(e) - sv.dlog('system returned from resume') + sv.fsetVal('CMD COMPLETE', 'trace_marker') + sv.dlog('system returned') # reset everything sv.testVal('restoreall') if(sv.rtcwake): @@ -5535,33 +5527,29 @@ def executeSuspend(quiet=False): sv.fsetVal('WAIT END', 'trace_marker') # return from suspend pprint('RESUME COMPLETE') - sv.fsetVal(datetime.now().strftime(sv.tmend), 'trace_marker') + if(count < sv.execcount): + sv.fsetVal(datetime.now().strftime(sv.tmend), 'trace_marker') + elif(not sv.wifitrace): + sv.fsetVal(datetime.now().strftime(sv.tmend), 'trace_marker') + sv.stop(pm) if sv.wifi and wifi: tdata['wifi'] = sv.pollWifi(wifi) sv.dlog('wifi check, %s' % tdata['wifi']) - if sv.netfix: - netfixout = sv.netfixon('wired') - elif sv.netfix: - netfixout = sv.netfixon() - if sv.netfix and netfixout: - tdata['netfix'] = netfixout + if(count == sv.execcount and sv.wifitrace): + sv.fsetVal(datetime.now().strftime(sv.tmend), 'trace_marker') + sv.stop(pm) + if sv.netfix: + tdata['netfix'] = sv.netfixon() sv.dlog('netfix, %s' % tdata['netfix']) if(sv.suspendmode == 'mem' or sv.suspendmode == 'command'): sv.dlog('read the ACPI FPDT') tdata['fw'] = getFPDT(False) testdata.append(tdata) - sv.dlog('run the cmdinfo list after') + sv.dlog('cmdinfo after') cmdafter = sv.cmdinfo(False) - # stop ftrace - if sv.useftrace: - if sv.useprocmon: - sv.dlog('stop the process monitor') - pm.stop() - sv.fsetVal('0', 'tracing_on') # grab a copy of the dmesg output if not quiet: pprint('CAPTURING DMESG') - sysvals.dlog('EXECUTION TRACE END') sv.getdmesg(testdata) # grab a copy of the ftrace output if sv.useftrace: @@ -6350,6 +6338,8 @@ def data_from_html(file, outpath, issues, fulldetail=False): if not m: continue name, time, phase = m.group('n'), m.group('t'), m.group('p') + if name == 'async_synchronize_full': + continue if ' async' in name or ' sync' in name: name = ' '.join(name.split(' ')[:-1]) if phase.startswith('suspend'): @@ -6701,6 +6691,7 @@ def printHelp(): ' -skiphtml Run the test and capture the trace logs, but skip the timeline (default: disabled)\n'\ ' -result fn Export a results table to a text file for parsing.\n'\ ' -wifi If a wifi connection is available, check that it reconnects after resume.\n'\ + ' -wifitrace Trace kernel execution through wifi reconnect.\n'\ ' -netfix Use netfix to reset the network in the event it fails to resume.\n'\ ' [testprep]\n'\ ' -sync Sync the filesystems before starting the test\n'\ @@ -6828,6 +6819,8 @@ if __name__ == '__main__': sysvals.sync = True elif(arg == '-wifi'): sysvals.wifi = True + elif(arg == '-wifitrace'): + sysvals.wifitrace = True elif(arg == '-netfix'): sysvals.netfix = True elif(arg == '-gzip'): |