diff options
author | Linus Torvalds <torvalds@linux-foundation.org> | 2022-10-28 16:44:12 -0700 |
---|---|---|
committer | Linus Torvalds <torvalds@linux-foundation.org> | 2022-10-28 16:44:12 -0700 |
commit | 6b872a5ecece462ba02c8cad1c0203583631db2b (patch) | |
tree | ec54d277ba71f21d83d90894f3d898b09b22ff98 | |
parent | fd7e2a25863d3a8104dc1e414b2d49e2418e250c (diff) | |
parent | 6f257934ed6170ed0094149e0e1bac09f7997103 (diff) | |
download | linux-6b872a5ecece462ba02c8cad1c0203583631db2b.tar.bz2 |
Merge tag 'pm-6.1-rc3' of git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm
Pull power management fixes from Rafael Wysocki:
"These make the intel_pstate driver work as expected on all hybrid
platforms to date (regardless of possible platform firmware issues),
fix hybrid sleep on systems using suspend-to-idle by default, make the
generic power domains code handle disabled idle states properly and
update pm-graph.
Specifics:
- Make intel_pstate use what is known about the hardware instead of
relying on information from the platform firmware (ACPI CPPC in
particular) to establish the relationship between the HWP CPU
performance levels and frequencies on all hybrid platforms
available to date (Rafael Wysocki)
- Allow hybrid sleep to use suspend-to-idle as a system suspend
method if it is the current suspend method of choice (Mario
Limonciello)
- Fix handling of unavailable/disabled idle states in the generic
power domains code (Sudeep Holla)
- Update the pm-graph suite of utilities to version 5.10 which is
fixes-mostly and does not add any new features (Todd Brandt)"
* tag 'pm-6.1-rc3' of git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm:
PM: domains: Fix handling of unavailable/disabled idle states
pm-graph v5.10
cpufreq: intel_pstate: hybrid: Use known scaling factor for P-cores
cpufreq: intel_pstate: Read all MSRs on the target CPU
PM: hibernate: Allow hybrid sleep to work with s2idle
-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'): |