From 6319aee10e530315689db7609a7d4c444124ff22 Mon Sep 17 00:00:00 2001 From: Viresh Kumar Date: Wed, 8 May 2019 15:19:13 +0530 Subject: [PATCH 01/13] opp: Attach genpds to devices from within OPP core The OPP core requires the virtual device pointers to set performance state on behalf of the device, for the multiple power domain case. The genpd API (dev_pm_domain_attach_by_name()) has evolved now to support even the single power domain case and that lets us add common code for handling both the cases more efficiently. The virtual device structure returned by dev_pm_domain_attach_by_name() isn't normally used by the cpufreq drivers as they don't manage power on/off of the domains and so is only useful for the OPP core. This patch moves all the complexity into the OPP core to make the end drivers simple. The earlier APIs dev_pm_opp_{set|put}_genpd_virt_dev() are reworked into dev_pm_opp_{attach|detach}_genpd(). The new helper dev_pm_opp_attach_genpd() accepts a NULL terminated array of strings which contains names of all the genpd's to attach. It then attaches all the domains and saves the pointers to the virtual devices. The other helper undo the work done by this helper. Tested-by: Niklas Cassel Signed-off-by: Viresh Kumar --- drivers/opp/core.c | 134 ++++++++++++++++++++++++++--------------- include/linux/pm_opp.h | 8 +-- 2 files changed, 89 insertions(+), 53 deletions(-) diff --git a/drivers/opp/core.c b/drivers/opp/core.c index 0e7703fe733f..67d6b0caeab1 100644 --- a/drivers/opp/core.c +++ b/drivers/opp/core.c @@ -1744,91 +1744,127 @@ void dev_pm_opp_unregister_set_opp_helper(struct opp_table *opp_table) } EXPORT_SYMBOL_GPL(dev_pm_opp_unregister_set_opp_helper); +static void _opp_detach_genpd(struct opp_table *opp_table) +{ + int index; + + for (index = 0; index < opp_table->required_opp_count; index++) { + if (!opp_table->genpd_virt_devs[index]) + continue; + + dev_pm_domain_detach(opp_table->genpd_virt_devs[index], false); + opp_table->genpd_virt_devs[index] = NULL; + } +} + /** - * dev_pm_opp_set_genpd_virt_dev - Set virtual genpd device for an index - * @dev: Consumer device for which the genpd device is getting set. - * @virt_dev: virtual genpd device. - * @index: index. + * dev_pm_opp_attach_genpd - Attach genpd(s) for the device and save virtual device pointer + * @dev: Consumer device for which the genpd is getting attached. + * @names: Null terminated array of pointers containing names of genpd to attach. * * Multiple generic power domains for a device are supported with the help of * virtual genpd devices, which are created for each consumer device - genpd * pair. These are the device structures which are attached to the power domain * and are required by the OPP core to set the performance state of the genpd. + * The same API also works for the case where single genpd is available and so + * we don't need to support that separately. * * This helper will normally be called by the consumer driver of the device - * "dev", as only that has details of the genpd devices. + * "dev", as only that has details of the genpd names. * - * This helper needs to be called once for each of those virtual devices, but - * only if multiple domains are available for a device. Otherwise the original - * device structure will be used instead by the OPP core. + * This helper needs to be called once with a list of all genpd to attach. + * Otherwise the original device structure will be used instead by the OPP core. */ -struct opp_table *dev_pm_opp_set_genpd_virt_dev(struct device *dev, - struct device *virt_dev, - int index) +struct opp_table *dev_pm_opp_attach_genpd(struct device *dev, const char **names) { struct opp_table *opp_table; + struct device *virt_dev; + int index, ret = -EINVAL; + const char **name = names; opp_table = dev_pm_opp_get_opp_table(dev); if (!opp_table) return ERR_PTR(-ENOMEM); - mutex_lock(&opp_table->genpd_virt_dev_lock); - - if (unlikely(!opp_table->genpd_virt_devs || - index >= opp_table->required_opp_count || - opp_table->genpd_virt_devs[index])) { - - dev_err(dev, "Invalid request to set required device\n"); - dev_pm_opp_put_opp_table(opp_table); - mutex_unlock(&opp_table->genpd_virt_dev_lock); - - return ERR_PTR(-EINVAL); + /* + * If the genpd's OPP table isn't already initialized, parsing of the + * required-opps fail for dev. We should retry this after genpd's OPP + * table is added. + */ + if (!opp_table->required_opp_count) { + ret = -EPROBE_DEFER; + goto put_table; + } + + mutex_lock(&opp_table->genpd_virt_dev_lock); + + while (*name) { + index = of_property_match_string(dev->of_node, + "power-domain-names", *name); + if (index < 0) { + dev_err(dev, "Failed to find power domain: %s (%d)\n", + *name, index); + goto err; + } + + if (index >= opp_table->required_opp_count) { + dev_err(dev, "Index can't be greater than required-opp-count - 1, %s (%d : %d)\n", + *name, opp_table->required_opp_count, index); + goto err; + } + + if (opp_table->genpd_virt_devs[index]) { + dev_err(dev, "Genpd virtual device already set %s\n", + *name); + goto err; + } + + virt_dev = dev_pm_domain_attach_by_name(dev, *name); + if (IS_ERR(virt_dev)) { + ret = PTR_ERR(virt_dev); + dev_err(dev, "Couldn't attach to pm_domain: %d\n", ret); + goto err; + } + + opp_table->genpd_virt_devs[index] = virt_dev; + name++; } - opp_table->genpd_virt_devs[index] = virt_dev; mutex_unlock(&opp_table->genpd_virt_dev_lock); return opp_table; + +err: + _opp_detach_genpd(opp_table); + mutex_unlock(&opp_table->genpd_virt_dev_lock); + +put_table: + dev_pm_opp_put_opp_table(opp_table); + + return ERR_PTR(ret); } +EXPORT_SYMBOL_GPL(dev_pm_opp_attach_genpd); /** - * dev_pm_opp_put_genpd_virt_dev() - Releases resources blocked for genpd device. - * @opp_table: OPP table returned by dev_pm_opp_set_genpd_virt_dev(). - * @virt_dev: virtual genpd device. + * dev_pm_opp_detach_genpd() - Detach genpd(s) from the device. + * @opp_table: OPP table returned by dev_pm_opp_attach_genpd(). * - * This releases the resource previously acquired with a call to - * dev_pm_opp_set_genpd_virt_dev(). The consumer driver shall call this helper - * if it doesn't want OPP core to update performance state of a power domain - * anymore. + * This detaches the genpd(s), resets the virtual device pointers, and puts the + * OPP table. */ -void dev_pm_opp_put_genpd_virt_dev(struct opp_table *opp_table, - struct device *virt_dev) +void dev_pm_opp_detach_genpd(struct opp_table *opp_table) { - int i; - /* * Acquire genpd_virt_dev_lock to make sure virt_dev isn't getting * used in parallel. */ mutex_lock(&opp_table->genpd_virt_dev_lock); - - for (i = 0; i < opp_table->required_opp_count; i++) { - if (opp_table->genpd_virt_devs[i] != virt_dev) - continue; - - opp_table->genpd_virt_devs[i] = NULL; - dev_pm_opp_put_opp_table(opp_table); - - /* Drop the vote */ - dev_pm_genpd_set_performance_state(virt_dev, 0); - break; - } - + _opp_detach_genpd(opp_table); mutex_unlock(&opp_table->genpd_virt_dev_lock); - if (unlikely(i == opp_table->required_opp_count)) - dev_err(virt_dev, "Failed to find required device entry\n"); + dev_pm_opp_put_opp_table(opp_table); } +EXPORT_SYMBOL_GPL(dev_pm_opp_detach_genpd); /** * dev_pm_opp_xlate_performance_state() - Find required OPP's pstate for src_table. diff --git a/include/linux/pm_opp.h b/include/linux/pm_opp.h index b150fe97ce5a..be570761b77a 100644 --- a/include/linux/pm_opp.h +++ b/include/linux/pm_opp.h @@ -131,8 +131,8 @@ struct opp_table *dev_pm_opp_set_clkname(struct device *dev, const char * name); void dev_pm_opp_put_clkname(struct opp_table *opp_table); struct opp_table *dev_pm_opp_register_set_opp_helper(struct device *dev, int (*set_opp)(struct dev_pm_set_opp_data *data)); void dev_pm_opp_unregister_set_opp_helper(struct opp_table *opp_table); -struct opp_table *dev_pm_opp_set_genpd_virt_dev(struct device *dev, struct device *virt_dev, int index); -void dev_pm_opp_put_genpd_virt_dev(struct opp_table *opp_table, struct device *virt_dev); +struct opp_table *dev_pm_opp_attach_genpd(struct device *dev, const char **names); +void dev_pm_opp_detach_genpd(struct opp_table *opp_table); int dev_pm_opp_xlate_performance_state(struct opp_table *src_table, struct opp_table *dst_table, unsigned int pstate); int dev_pm_opp_set_rate(struct device *dev, unsigned long target_freq); int dev_pm_opp_set_sharing_cpus(struct device *cpu_dev, const struct cpumask *cpumask); @@ -295,12 +295,12 @@ static inline struct opp_table *dev_pm_opp_set_clkname(struct device *dev, const static inline void dev_pm_opp_put_clkname(struct opp_table *opp_table) {} -static inline struct opp_table *dev_pm_opp_set_genpd_virt_dev(struct device *dev, struct device *virt_dev, int index) +static inline struct opp_table *dev_pm_opp_attach_genpd(struct device *dev, const char **names) { return ERR_PTR(-ENOTSUPP); } -static inline void dev_pm_opp_put_genpd_virt_dev(struct opp_table *opp_table, struct device *virt_dev) {} +static inline void dev_pm_opp_detach_genpd(struct opp_table *opp_table) {} static inline int dev_pm_opp_xlate_performance_state(struct opp_table *src_table, struct opp_table *dst_table, unsigned int pstate) { From c0ab9e0812da8e2134dd63d030c8a8abd2112a5a Mon Sep 17 00:00:00 2001 From: Viresh Kumar Date: Wed, 8 May 2019 15:43:36 +0530 Subject: [PATCH 02/13] opp: Allocate genpd_virt_devs from dev_pm_opp_attach_genpd() Currently the space for the array of virtual devices is allocated along with the OPP table, but that isn't going to work well from now onwards. For single power domain case, a driver can either use the original device structure for setting the performance state (if genpd attached with dev_pm_domain_attach()) or use the virtual device structure (if genpd attached with dev_pm_domain_attach_by_name(), which returns the virtual device) and so we can't know in advance if we are going to need genpd_virt_devs array or not. Lets delay the allocation a bit and do it along with dev_pm_opp_attach_genpd() rather. The deallocation is done from dev_pm_opp_detach_genpd(). Tested-by: Niklas Cassel Signed-off-by: Viresh Kumar --- drivers/opp/core.c | 10 ++++++++++ drivers/opp/of.c | 30 ++---------------------------- 2 files changed, 12 insertions(+), 28 deletions(-) diff --git a/drivers/opp/core.c b/drivers/opp/core.c index 67d6b0caeab1..764e05a2fa66 100644 --- a/drivers/opp/core.c +++ b/drivers/opp/core.c @@ -1755,6 +1755,9 @@ static void _opp_detach_genpd(struct opp_table *opp_table) dev_pm_domain_detach(opp_table->genpd_virt_devs[index], false); opp_table->genpd_virt_devs[index] = NULL; } + + kfree(opp_table->genpd_virt_devs); + opp_table->genpd_virt_devs = NULL; } /** @@ -1798,6 +1801,12 @@ struct opp_table *dev_pm_opp_attach_genpd(struct device *dev, const char **names mutex_lock(&opp_table->genpd_virt_dev_lock); + opp_table->genpd_virt_devs = kcalloc(opp_table->required_opp_count, + sizeof(*opp_table->genpd_virt_devs), + GFP_KERNEL); + if (!opp_table->genpd_virt_devs) + goto unlock; + while (*name) { index = of_property_match_string(dev->of_node, "power-domain-names", *name); @@ -1836,6 +1845,7 @@ struct opp_table *dev_pm_opp_attach_genpd(struct device *dev, const char **names err: _opp_detach_genpd(opp_table); +unlock: mutex_unlock(&opp_table->genpd_virt_dev_lock); put_table: diff --git a/drivers/opp/of.c b/drivers/opp/of.c index c10c782d15aa..a637f30552a3 100644 --- a/drivers/opp/of.c +++ b/drivers/opp/of.c @@ -141,7 +141,6 @@ static struct opp_table *_find_table_of_opp_np(struct device_node *opp_np) static void _opp_table_free_required_tables(struct opp_table *opp_table) { struct opp_table **required_opp_tables = opp_table->required_opp_tables; - struct device **genpd_virt_devs = opp_table->genpd_virt_devs; int i; if (!required_opp_tables) @@ -155,10 +154,8 @@ static void _opp_table_free_required_tables(struct opp_table *opp_table) } kfree(required_opp_tables); - kfree(genpd_virt_devs); opp_table->required_opp_count = 0; - opp_table->genpd_virt_devs = NULL; opp_table->required_opp_tables = NULL; } @@ -171,9 +168,8 @@ static void _opp_table_alloc_required_tables(struct opp_table *opp_table, struct device_node *opp_np) { struct opp_table **required_opp_tables; - struct device **genpd_virt_devs = NULL; struct device_node *required_np, *np; - int count, count_pd, i; + int count, i; /* Traversing the first OPP node is all we need */ np = of_get_next_available_child(opp_np, NULL); @@ -186,33 +182,11 @@ static void _opp_table_alloc_required_tables(struct opp_table *opp_table, if (!count) goto put_np; - /* - * Check the number of power-domains to know if we need to deal - * with virtual devices. In some cases we have devices with multiple - * power domains but with only one of them being scalable, hence - * 'count' could be 1, but we still have to deal with multiple genpds - * and virtual devices. - */ - count_pd = of_count_phandle_with_args(dev->of_node, "power-domains", - "#power-domain-cells"); - if (!count_pd) - goto put_np; - - if (count_pd > 1) { - genpd_virt_devs = kcalloc(count, sizeof(*genpd_virt_devs), - GFP_KERNEL); - if (!genpd_virt_devs) - goto put_np; - } - required_opp_tables = kcalloc(count, sizeof(*required_opp_tables), GFP_KERNEL); - if (!required_opp_tables) { - kfree(genpd_virt_devs); + if (!required_opp_tables) goto put_np; - } - opp_table->genpd_virt_devs = genpd_virt_devs; opp_table->required_opp_tables = required_opp_tables; opp_table->required_opp_count = count; From 7673896a40693506db49c1e9f9c3a4a8c7e357c5 Mon Sep 17 00:00:00 2001 From: Todd Brandt Date: Tue, 14 May 2019 10:53:57 -0700 Subject: [PATCH 03/13] Update to pm-graph 5.3 sleepgraph: - add support for parsing kernel issues from timeline dmesg logs - with -summary, generate a summary-issues.html for kernel issues found - with -summary, generate a summary-devices.html for device callback times - when recreating a timeline, use -o to set the output html filename - capture mcelog data when hardware errors occur and store in log - add -turbostat option to capture power data during freeze Signed-off-by: Todd Brandt Signed-off-by: Rafael J. Wysocki --- tools/power/pm-graph/sleepgraph.py | 496 ++++++++++++++++++++++------- 1 file changed, 379 insertions(+), 117 deletions(-) diff --git a/tools/power/pm-graph/sleepgraph.py b/tools/power/pm-graph/sleepgraph.py index 52618f3444d4..41d28d63e7c9 100755 --- a/tools/power/pm-graph/sleepgraph.py +++ b/tools/power/pm-graph/sleepgraph.py @@ -61,6 +61,7 @@ import ConfigParser import gzip from threading import Thread from subprocess import call, Popen, PIPE +import base64 def pprint(msg): print(msg) @@ -74,7 +75,7 @@ def pprint(msg): # store system values and test parameters class SystemValues: title = 'SleepGraph' - version = '5.2' + version = '5.3' ansi = False rs = 0 display = '' @@ -199,6 +200,7 @@ class SystemValues: '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}, + 'rt_mutex_slowlock': {'ub': 1}, # ACPI 'acpi_resume_power_resources': {}, 'acpi_ps_parse_aml': {}, @@ -344,10 +346,12 @@ class SystemValues: m = info['baseboard-manufacturer'] elif 'system-manufacturer' in info: m = info['system-manufacturer'] - if 'baseboard-product-name' in info: - p = info['baseboard-product-name'] - elif 'system-product-name' in info: + if 'system-product-name' in info: p = info['system-product-name'] + elif 'baseboard-product-name' in info: + p = info['baseboard-product-name'] + if m[:5].lower() == 'intel' and 'baseboard-product-name' in info: + p = info['baseboard-product-name'] if 'processor-version' in info: c = info['processor-version'] if 'bios-version' in info: @@ -688,7 +692,8 @@ class SystemValues: if self.bufsize > 0: tgtsize = self.bufsize elif self.usecallgraph or self.usedevsrc: - bmax = (1*1024*1024) if self.suspendmode == 'disk' else (3*1024*1024) + bmax = (1*1024*1024) if self.suspendmode in ['disk', 'command'] \ + else (3*1024*1024) tgtsize = min(self.memfree, bmax) else: tgtsize = 65536 @@ -776,6 +781,10 @@ class SystemValues: fw = test['fw'] if(fw): fp.write('# fwsuspend %u fwresume %u\n' % (fw[0], fw[1])) + if 'mcelog' in test: + fp.write('# mcelog %s\n' % test['mcelog']) + if 'turbo' in test: + fp.write('# turbostat %s\n' % test['turbo']) if 'bat' in test: (a1, c1), (a2, c2) = test['bat'] fp.write('# battery %s %d %s %d\n' % (a1, c1, a2, c2)) @@ -829,6 +838,56 @@ class SystemValues: if isgz: return gzip.open(filename, mode+'b') return open(filename, mode) + def mcelog(self, clear=False): + cmd = self.getExec('mcelog') + if not cmd: + return '' + if clear: + call(cmd+' > /dev/null 2>&1', shell=True) + return '' + fp = Popen([cmd], stdout=PIPE, stderr=PIPE).stdout + out = fp.read().strip() + fp.close() + if not out: + return '' + return base64.b64encode(out.encode('zlib')) + def haveTurbostat(self): + cmd = self.getExec('turbostat') + if not cmd: + return False + fp = Popen([cmd, '-v'], stdout=PIPE, stderr=PIPE).stderr + out = fp.read().strip() + fp.close() + return re.match('turbostat version [0-8.]* .*', out) + def turbostat(self): + cmd = self.getExec('turbostat') + if not cmd: + return 'missing turbostat executable' + outfile = '/tmp/pm-graph-turbostat.txt' + res = call('%s -o %s -q -S echo freeze > %s' % \ + (cmd, outfile, self.powerfile), shell=True) + if res != 0: + return 'turbosat returned %d' % res + if not os.path.exists(outfile): + return 'turbostat output missing' + fp = open(outfile, 'r') + text = [] + for line in fp: + if re.match('[0-9.]* sec', line): + continue + text.append(line.split()) + fp.close() + if len(text) < 2: + return 'turbostat output format error' + out = [] + for key in text[0]: + values = [] + idx = text[0].index(key) + for line in text[1:]: + if len(line) > idx: + values.append(line[idx]) + out.append('%s=%s' % (key, ','.join(values))) + return '|'.join(out) sysvals = SystemValues() switchvalues = ['enable', 'disable', 'on', 'off', 'true', 'false', '1', '0'] @@ -941,6 +1000,8 @@ class Data: self.outfile = '' self.kerror = False self.battery = 0 + self.turbostat = 0 + self.mcelog = 0 self.enterfail = '' self.currphase = '' self.pstl = dict() # process timeline @@ -975,8 +1036,38 @@ class Data: if len(plist) < 1: return '' return plist[-1] - def extractErrorInfo(self): - lf = sysvals.openlog(sysvals.dmesgfile, 'r') + def errorSummary(self, errinfo, msg): + found = False + for entry in errinfo: + if re.match(entry['match'], msg): + entry['count'] += 1 + if sysvals.hostname not in entry['urls']: + entry['urls'][sysvals.hostname] = sysvals.htmlfile + found = True + break + if found: + return + arr = msg.split() + for j in range(len(arr)): + if re.match('^[0-9\-\.]*$', arr[j]): + arr[j] = '[0-9\-\.]*' + else: + arr[j] = arr[j]\ + .replace(']', '\]').replace('[', '\[').replace('.', '\.')\ + .replace('+', '\+').replace('*', '\*').replace('(', '\(')\ + .replace(')', '\)') + mstr = ' '.join(arr) + entry = { + 'line': msg, + 'match': mstr, + 'count': 1, + 'urls': {sysvals.hostname: sysvals.htmlfile} + } + errinfo.append(entry) + def extractErrorInfo(self, issues=0): + lf = self.dmesgtext + if len(self.dmesgtext) < 1 and sysvals.dmesgfile: + lf = sysvals.openlog(sysvals.dmesgfile, 'r') i = 0 list = [] for line in lf: @@ -993,6 +1084,8 @@ class Data: if re.match(self.errlist[err], msg): list.append((err, dir, t, i, i)) self.kerror = True + if not isinstance(issues, int): + self.errorSummary(issues, msg) break for e in list: type, dir, t, idx1, idx2 = e @@ -1000,7 +1093,8 @@ class Data: self.errorinfo[dir].append((type, t, idx1, idx2)) if self.kerror: sysvals.dmesglog = True - lf.close() + if len(self.dmesgtext) < 1 and sysvals.dmesgfile: + lf.close() def setStart(self, time): self.start = time def setEnd(self, time): @@ -2358,6 +2452,8 @@ class TestProps: '(?P[0-9]{2})(?P[0-9]{2})(?P[0-9]{2})'+\ ' (?P.*) (?P.*) (?P.*)$' batteryfmt = '^# battery (?P\w*) (?P\d*) (?P\w*) (?P\d*)' + tstatfmt = '^# turbostat (?P\S*)' + mcelogfmt = '^# mcelog (?P\S*)' testerrfmt = '^# enter_sleep_error (?P.*)' sysinfofmt = '^# sysinfo .*' cmdlinefmt = '^# command \| (?P.*)' @@ -2380,6 +2476,8 @@ class TestProps: self.cmdline = '' self.kparams = '' self.testerror = [] + self.mcelog = [] + self.turbostat = [] self.battery = [] self.fwdata = [] self.ftrace_line_fmt = self.ftrace_line_fmt_nop @@ -2394,6 +2492,38 @@ class TestProps: self.ftrace_line_fmt = self.ftrace_line_fmt_nop else: doError('Invalid tracer format: [%s]' % tracer) + def decode(self, data): + try: + out = base64.b64decode(data).decode('zlib') + except: + out = data + return out + def stampInfo(self, line): + if re.match(self.stampfmt, line): + self.stamp = line + return True + elif re.match(self.sysinfofmt, line): + self.sysinfo = line + return True + elif re.match(self.cmdlinefmt, line): + self.cmdline = line + return True + elif re.match(self.mcelogfmt, line): + self.mcelog.append(line) + return True + elif re.match(self.tstatfmt, line): + self.turbostat.append(line) + return True + elif re.match(self.batteryfmt, line): + self.battery.append(line) + return True + elif re.match(self.testerrfmt, line): + self.testerror.append(line) + return True + elif re.match(self.firmwarefmt, line): + self.fwdata.append(line) + return True + return False def parseStamp(self, data, sv): # global test data m = re.match(self.stampfmt, self.stamp) @@ -2436,9 +2566,21 @@ class TestProps: sv.stamp = data.stamp # firmware data if sv.suspendmode == 'mem' and len(self.fwdata) > data.testnumber: - data.fwSuspend, data.fwResume = self.fwdata[data.testnumber] - if(data.fwSuspend > 0 or data.fwResume > 0): - data.fwValid = True + m = re.match(self.firmwarefmt, self.fwdata[data.testnumber]) + if m: + data.fwSuspend, data.fwResume = int(m.group('s')), int(m.group('r')) + if(data.fwSuspend > 0 or data.fwResume > 0): + data.fwValid = True + # mcelog data + if len(self.mcelog) > data.testnumber: + m = re.match(self.mcelogfmt, self.mcelog[data.testnumber]) + if m: + data.mcelog = self.decode(m.group('m')) + # turbostat data + if len(self.turbostat) > data.testnumber: + m = re.match(self.tstatfmt, self.turbostat[data.testnumber]) + if m: + data.turbostat = m.group('t') # battery data if len(self.battery) > data.testnumber: m = re.match(self.batteryfmt, self.battery[data.testnumber]) @@ -2564,21 +2706,7 @@ def appendIncompleteTraceLog(testruns): for line in tf: # remove any latent carriage returns line = line.replace('\r\n', '') - # grab the stamp and sysinfo - if re.match(tp.stampfmt, line): - tp.stamp = line - continue - elif re.match(tp.sysinfofmt, line): - tp.sysinfo = line - continue - elif re.match(tp.cmdlinefmt, line): - tp.cmdline = line - continue - elif re.match(tp.batteryfmt, line): - tp.battery.append(line) - continue - elif re.match(tp.testerrfmt, line): - tp.testerror.append(line) + if tp.stampInfo(line): continue # determine the trace data type (required for further parsing) m = re.match(tp.tracertypefmt, line) @@ -2701,26 +2829,7 @@ def parseTraceLog(live=False): for line in tf: # remove any latent carriage returns line = line.replace('\r\n', '') - # stamp and sysinfo lines - if re.match(tp.stampfmt, line): - tp.stamp = line - continue - elif re.match(tp.sysinfofmt, line): - tp.sysinfo = line - continue - elif re.match(tp.cmdlinefmt, line): - tp.cmdline = line - continue - elif re.match(tp.batteryfmt, line): - tp.battery.append(line) - continue - elif re.match(tp.testerrfmt, line): - tp.testerror.append(line) - continue - # firmware line: pull out any firmware data - m = re.match(tp.firmwarefmt, line) - if(m): - tp.fwdata.append((int(m.group('s')), int(m.group('r')))) + if tp.stampInfo(line): continue # tracer type line: determine the trace data type m = re.match(tp.tracertypefmt, line) @@ -3141,25 +3250,7 @@ def loadKernelLog(): idx = line.find('[') if idx > 1: line = line[idx:] - # grab the stamp and sysinfo - if re.match(tp.stampfmt, line): - tp.stamp = line - continue - elif re.match(tp.sysinfofmt, line): - tp.sysinfo = line - continue - elif re.match(tp.cmdlinefmt, line): - tp.cmdline = line - continue - elif re.match(tp.batteryfmt, line): - tp.battery.append(line) - continue - elif re.match(tp.testerrfmt, line): - tp.testerror.append(line) - continue - m = re.match(tp.firmwarefmt, line) - if(m): - tp.fwdata.append((int(m.group('s')), int(m.group('r')))) + if tp.stampInfo(line): continue m = re.match('[ \t]*(\[ *)(?P[0-9\.]*)(\]) (?P.*)', line) if(not m): @@ -3531,22 +3622,16 @@ def addCallgraphs(sv, hf, data): name+' → '+cg.name, color, dev['id']) hf.write('\n\n \n') -# Function: createHTMLSummarySimple -# Description: -# Create summary html file for a series of tests -# Arguments: -# testruns: array of Data objects from parseTraceLog -def createHTMLSummarySimple(testruns, htmlfile, title): - # write the html header first (html head, css code, up to body start) - html = '\n\n\n\ +def summaryCSS(title, center=True): + tdcenter = 'text-align:center;' if center else '' + out = '\n\n\n\ \n\ - SleepGraph Summary\n\ + '+title+'\n\ \n\n\n' + return out + +# Function: createHTMLSummarySimple +# Description: +# Create summary html file for a series of tests +# Arguments: +# testruns: array of Data objects from parseTraceLog +def createHTMLSummarySimple(testruns, htmlfile, title): + # write the html header first (html head, css code, up to body start) + html = summaryCSS('Summary - SleepGraph') # extract the test data into list list = dict() @@ -3579,17 +3674,20 @@ def createHTMLSummarySimple(testruns, htmlfile, title): tAvg, tMin, tMax, tMed = [0.0, 0.0], [0.0, 0.0], [0.0, 0.0], [[], []] iMin, iMed, iMax = [0, 0], [0, 0], [0, 0] num = 0 + res = data['result'] tVal = [float(data['suspend']), float(data['resume'])] list[mode]['data'].append([data['host'], data['kernel'], - data['time'], tVal[0], tVal[1], data['url'], data['result'], + data['time'], tVal[0], tVal[1], data['url'], res, data['issues'], data['sus_worst'], data['sus_worsttime'], data['res_worst'], data['res_worsttime']]) idx = len(list[mode]['data']) - 1 - if data['result'] not in cnt: - cnt[data['result']] = 1 + if res.startswith('fail in'): + res = 'fail' + if res not in cnt: + cnt[res] = 1 else: - cnt[data['result']] += 1 - if data['result'] == 'pass': + cnt[res] += 1 + if res == 'pass': for i in range(2): tMed[i].append(tVal[i]) tAvg[i] += tVal[i] @@ -3623,7 +3721,7 @@ def createHTMLSummarySimple(testruns, htmlfile, title): tdlink = '\thtml\n' # table header - html += '\n\n' + th.format('#') +\ + html += '
\n\n' + th.format('#') +\ th.format('Mode') + th.format('Host') + th.format('Kernel') +\ th.format('Test Time') + th.format('Result') + th.format('Issues') +\ th.format('Suspend') + th.format('Resume') +\ @@ -3698,6 +3796,104 @@ def createHTMLSummarySimple(testruns, htmlfile, title): hf.write(html+'
\n\n\n') hf.close() +def createHTMLDeviceSummary(testruns, htmlfile, title): + html = summaryCSS('Device Summary - SleepGraph', False) + + # create global device list from all tests + devall = dict() + for data in testruns: + host, url, devlist = data['host'], data['url'], data['devlist'] + for type in devlist: + if type not in devall: + devall[type] = dict() + mdevlist, devlist = devall[type], data['devlist'][type] + for name in devlist: + length = devlist[name] + if name not in mdevlist: + mdevlist[name] = {'name': name, 'host': host, + 'worst': length, 'total': length, 'count': 1, + 'url': url} + else: + if length > mdevlist[name]['worst']: + mdevlist[name]['worst'] = length + mdevlist[name]['url'] = url + mdevlist[name]['host'] = host + mdevlist[name]['total'] += length + mdevlist[name]['count'] += 1 + + # generate the html + th = '\t{0}\n' + td = '\t{0}\n' + tdr = '\t{0}\n' + tdlink = '\thtml\n' + limit = 1 + for type in sorted(devall, reverse=True): + num = 0 + devlist = devall[type] + # table header + html += '
%s (%s devices > %d ms)
\n' % \ + (title, type.upper(), limit) + html += '\n' + '' +\ + th.format('Average Time') + th.format('Count') +\ + th.format('Worst Time') + th.format('Host (worst time)') +\ + th.format('Link (worst time)') + '\n' + for name in sorted(devlist, key=lambda k:devlist[k]['worst'], reverse=True): + data = devall[type][name] + data['average'] = data['total'] / data['count'] + if data['average'] < limit: + continue + # row classes - alternate row color + rcls = ['alt'] if num % 2 == 1 else [] + html += '\n' if len(rcls) > 0 else '\n' + html += tdr.format(data['name']) # name + html += td.format('%.3f ms' % data['average']) # average + html += td.format(data['count']) # count + html += td.format('%.3f ms' % data['worst']) # worst + html += td.format(data['host']) # host + html += tdlink.format(data['url']) # url + html += '\n' + num += 1 + html += '
Device Name
\n' + + # flush the data to file + hf = open(htmlfile, 'w') + hf.write(html+'\n\n') + hf.close() + return devall + +def createHTMLIssuesSummary(issues, htmlfile, title): + html = summaryCSS('Issues Summary - SleepGraph', False) + + # generate the html + th = '\t{0}\n' + td = '\t{1}\n' + tdlink = '{0}' + subtitle = '%d issues' % len(issues) if len(issues) > 0 else 'no issues' + html += '
%s (%s)
\n' % (title, subtitle) + html += '\n' + th.format('Count') + th.format('Issue') +\ + th.format('Hosts') + th.format('First Instance') + '\n' + + num = 0 + for e in sorted(issues, key=lambda v:v['count'], reverse=True): + links = [] + for host in sorted(e['urls']): + links.append(tdlink.format(host, e['urls'][host])) + # row classes - alternate row color + rcls = ['alt'] if num % 2 == 1 else [] + html += '\n' if len(rcls) > 0 else '\n' + html += td.format('center', e['count']) # count + html += td.format('left', e['line']) # issue + html += td.format('center', len(e['urls'])) # hosts + html += td.format('center nowrap', '
'.join(links)) # links + html += '\n' + num += 1 + + # flush the data to file + hf = open(htmlfile, 'w') + hf.write(html+'
\n\n\n') + hf.close() + return issues + def ordinal(value): suffix = 'th' if value < 10 or value > 19: @@ -4621,6 +4817,7 @@ def executeSuspend(): pprint('SUSPEND START') else: pprint('SUSPEND START (press a key to resume)') + sysvals.mcelog(True) bat1 = getBattery() if battery else False # set rtcwake if(sysvals.rtcwake): @@ -4652,13 +4849,21 @@ def executeSuspend(): pf = open(sysvals.diskpowerfile, 'w') pf.write(sysvals.diskmode) pf.close() - pf = open(sysvals.powerfile, 'w') - pf.write(mode) - # execution will pause here - try: - pf.close() - except Exception as e: - tdata['error'] = str(e) + if mode == 'freeze' and sysvals.haveTurbostat(): + # execution will pause here + turbo = sysvals.turbostat() + if '|' in turbo: + tdata['turbo'] = turbo + else: + tdata['error'] = turbo + else: + pf = open(sysvals.powerfile, 'w') + pf.write(mode) + # execution will pause here + try: + pf.close() + except Exception as e: + tdata['error'] = str(e) if(sysvals.rtcwake): sysvals.rtcWakeAlarmOff() # postdelay delay @@ -4672,6 +4877,9 @@ def executeSuspend(): sysvals.fsetVal('RESUME COMPLETE', 'trace_marker') if(sysvals.suspendmode == 'mem' or sysvals.suspendmode == 'command'): tdata['fw'] = getFPDT(False) + mcelog = sysvals.mcelog() + if mcelog: + tdata['mcelog'] = mcelog bat2 = getBattery() if battery else False if battery and bat1 and bat2: tdata['bat'] = (bat1, bat2) @@ -4694,6 +4902,7 @@ def executeSuspend(): op.close() sysvals.fsetVal('', 'trace') devProps() + return testdata def readFile(file): if os.path.islink(file): @@ -5398,6 +5607,12 @@ def processData(live=False): appendIncompleteTraceLog(testruns) sysvals.vprint('Command:\n %s' % sysvals.cmdline) for data in testruns: + if data.mcelog: + sysvals.vprint('MCELOG Data:') + for line in data.mcelog.split('\n'): + sysvals.vprint(' %s' % line) + if data.turbostat: + sysvals.vprint('Turbostat:\n %s' % data.turbostat.replace('|', ' ')) if data.battery: a1, c1, a2, c2 = data.battery s = 'Battery:\n Before - AC: %s, Charge: %d\n After - AC: %s, Charge: %d' % \ @@ -5431,7 +5646,10 @@ def rerunTest(): doesTraceLogHaveTraceEvents() if not sysvals.dmesgfile and not sysvals.usetraceevents: doError('recreating this html output requires a dmesg file') - sysvals.setOutputFile() + if sysvals.outdir: + sysvals.htmlfile = sysvals.outdir + else: + sysvals.setOutputFile() if os.path.exists(sysvals.htmlfile): if not os.path.isfile(sysvals.htmlfile): doError('a directory already exists with this name: %s' % sysvals.htmlfile) @@ -5450,14 +5668,18 @@ def runTest(n=0): sysvals.initTestOutput('suspend') # execute the test - executeSuspend() + testdata = executeSuspend() sysvals.cleanupFtrace() if sysvals.skiphtml: sysvals.sudoUserchown(sysvals.testdir) return - testruns, stamp = processData(True) - for data in testruns: - del data + if len(testdata) > 0 and not testdata[0]['error']: + testruns, stamp = processData(True) + for data in testruns: + del data + else: + stamp = testdata[0] + sysvals.sudoUserchown(sysvals.testdir) sysvals.outputResult(stamp, n) if 'error' in stamp: @@ -5487,8 +5709,13 @@ def find_in_html(html, start, end, firstonly=True): return '' return out -def data_from_html(file, outpath, devlist=False): - html = open(file, 'r').read() +def data_from_html(file, outpath, issues): + if '' not in file: + html = open(file, 'r').read() + sysvals.htmlfile = os.path.relpath(file, outpath) + else: + html = file + # extract general info suspend = find_in_html(html, 'Kernel Suspend', 'ms') resume = find_in_html(html, 'Kernel Resume', 'ms') line = find_in_html(html, '
', '
') @@ -5499,6 +5726,7 @@ def data_from_html(file, outpath, devlist=False): dt = datetime.strptime(' '.join(stmp[3:]), '%B %d %Y, %I:%M:%S %p') except: return False + sysvals.hostname = stmp[0] tstr = dt.strftime('%Y/%m/%d %H:%M:%S') error = find_in_html(html, '') if error: @@ -5509,13 +5737,39 @@ def data_from_html(file, outpath, devlist=False): result = 'fail' else: result = 'pass' + # extract error info ilist = [] - e = find_in_html(html, 'class="err"[\w=":;\.%\- ]*>', '→', False) - for i in list(set(e)): - ilist.append('%sx%d' % (i, e.count(i)) if e.count(i) > 1 else i) + log = find_in_html(html, '').strip() + if log: + d = Data(0) + d.end = 999999999 + d.dmesgtext = log.split('\n') + d.extractErrorInfo(issues) + elist = dict() + for dir in d.errorinfo: + for err in d.errorinfo[dir]: + if err[0] not in elist: + elist[err[0]] = 0 + elist[err[0]] += 1 + for i in elist: + ilist.append('%sx%d' % (i, elist[i]) if elist[i] > 1 else i) low = find_in_html(html, 'freeze time: ', ' ms') if low and '|' in low: - ilist.append('FREEZEx%d' % len(low.split('|'))) + issue = 'FREEZEx%d' % len(low.split('|')) + match = [i for i in issues if i['match'] == issue] + if len(match) > 0: + match[0]['count'] += 1 + if sysvals.hostname not in match[0]['urls']: + match[0]['urls'][sysvals.hostname] = sysvals.htmlfile + else: + issues.append({ + 'match': issue, 'count': 1, 'line': issue, + 'urls': {sysvals.hostname: sysvals.htmlfile}, + }) + ilist.append(issue) + + # extract device info devices = dict() for line in html.split('\n'): m = re.match(' *
.*)\" class=\"thread.*', line) @@ -5527,19 +5781,23 @@ def data_from_html(file, outpath, devlist=False): name, time, phase = m.group('n'), m.group('t'), m.group('p') if ' async' in name or ' sync' in name: name = ' '.join(name.split(' ')[:-1]) - d = phase.split('_')[0] + if phase.startswith('suspend'): + d = 'suspend' + elif phase.startswith('resume'): + d = 'resume' + else: + continue if d not in devices: devices[d] = dict() if name not in devices[d]: devices[d][name] = 0.0 devices[d][name] += float(time) - worst = {'suspend': {'name':'', 'time': 0.0}, - 'resume': {'name':'', 'time': 0.0}} - for d in devices: - if d not in worst: - worst[d] = dict() - dev = devices[d] - if len(dev.keys()) > 0: + # create worst device info + worst = dict() + for d in ['suspend', 'resume']: + worst[d] = {'name':'', 'time': 0.0} + dev = devices[d] if d in devices else 0 + if dev and len(dev.keys()) > 0: n = sorted(dev, key=dev.get, reverse=True)[0] worst[d]['name'], worst[d]['time'] = n, dev[n] data = { @@ -5551,14 +5809,13 @@ def data_from_html(file, outpath, devlist=False): 'issues': ' '.join(ilist), 'suspend': suspend, 'resume': resume, + 'devlist': devices, 'sus_worst': worst['suspend']['name'], 'sus_worsttime': worst['suspend']['time'], 'res_worst': worst['resume']['name'], 'res_worsttime': worst['resume']['time'], - 'url': os.path.relpath(file, outpath), + 'url': sysvals.htmlfile, } - if devlist: - data['devlist'] = devices return data # Function: runSummary @@ -5567,7 +5824,7 @@ def data_from_html(file, outpath, devlist=False): def runSummary(subdir, local=True, genhtml=False): inpath = os.path.abspath(subdir) outpath = os.path.abspath('.') if local else inpath - pprint('Generating a summary of folder "%s"' % inpath) + pprint('Generating a summary of folder:\n %s' % inpath) if genhtml: for dirname, dirnames, filenames in os.walk(subdir): sysvals.dmesgfile = sysvals.ftracefile = sysvals.htmlfile = '' @@ -5583,26 +5840,31 @@ def runSummary(subdir, local=True, genhtml=False): if sysvals.dmesgfile: pprint('DMESG : %s' % sysvals.dmesgfile) rerunTest() + issues = [] testruns = [] desc = {'host':[],'mode':[],'kernel':[]} for dirname, dirnames, filenames in os.walk(subdir): for filename in filenames: if(not re.match('.*.html', filename)): continue - data = data_from_html(os.path.join(dirname, filename), outpath) + data = data_from_html(os.path.join(dirname, filename), outpath, issues) if(not data): continue testruns.append(data) for key in desc: if data[key] not in desc[key]: desc[key].append(data[key]) - outfile = os.path.join(outpath, 'summary.html') - pprint('Summary file: %s' % outfile) + pprint('Summary files:') if len(desc['host']) == len(desc['mode']) == len(desc['kernel']) == 1: title = '%s %s %s' % (desc['host'][0], desc['kernel'][0], desc['mode'][0]) else: title = inpath - createHTMLSummarySimple(testruns, outfile, title) + createHTMLSummarySimple(testruns, os.path.join(outpath, 'summary.html'), title) + pprint(' summary.html - tabular list of test data found') + createHTMLDeviceSummary(testruns, os.path.join(outpath, 'summary-devices.html'), title) + pprint(' summary-devices.html - kernel device list sorted by total execution time') + createHTMLIssuesSummary(issues, os.path.join(outpath, 'summary-issues.html'), title) + pprint(' summary-issues.html - kernel issues found sorted by frequency') # Function: checkArgBool # Description: From 45dd0a42b90bed6cb8c63e7f88f62bf5662c2413 Mon Sep 17 00:00:00 2001 From: Todd Brandt Date: Tue, 14 May 2019 10:53:58 -0700 Subject: [PATCH 04/13] Update to pm-graph 5.4 bootgraph: - dmesg log format has changed, update parser in two places - fix prints in preparation for upgrade to python3 sleepgraph: - fix prints in preparation for upgrade to python3 - add new trace events and kprobes to cover freeze more completely - add new -ftop callgraph trace over suspend_devices_and_enter - add -wifi option to check if a wifi connection is active - add -skipkprobe option to suppress unwanted kprobes in dev mode - add kernel params and sysinfo to the log output - don't crash if /dev/mem is throwing IO errors, ignore FPDT and DMI - fix kprobe length calculation when calls are recursive - add several new kernel issue definitions for USB, ACPI, ATA, etc - enable turbostat output to be read from stdout instead of from file - add BIOS call data to the timeline from acpi_ps_execute_method kprobe Signed-off-by: Todd Brandt Signed-off-by: Rafael J. Wysocki --- tools/power/pm-graph/bootgraph.py | 8 +- tools/power/pm-graph/sleepgraph.py | 491 ++++++++++++++++++++--------- 2 files changed, 347 insertions(+), 152 deletions(-) diff --git a/tools/power/pm-graph/bootgraph.py b/tools/power/pm-graph/bootgraph.py index 6dae57041537..d7f4bd152bf1 100755 --- a/tools/power/pm-graph/bootgraph.py +++ b/tools/power/pm-graph/bootgraph.py @@ -333,9 +333,9 @@ def parseKernelLog(): if(not sysvals.stamp['kernel']): sysvals.stamp['kernel'] = sysvals.kernelVersion(msg) continue - m = re.match('.* setting system clock to (?P.*) UTC.*', msg) + m = re.match('.* setting system clock to (?P[0-9\-]*)[ A-Z](?P[0-9:]*) UTC.*', msg) if(m): - bt = datetime.strptime(m.group('t'), '%Y-%m-%d %H:%M:%S') + bt = datetime.strptime(m.group('d')+' '+m.group('t'), '%Y-%m-%d %H:%M:%S') bt = bt - timedelta(seconds=int(ktime)) data.boottime = bt.strftime('%Y-%m-%d_%H:%M:%S') sysvals.stamp['time'] = bt.strftime('%B %d %Y, %I:%M:%S %p') @@ -356,7 +356,7 @@ def parseKernelLog(): data.newAction(phase, f, pid, start, ktime, int(r), int(t)) del devtemp[f] continue - if(re.match('^Freeing unused kernel memory.*', msg)): + if(re.match('^Freeing unused kernel .*', msg)): data.tUserMode = ktime data.dmesg['kernel']['end'] = ktime data.dmesg['user']['start'] = ktime @@ -1016,7 +1016,7 @@ if __name__ == '__main__': updateKernelParams() elif cmd == 'flistall': for f in sysvals.getBootFtraceFilterFunctions(): - print f + print(f) elif cmd == 'checkbl': sysvals.getBootLoader() pprint('Boot Loader: %s\n%s' % (sysvals.bootloader, sysvals.blexec)) diff --git a/tools/power/pm-graph/sleepgraph.py b/tools/power/pm-graph/sleepgraph.py index 41d28d63e7c9..ccd0f3917c51 100755 --- a/tools/power/pm-graph/sleepgraph.py +++ b/tools/power/pm-graph/sleepgraph.py @@ -17,9 +17,9 @@ # # Links: # Home Page -# https://01.org/suspendresume +# https://01.org/pm-graph # Source repo -# git@github.com:01org/pm-graph +# git@github.com:intel/pm-graph # # Description: # This tool is designed to assist kernel and OS developers in optimizing @@ -32,6 +32,7 @@ # viewed in firefox or chrome. # # The following kernel build options are required: +# CONFIG_DEVMEM=y # CONFIG_PM_DEBUG=y # CONFIG_PM_SLEEP_DEBUG=y # CONFIG_FTRACE=y @@ -75,7 +76,7 @@ def pprint(msg): # store system values and test parameters class SystemValues: title = 'SleepGraph' - version = '5.3' + version = '5.4' ansi = False rs = 0 display = '' @@ -83,8 +84,9 @@ class SystemValues: sync = False verbose = False testlog = True - dmesglog = False + dmesglog = True ftracelog = False + tstat = False mindevlen = 0.0 mincglen = 0.0 cgphase = '' @@ -108,6 +110,8 @@ class SystemValues: pmdpath = '/sys/power/pm_debug_messages' traceevents = [ 'suspend_resume', + 'wakeup_source_activate', + 'wakeup_source_deactivate', 'device_pm_callback_end', 'device_pm_callback_start' ] @@ -139,6 +143,8 @@ class SystemValues: x2delay = 0 skiphtml = False usecallgraph = False + ftopfunc = 'suspend_devices_and_enter' + ftop = False usetraceevents = False usetracemarkers = True usekprobes = True @@ -167,6 +173,13 @@ class SystemValues: 'acpi_hibernation_leave': {}, 'acpi_pm_freeze': {}, 'acpi_pm_thaw': {}, + 'acpi_s2idle_end': {}, + 'acpi_s2idle_sync': {}, + 'acpi_s2idle_begin': {}, + 'acpi_s2idle_prepare': {}, + 'acpi_s2idle_wake': {}, + 'acpi_s2idle_wakeup': {}, + 'acpi_s2idle_restore': {}, 'hibernate_preallocate_memory': {}, 'create_basic_memory_bitmaps': {}, 'swsusp_write': {}, @@ -203,7 +216,11 @@ class SystemValues: 'rt_mutex_slowlock': {'ub': 1}, # ACPI 'acpi_resume_power_resources': {}, - 'acpi_ps_parse_aml': {}, + 'acpi_ps_execute_method': { 'args_x86_64': { + 'fullpath':'+0(+40(%di)):string', + }}, + # mei_me + 'mei_reset': {}, # filesystem 'ext4_sync_fs': {}, # 80211 @@ -252,6 +269,7 @@ class SystemValues: timeformat = '%.3f' cmdline = '%s %s' % \ (os.path.basename(sys.argv[0]), ' '.join(sys.argv[1:])) + kparams = '' sudouser = '' def __init__(self): self.archargs = 'args_'+platform.machine() @@ -330,6 +348,7 @@ class SystemValues: args['date'] = n.strftime('%y%m%d') args['time'] = n.strftime('%H%M%S') args['hostname'] = args['host'] = self.hostname + args['mode'] = self.suspendmode return value.format(**args) def setOutputFile(self): if self.dmesgfile != '': @@ -341,7 +360,7 @@ class SystemValues: if(m): self.htmlfile = m.group('name')+'.html' def systemInfo(self, info): - p = c = m = b = '' + p = m = '' if 'baseboard-manufacturer' in info: m = info['baseboard-manufacturer'] elif 'system-manufacturer' in info: @@ -352,12 +371,17 @@ class SystemValues: p = info['baseboard-product-name'] if m[:5].lower() == 'intel' and 'baseboard-product-name' in info: p = info['baseboard-product-name'] - if 'processor-version' in info: - c = info['processor-version'] - if 'bios-version' in info: - b = info['bios-version'] - self.sysstamp = '# sysinfo | man:%s | plat:%s | cpu:%s | bios:%s | numcpu:%d | memsz:%d | memfr:%d' % \ - (m, p, c, b, self.cpucount, self.memtotal, self.memfree) + c = info['processor-version'] if 'processor-version' in info else '' + b = info['bios-version'] if 'bios-version' in info else '' + r = info['bios-release-date'] if 'bios-release-date' in info else '' + self.sysstamp = '# sysinfo | man:%s | plat:%s | cpu:%s | bios:%s | biosdate:%s | numcpu:%d | memsz:%d | memfr:%d' % \ + (m, p, c, b, r, self.cpucount, self.memtotal, self.memfree) + try: + kcmd = open('/proc/cmdline', 'r').read().strip() + except: + kcmd = '' + if kcmd: + self.sysstamp += '\n# kparams | %s' % kcmd def printSystemInfo(self, fatal=False): self.rootCheck(True) out = dmidecode(self.mempath, fatal) @@ -365,10 +389,10 @@ class SystemValues: return fmt = '%-24s: %s' for name in sorted(out): - print fmt % (name, out[name]) - print fmt % ('cpucount', ('%d' % self.cpucount)) - print fmt % ('memtotal', ('%d kB' % self.memtotal)) - print fmt % ('memfree', ('%d kB' % self.memfree)) + print(fmt % (name, out[name])) + print(fmt % ('cpucount', ('%d' % self.cpucount))) + print(fmt % ('memtotal', ('%d kB' % self.memtotal))) + print(fmt % ('memfree', ('%d kB' % self.memfree))) def cpuInfo(self): self.cpucount = 0 fp = open('/proc/cpuinfo', 'r') @@ -388,7 +412,7 @@ class SystemValues: def initTestOutput(self, name): self.prefix = self.hostname v = open('/proc/version', 'r').read().strip() - kver = string.split(v)[2] + kver = v.split()[2] fmt = name+'-%m%d%y-%H%M%S' testtime = datetime.now().strftime(fmt) self.teststamp = \ @@ -403,7 +427,7 @@ class SystemValues: self.htmlfile = \ self.testdir+'/'+self.prefix+'_'+self.suspendmode+'.html' if not os.path.isdir(self.testdir): - os.mkdir(self.testdir) + os.makedirs(self.testdir) def getValueList(self, value): out = [] for i in value.split(','): @@ -414,6 +438,12 @@ class SystemValues: self.devicefilter = self.getValueList(value) def setCallgraphFilter(self, value): self.cgfilter = self.getValueList(value) + def skipKprobes(self, value): + for k in self.getValueList(value): + if k in self.tracefuncs: + del self.tracefuncs[k] + if k in self.dev_tracefuncs: + del self.dev_tracefuncs[k] def setCallgraphBlacklist(self, file): self.cgblacklist = self.listFromFile(file) def rtcWakeAlarmOn(self): @@ -483,9 +513,9 @@ class SystemValues: if 'func' in self.tracefuncs[i]: i = self.tracefuncs[i]['func'] if i in master: - print i + print(i) else: - print self.colorText(i) + print(self.colorText(i)) def setFtraceFilterFunctions(self, list): master = self.listFromFile(self.tpath+'available_filter_functions') flist = '' @@ -728,7 +758,10 @@ class SystemValues: cf.append(self.tracefuncs[fn]['func']) else: cf.append(fn) - self.setFtraceFilterFunctions(cf) + if self.ftop: + self.setFtraceFilterFunctions([self.ftopfunc]) + else: + self.setFtraceFilterFunctions(cf) # initialize the kprobe trace elif self.usekprobes: for name in self.tracefuncs: @@ -788,6 +821,14 @@ class SystemValues: if 'bat' in test: (a1, c1), (a2, c2) = test['bat'] fp.write('# battery %s %d %s %d\n' % (a1, c1, a2, c2)) + if 'wifi' in test: + wstr = [] + for wifi in test['wifi']: + tmp = [] + for key in sorted(wifi): + tmp.append('%s:%s' % (key, wifi[key])) + wstr.append('|'.join(tmp)) + fp.write('# wifi %s\n' % (','.join(wstr))) if test['error'] or len(testdata) > 1: fp.write('# enter_sleep_error %s\n' % test['error']) return fp @@ -852,26 +893,22 @@ class SystemValues: return '' return base64.b64encode(out.encode('zlib')) def haveTurbostat(self): + if not self.tstat: + return False cmd = self.getExec('turbostat') if not cmd: return False fp = Popen([cmd, '-v'], stdout=PIPE, stderr=PIPE).stderr out = fp.read().strip() fp.close() - return re.match('turbostat version [0-8.]* .*', out) + return re.match('turbostat version [0-9\.]* .*', out) def turbostat(self): cmd = self.getExec('turbostat') if not cmd: return 'missing turbostat executable' - outfile = '/tmp/pm-graph-turbostat.txt' - res = call('%s -o %s -q -S echo freeze > %s' % \ - (cmd, outfile, self.powerfile), shell=True) - if res != 0: - return 'turbosat returned %d' % res - if not os.path.exists(outfile): - return 'turbostat output missing' - fp = open(outfile, 'r') text = [] + fullcmd = '%s -q -S echo freeze > %s' % (cmd, self.powerfile) + fp = Popen(['sh', '-c', fullcmd], stdout=PIPE, stderr=PIPE).stderr for line in fp: if re.match('[0-9.]* sec', line): continue @@ -888,6 +925,60 @@ class SystemValues: values.append(line[idx]) out.append('%s=%s' % (key, ','.join(values))) return '|'.join(out) + def checkWifi(self): + out = dict() + iwcmd, ifcmd = self.getExec('iwconfig'), self.getExec('ifconfig') + if not iwcmd or not ifcmd: + return out + fp = Popen(iwcmd, stdout=PIPE, stderr=PIPE).stdout + for line in fp: + m = re.match('(?P\S*) .* ESSID:(?P\S*)', line) + if not m: + continue + out['device'] = m.group('dev') + if '"' in m.group('ess'): + out['essid'] = m.group('ess').strip('"') + break + fp.close() + if 'device' in out: + fp = Popen([ifcmd, out['device']], stdout=PIPE, stderr=PIPE).stdout + for line in fp: + m = re.match('.* inet (?P[0-9\.]*)', line) + if m: + out['ip'] = m.group('ip') + break + fp.close() + return out + def errorSummary(self, errinfo, msg): + found = False + for entry in errinfo: + if re.match(entry['match'], msg): + entry['count'] += 1 + if self.hostname not in entry['urls']: + entry['urls'][self.hostname] = [self.htmlfile] + elif self.htmlfile not in entry['urls'][self.hostname]: + entry['urls'][self.hostname].append(self.htmlfile) + found = True + break + if found: + return + arr = msg.split() + for j in range(len(arr)): + if re.match('^[0-9,\-\.]*$', arr[j]): + arr[j] = '[0-9,\-\.]*' + else: + arr[j] = arr[j]\ + .replace('\\', '\\\\').replace(']', '\]').replace('[', '\[')\ + .replace('.', '\.').replace('+', '\+').replace('*', '\*')\ + .replace('(', '\(').replace(')', '\)') + mstr = ' '.join(arr) + entry = { + 'line': msg, + 'match': mstr, + 'count': 1, + 'urls': {self.hostname: [self.htmlfile]} + } + errinfo.append(entry) sysvals = SystemValues() switchvalues = ['enable', 'disable', 'on', 'off', 'true', 'false', '1', '0'] @@ -982,7 +1073,14 @@ class Data: 'ERROR' : '.*ERROR.*', 'WARNING' : '.*WARNING.*', 'IRQ' : '.*genirq: .*', - 'TASKFAIL': '.*Freezing of tasks failed.*', + 'TASKFAIL': '.*Freezing of tasks *.*', + 'ACPI' : '.*ACPI *(?P[A-Za-z]*) *Error[: ].*', + 'DEVFAIL' : '.* failed to (?P[a-z]*) async: .*', + 'DISKFULL': '.*No space left on device.*', + 'USBERR' : '.*usb .*device .*, error [0-9-]*', + 'ATAERR' : ' *ata[0-9\.]*: .*failed.*', + 'MEIERR' : ' *mei.*: .*failed.*', + 'TPMERR' : '(?i) *tpm *tpm[0-9]*: .*error.*', } def __init__(self, num): idchar = 'abcdefghij' @@ -1000,6 +1098,7 @@ class Data: self.outfile = '' self.kerror = False self.battery = 0 + self.wifi = 0 self.turbostat = 0 self.mcelog = 0 self.enterfail = '' @@ -1036,35 +1135,21 @@ class Data: if len(plist) < 1: return '' return plist[-1] - def errorSummary(self, errinfo, msg): - found = False - for entry in errinfo: - if re.match(entry['match'], msg): - entry['count'] += 1 - if sysvals.hostname not in entry['urls']: - entry['urls'][sysvals.hostname] = sysvals.htmlfile - found = True - break - if found: - return - arr = msg.split() - for j in range(len(arr)): - if re.match('^[0-9\-\.]*$', arr[j]): - arr[j] = '[0-9\-\.]*' - else: - arr[j] = arr[j]\ - .replace(']', '\]').replace('[', '\[').replace('.', '\.')\ - .replace('+', '\+').replace('*', '\*').replace('(', '\(')\ - .replace(')', '\)') - mstr = ' '.join(arr) - entry = { - 'line': msg, - 'match': mstr, - 'count': 1, - 'urls': {sysvals.hostname: sysvals.htmlfile} - } - errinfo.append(entry) - def extractErrorInfo(self, issues=0): + def turbostatInfo(self): + tp = TestProps() + out = {'syslpi':'N/A','pkgpc10':'N/A'} + for line in self.dmesgtext: + m = re.match(tp.tstatfmt, line) + if not m: + continue + for i in m.group('t').split('|'): + if 'SYS%LPI' in i: + out['syslpi'] = i.split('=')[-1]+'%' + elif 'pc10' in i: + out['pkgpc10'] = i.split('=')[-1]+'%' + break + return out + def extractErrorInfo(self): lf = self.dmesgtext if len(self.dmesgtext) < 1 and sysvals.dmesgfile: lf = sysvals.openlog(sysvals.dmesgfile, 'r') @@ -1082,19 +1167,19 @@ class Data: msg = m.group('msg') for err in self.errlist: if re.match(self.errlist[err], msg): - list.append((err, dir, t, i, i)) + list.append((msg, err, dir, t, i, i)) self.kerror = True - if not isinstance(issues, int): - self.errorSummary(issues, msg) break - for e in list: - type, dir, t, idx1, idx2 = e + msglist = [] + for msg, type, dir, t, idx1, idx2 in list: + msglist.append(msg) sysvals.vprint('kernel %s found in %s at %f' % (type, dir, t)) self.errorinfo[dir].append((type, t, idx1, idx2)) if self.kerror: sysvals.dmesglog = True if len(self.dmesgtext) < 1 and sysvals.dmesgfile: lf.close() + return msglist def setStart(self, time): self.start = time def setEnd(self, time): @@ -2147,7 +2232,7 @@ class FTraceCallGraph: if(data.dmesg[p]['start'] <= self.start and self.start <= data.dmesg[p]['end']): list = data.dmesg[p]['list'] - for devname in list: + for devname in sorted(list, key=lambda k:list[k]['start']): dev = list[devname] if(pid == dev['pid'] and self.start <= dev['start'] and @@ -2452,6 +2537,7 @@ class TestProps: '(?P[0-9]{2})(?P[0-9]{2})(?P[0-9]{2})'+\ ' (?P.*) (?P.*) (?P.*)$' batteryfmt = '^# battery (?P\w*) (?P\d*) (?P\w*) (?P\d*)' + wififmt = '^# wifi (?P.*)' tstatfmt = '^# turbostat (?P\S*)' mcelogfmt = '^# mcelog (?P\S*)' testerrfmt = '^# enter_sleep_error (?P.*)' @@ -2479,6 +2565,7 @@ class TestProps: self.mcelog = [] self.turbostat = [] self.battery = [] + self.wifi = [] self.fwdata = [] self.ftrace_line_fmt = self.ftrace_line_fmt_nop self.cgformat = False @@ -2505,6 +2592,9 @@ class TestProps: elif re.match(self.sysinfofmt, line): self.sysinfo = line return True + elif re.match(self.kparamsfmt, line): + self.kparams = line + return True elif re.match(self.cmdlinefmt, line): self.cmdline = line return True @@ -2517,6 +2607,9 @@ class TestProps: elif re.match(self.batteryfmt, line): self.battery.append(line) return True + elif re.match(self.wififmt, line): + self.wifi.append(line) + return True elif re.match(self.testerrfmt, line): self.testerror.append(line) return True @@ -2586,6 +2679,11 @@ class TestProps: m = re.match(self.batteryfmt, self.battery[data.testnumber]) if m: data.battery = m.groups() + # wifi data + if len(self.wifi) > data.testnumber: + m = re.match(self.wififmt, self.wifi[data.testnumber]) + if m: + data.wifi = m.group('w') # sleep mode enter errors if len(self.testerror) > data.testnumber: m = re.match(self.testerrfmt, self.testerror[data.testnumber]) @@ -2655,9 +2753,9 @@ class ProcessMonitor: # Quickly determine if the ftrace log has all of the trace events, # markers, and/or kprobes required for primary parsing. def doesTraceLogHaveTraceEvents(): - kpcheck = ['_cal: (', '_cpu_down()'] + kpcheck = ['_cal: (', '_ret: ('] techeck = ['suspend_resume', 'device_pm_callback'] - tmcheck = ['tracing_mark_write'] + tmcheck = ['SUSPEND START', 'RESUME COMPLETE'] sysvals.usekprobes = False fp = sysvals.openlog(sysvals.ftracefile, 'r') for line in fp: @@ -3042,7 +3140,7 @@ def parseTraceLog(live=False): tp.ktemp[key].append({ 'pid': pid, 'begin': t.time, - 'end': t.time, + 'end': -1, 'name': displayname, 'cdata': kprobedata, 'proc': m_proc, @@ -3053,12 +3151,11 @@ def parseTraceLog(live=False): elif(t.freturn): if(key not in tp.ktemp) or len(tp.ktemp[key]) < 1: continue - e = tp.ktemp[key][-1] - if e['begin'] < 0.0 or t.time - e['begin'] < 0.000001: - tp.ktemp[key].pop() - else: - e['end'] = t.time - e['rdata'] = kprobedata + e = next((x for x in reversed(tp.ktemp[key]) if x['end'] < 0), 0) + if not e: + continue + e['end'] = t.time + e['rdata'] = kprobedata # end of kernel resume if(phase != 'suspend_prepare' and kprobename in krescalls): if phase in data.dmesg: @@ -3080,8 +3177,10 @@ def parseTraceLog(live=False): if(res == -1): testrun.ftemp[key][-1].addLine(t) tf.close() + if len(testdata) < 1: + sysvals.vprint('WARNING: ftrace start marker is missing') if data and not data.devicegroups: - sysvals.vprint('WARNING: end marker is missing') + sysvals.vprint('WARNING: ftrace end marker is missing') data.handleEndMarker(t.time) if sysvals.suspendmode == 'command': @@ -3130,9 +3229,11 @@ def parseTraceLog(live=False): name, pid = key if name not in sysvals.tracefuncs: continue + if pid not in data.devpids: + data.devpids.append(pid) for e in tp.ktemp[key]: kb, ke = e['begin'], e['end'] - if kb == ke or tlb > kb or tle <= kb: + if ke - kb < 0.000001 or tlb > kb or tle <= kb: continue color = sysvals.kprobeColor(name) data.newActionGlobal(e['name'], kb, ke, pid, color) @@ -3144,7 +3245,7 @@ def parseTraceLog(live=False): continue for e in tp.ktemp[key]: kb, ke = e['begin'], e['end'] - if kb == ke or tlb > kb or tle <= kb: + if ke - kb < 0.000001 or tlb > kb or tle <= kb: continue data.addDeviceFunctionCall(e['name'], name, e['proc'], pid, kb, ke, e['cdata'], e['rdata']) @@ -3168,7 +3269,7 @@ def parseTraceLog(live=False): if not devname: sortkey = '%f%f%d' % (cg.start, cg.end, pid) sortlist[sortkey] = cg - elif len(cg.list) > 1000000: + elif len(cg.list) > 1000000 and cg.name != sysvals.ftopfunc: sysvals.vprint('WARNING: the callgraph for %s is massive (%d lines)' %\ (devname, len(cg.list))) # create blocks for orphan cg data @@ -3275,7 +3376,7 @@ def loadKernelLog(): if data: testruns.append(data) if len(testruns) < 1: - pprint('ERROR: dmesg log has no suspend/resume data: %s' \ + doError('dmesg log has no suspend/resume data: %s' \ % sysvals.dmesgfile) # fix lines with same timestamp/function with the call and return swapped @@ -3614,6 +3715,8 @@ def addCallgraphs(sv, hf, data): name += ' '+p if('ftrace' in dev): cg = dev['ftrace'] + if cg.name == sv.ftopfunc: + name = 'top level suspend/resume call' num = callgraphHTML(sv, hf, num, cg, name, color, dev['id']) if('ftraces' in dev): @@ -3653,9 +3756,10 @@ def createHTMLSummarySimple(testruns, htmlfile, title): # extract the test data into list list = dict() - tAvg, tMin, tMax, tMed = [0.0, 0.0], [0.0, 0.0], [0.0, 0.0], [[], []] + tAvg, tMin, tMax, tMed = [0.0, 0.0], [0.0, 0.0], [0.0, 0.0], [dict(), dict()] iMin, iMed, iMax = [0, 0], [0, 0], [0, 0] num = 0 + useturbo = False lastmode = '' cnt = dict() for data in sorted(testruns, key=lambda v:(v['mode'], v['host'], v['kernel'], v['time'])): @@ -3666,20 +3770,25 @@ def createHTMLSummarySimple(testruns, htmlfile, title): for i in range(2): s = sorted(tMed[i]) list[lastmode]['med'][i] = s[int(len(s)/2)] - iMed[i] = tMed[i].index(list[lastmode]['med'][i]) + iMed[i] = tMed[i][list[lastmode]['med'][i]] list[lastmode]['avg'] = [tAvg[0] / num, tAvg[1] / num] list[lastmode]['min'] = tMin list[lastmode]['max'] = tMax list[lastmode]['idx'] = (iMin, iMed, iMax) - tAvg, tMin, tMax, tMed = [0.0, 0.0], [0.0, 0.0], [0.0, 0.0], [[], []] + tAvg, tMin, tMax, tMed = [0.0, 0.0], [0.0, 0.0], [0.0, 0.0], [dict(), dict()] iMin, iMed, iMax = [0, 0], [0, 0], [0, 0] num = 0 + pkgpc10 = syslpi = '' + if 'pkgpc10' in data and 'syslpi' in data: + pkgpc10 = data['pkgpc10'] + syslpi = data['syslpi'] + useturbo = True res = data['result'] tVal = [float(data['suspend']), float(data['resume'])] list[mode]['data'].append([data['host'], data['kernel'], data['time'], tVal[0], tVal[1], data['url'], res, data['issues'], data['sus_worst'], data['sus_worsttime'], - data['res_worst'], data['res_worsttime']]) + data['res_worst'], data['res_worsttime'], pkgpc10, syslpi]) idx = len(list[mode]['data']) - 1 if res.startswith('fail in'): res = 'fail' @@ -3689,7 +3798,7 @@ def createHTMLSummarySimple(testruns, htmlfile, title): cnt[res] += 1 if res == 'pass': for i in range(2): - tMed[i].append(tVal[i]) + tMed[i][tVal[i]] = idx tAvg[i] += tVal[i] if tMin[i] == 0 or tVal[i] < tMin[i]: iMin[i] = idx @@ -3703,7 +3812,7 @@ def createHTMLSummarySimple(testruns, htmlfile, title): for i in range(2): s = sorted(tMed[i]) list[lastmode]['med'][i] = s[int(len(s)/2)] - iMed[i] = tMed[i].index(list[lastmode]['med'][i]) + iMed[i] = tMed[i][list[lastmode]['med'][i]] list[lastmode]['avg'] = [tAvg[0] / num, tAvg[1] / num] list[lastmode]['min'] = tMin list[lastmode]['max'] = tMax @@ -3719,6 +3828,7 @@ def createHTMLSummarySimple(testruns, htmlfile, title): td = '\t
\n' tdh = '\t{0}\n' tdlink = '\t\n' + colspan = '14' if useturbo else '12' # table header html += '
', '{0}html
\n\n' + th.format('#') +\ @@ -3726,12 +3836,13 @@ def createHTMLSummarySimple(testruns, htmlfile, title): th.format('Test Time') + th.format('Result') + th.format('Issues') +\ th.format('Suspend') + th.format('Resume') +\ th.format('Worst Suspend Device') + th.format('SD Time') +\ - th.format('Worst Resume Device') + th.format('RD Time') +\ - th.format('Detail') + '\n' - + th.format('Worst Resume Device') + th.format('RD Time') + if useturbo: + html += th.format('PkgPC10') + th.format('SysLPI') + html += th.format('Detail')+'\n' # export list into html head = ''+\ - ''+\ '\n' - headnone = '\n' + headnone = '\n' for mode in list: # header line for each suspend mode num = 0 @@ -3787,6 +3899,9 @@ def createHTMLSummarySimple(testruns, htmlfile, title): html += td.format('%.3f ms' % d[9]) if d[9] else td.format('') # sus_worst time html += td.format(d[10]) # res_worst html += td.format('%.3f ms' % d[11]) if d[11] else td.format('') # res_worst time + if useturbo: + html += td.format(d[12]) # pkg_pc10 + html += td.format(d[13]) # syslpi html += tdlink.format(d[5]) if d[5] else td.format('') # url html += '\n' num += 1 @@ -3861,8 +3976,10 @@ def createHTMLDeviceSummary(testruns, htmlfile, title): hf.close() return devall -def createHTMLIssuesSummary(issues, htmlfile, title): +def createHTMLIssuesSummary(testruns, issues, htmlfile, title, extra=''): + multihost = len([e for e in issues if len(e['urls']) > 1]) > 0 html = summaryCSS('Issues Summary - SleepGraph', False) + total = len(testruns) # generate the html th = '\t\n' @@ -3870,27 +3987,36 @@ def createHTMLIssuesSummary(issues, htmlfile, title): tdlink = '{0}' subtitle = '%d issues' % len(issues) if len(issues) > 0 else 'no issues' html += '
%s (%s)
{0}{1}Suspend Avg={2} '+\ + 'Suspend Avg={2} '+\ 'Min={3} '+\ 'Med={4} '+\ 'Max={5} '+\ @@ -3740,7 +3851,8 @@ def createHTMLSummarySimple(testruns, htmlfile, title): 'Med={8} '+\ 'Max={9}
{0}{1}
{0}{1}
{0}
\n' % (title, subtitle) - html += '\n' + th.format('Count') + th.format('Issue') +\ - th.format('Hosts') + th.format('First Instance') + '\n' + html += '\n' + th.format('Issue') + th.format('Count') + if multihost: + html += th.format('Hosts') + html += th.format('Tests') + th.format('Fail Rate') +\ + th.format('First Instance') + '\n' num = 0 for e in sorted(issues, key=lambda v:v['count'], reverse=True): + testtotal = 0 links = [] for host in sorted(e['urls']): - links.append(tdlink.format(host, e['urls'][host])) + links.append(tdlink.format(host, e['urls'][host][0])) + testtotal += len(e['urls'][host]) + rate = '%d/%d (%.2f%%)' % (testtotal, total, 100*float(testtotal)/float(total)) # row classes - alternate row color rcls = ['alt'] if num % 2 == 1 else [] html += '\n' if len(rcls) > 0 else '\n' - html += td.format('center', e['count']) # count html += td.format('left', e['line']) # issue - html += td.format('center', len(e['urls'])) # hosts + html += td.format('center', e['count']) # count + if multihost: + html += td.format('center', len(e['urls'])) # hosts + html += td.format('center', testtotal) # test count + html += td.format('center', rate) # test rate html += td.format('center nowrap', '
'.join(links)) # links html += '\n' num += 1 # flush the data to file hf = open(htmlfile, 'w') - hf.write(html+'
\n\n\n') + hf.write(html+'\n'+extra+'\n\n') hf.close() return issues @@ -4195,7 +4321,7 @@ def createHTML(testruns, testfail): for word in phase.split('_'): id += word[0] order = '%.2f' % ((p['order'] * pdelta) + pmargin) - name = string.replace(phase, '_', '  ') + name = phase.replace('_', '  ') devtl.html += devtl.html_legend.format(order, p['color'], name, id) devtl.html += '\n' @@ -4784,6 +4910,7 @@ def setRuntimeSuspend(before=True): def executeSuspend(): pm = ProcessMonitor() tp = sysvals.tpath + wifi = sysvals.checkWifi() testdata = [] battery = True if getBattery() else False # run these commands to prepare the system for suspend @@ -4857,6 +4984,8 @@ def executeSuspend(): else: tdata['error'] = turbo else: + if sysvals.haveTurbostat(): + sysvals.vprint('WARNING: ignoring turbostat in mode "%s"' % mode) pf = open(sysvals.powerfile, 'w') pf.write(mode) # execution will pause here @@ -4883,6 +5012,8 @@ def executeSuspend(): bat2 = getBattery() if battery else False if battery and bat1 and bat2: tdata['bat'] = (bat1, bat2) + if 'device' in wifi and 'ip' in wifi: + tdata['wifi'] = (wifi, sysvals.checkWifi()) testdata.append(tdata) # stop ftrace if(sysvals.usecallgraph or sysvals.usetraceevents): @@ -4989,7 +5120,7 @@ def deviceInfo(output=''): ms2nice(power['runtime_active_time']), \ ms2nice(power['runtime_suspended_time'])) for i in sorted(lines): - print lines[i] + print(lines[i]) return res # Function: devProps @@ -5122,12 +5253,12 @@ def getModes(): modes = [] if(os.path.exists(sysvals.powerfile)): fp = open(sysvals.powerfile, 'r') - modes = string.split(fp.read()) + modes = fp.read().split() fp.close() if(os.path.exists(sysvals.mempowerfile)): deep = False fp = open(sysvals.mempowerfile, 'r') - for m in string.split(fp.read()): + for m in fp.read().split(): memmode = m.strip('[]') if memmode == 'deep': deep = True @@ -5138,7 +5269,7 @@ def getModes(): modes.remove('mem') if('disk' in modes and os.path.exists(sysvals.diskpowerfile)): fp = open(sysvals.diskpowerfile, 'r') - for m in string.split(fp.read()): + for m in fp.read().split(): modes.append('disk-%s' % m.strip('[]')) fp.close() return modes @@ -5201,14 +5332,15 @@ def dmidecode(mempath, fatal=False): continue # read in the memory for scanning - fp = open(mempath, 'rb') try: + fp = open(mempath, 'rb') fp.seek(memaddr) buf = fp.read(memsize) except: if(fatal): doError('DMI table is unreachable, sorry') else: + pprint('WARNING: /dev/mem is not readable, ignoring DMI data') return out fp.close() @@ -5231,14 +5363,15 @@ def dmidecode(mempath, fatal=False): return out # read in the SM or DMI table - fp = open(mempath, 'rb') try: + fp = open(mempath, 'rb') fp.seek(base) buf = fp.read(length) except: if(fatal): doError('DMI table is unreachable, sorry') else: + pprint('WARNING: /dev/mem is not readable, ignoring DMI data') return out fp.close() @@ -5382,7 +5515,11 @@ def getFPDT(output): i = 0 fwData = [0, 0] records = buf[36:] - fp = open(sysvals.mempath, 'rb') + try: + fp = open(sysvals.mempath, 'rb') + except: + pprint('WARNING: /dev/mem is not readable, ignoring the FPDT data') + return False while(i < len(records)): header = struct.unpack('HBB', records[i:i+4]) if(header[0] not in rectype): @@ -5499,13 +5636,14 @@ def statusCheck(probecheck=False): pprint(' is ftrace supported: %s' % res) # check if kprobes are available - res = sysvals.colorText('NO') - sysvals.usekprobes = sysvals.verifyKprobes() - if(sysvals.usekprobes): - res = 'YES' - else: - sysvals.usedevsrc = False - pprint(' are kprobes supported: %s' % res) + if sysvals.usekprobes: + res = sysvals.colorText('NO') + sysvals.usekprobes = sysvals.verifyKprobes() + if(sysvals.usekprobes): + res = 'YES' + else: + sysvals.usedevsrc = False + pprint(' are kprobes supported: %s' % res) # what data source are we using res = 'DMESG' @@ -5593,6 +5731,8 @@ def getArgFloat(name, args, min, max, main=True): def processData(live=False): pprint('PROCESSING DATA') + sysvals.vprint('usetraceevents=%s, usetracemarkers=%s, usekprobes=%s' % \ + (sysvals.usetraceevents, sysvals.usetracemarkers, sysvals.usekprobes)) error = '' if(sysvals.usetraceevents): testruns, error = parseTraceLog(live) @@ -5605,6 +5745,11 @@ def processData(live=False): parseKernelLog(data) if(sysvals.ftracefile and (sysvals.usecallgraph or sysvals.usetraceevents)): appendIncompleteTraceLog(testruns) + sysvals.vprint('System Info:') + for key in sorted(sysvals.stamp): + sysvals.vprint(' %-8s : %s' % (key.upper(), sysvals.stamp[key])) + if sysvals.kparams: + sysvals.vprint('Kparams:\n %s' % sysvals.kparams) sysvals.vprint('Command:\n %s' % sysvals.cmdline) for data in testruns: if data.mcelog: @@ -5612,12 +5757,24 @@ def processData(live=False): for line in data.mcelog.split('\n'): sysvals.vprint(' %s' % line) if data.turbostat: - sysvals.vprint('Turbostat:\n %s' % data.turbostat.replace('|', ' ')) + idx, s = 0, 'Turbostat:\n ' + for val in data.turbostat.split('|'): + idx += len(val) + 1 + if idx >= 80: + idx = 0 + s += '\n ' + s += val + ' ' + sysvals.vprint(s) if data.battery: a1, c1, a2, c2 = data.battery s = 'Battery:\n Before - AC: %s, Charge: %d\n After - AC: %s, Charge: %d' % \ (a1, int(c1), a2, int(c2)) sysvals.vprint(s) + if data.wifi: + w = data.wifi.replace('|', ' ').split(',') + s = 'Wifi:\n Before %s\n After %s' % \ + (w[0], w[1]) + sysvals.vprint(s) data.printDetails() if sysvals.cgdump: for data in testruns: @@ -5641,13 +5798,13 @@ def processData(live=False): # Function: rerunTest # Description: # generate an output from an existing set of ftrace/dmesg logs -def rerunTest(): +def rerunTest(htmlfile=''): if sysvals.ftracefile: doesTraceLogHaveTraceEvents() if not sysvals.dmesgfile and not sysvals.usetraceevents: doError('recreating this html output requires a dmesg file') - if sysvals.outdir: - sysvals.htmlfile = sysvals.outdir + if htmlfile: + sysvals.htmlfile = htmlfile else: sysvals.setOutputFile() if os.path.exists(sysvals.htmlfile): @@ -5673,7 +5830,7 @@ def runTest(n=0): if sysvals.skiphtml: sysvals.sudoUserchown(sysvals.testdir) return - if len(testdata) > 0 and not testdata[0]['error']: + if not testdata[0]['error']: testruns, stamp = processData(True) for data in testruns: del data @@ -5709,15 +5866,13 @@ def find_in_html(html, start, end, firstonly=True): return '' return out -def data_from_html(file, outpath, issues): - if '' not in file: - html = open(file, 'r').read() - sysvals.htmlfile = os.path.relpath(file, outpath) - else: - html = file +def data_from_html(file, outpath, issues, fulldetail=False): + html = open(file, 'r').read() + sysvals.htmlfile = os.path.relpath(file, outpath) # extract general info suspend = find_in_html(html, 'Kernel Suspend', 'ms') resume = find_in_html(html, 'Kernel Resume', 'ms') + sysinfo = find_in_html(html, '
', '
') line = find_in_html(html, '
', '
') stmp = line.split() if not suspend or not resume or len(stmp) != 8: @@ -5739,13 +5894,18 @@ def data_from_html(file, outpath, issues): result = 'pass' # extract error info ilist = [] + extra = dict() log = find_in_html(html, '').strip() if log: d = Data(0) d.end = 999999999 d.dmesgtext = log.split('\n') - d.extractErrorInfo(issues) + msglist = d.extractErrorInfo() + for msg in msglist: + sysvals.errorSummary(issues, msg) + if stmp[2] == 'freeze': + extra = d.turbostatInfo() elist = dict() for dir in d.errorinfo: for err in d.errorinfo[dir]: @@ -5761,14 +5921,15 @@ def data_from_html(file, outpath, issues): if len(match) > 0: match[0]['count'] += 1 if sysvals.hostname not in match[0]['urls']: - match[0]['urls'][sysvals.hostname] = sysvals.htmlfile + match[0]['urls'][sysvals.hostname] = [sysvals.htmlfile] + elif sysvals.htmlfile not in match[0]['urls'][sysvals.hostname]: + match[0]['urls'][sysvals.hostname].append(sysvals.htmlfile) else: issues.append({ 'match': issue, 'count': 1, 'line': issue, - 'urls': {sysvals.hostname: sysvals.htmlfile}, + 'urls': {sysvals.hostname: [sysvals.htmlfile]}, }) ilist.append(issue) - # extract device info devices = dict() for line in html.split('\n'): @@ -5804,6 +5965,7 @@ def data_from_html(file, outpath, issues): 'mode': stmp[2], 'host': stmp[0], 'kernel': stmp[1], + 'sysinfo': sysinfo, 'time': tstr, 'result': result, 'issues': ' '.join(ilist), @@ -5816,8 +5978,28 @@ def data_from_html(file, outpath, issues): 'res_worsttime': worst['resume']['time'], 'url': sysvals.htmlfile, } + for key in extra: + data[key] = extra[key] + if fulldetail: + data['funclist'] = find_in_html(html, '
Test xset by toggling the given mode (on/off/standby/suspend)\n'\ ' -sysinfo Print out system info extracted from BIOS\n'\ ' -devinfo Print out the pm settings of all devices which support runtime suspend\n'\ @@ -6158,7 +6330,7 @@ def printHelp(): ' [redo]\n'\ ' -ftrace ftracefile Create HTML output using ftrace input (used with -dmesg)\n'\ ' -dmesg dmesgfile Create HTML output using dmesg (used with -ftrace)\n'\ - '' % (sysvals.title, sysvals.version, sysvals.suspendmode)) + '' % (sysvals.title, sysvals.version, sysvals.suspendmode, sysvals.ftopfunc)) return True # ----------------- MAIN -------------------- @@ -6168,7 +6340,7 @@ if __name__ == '__main__': cmd = '' simplecmds = ['-sysinfo', '-modes', '-fpdt', '-flist', '-flistall', '-devinfo', '-status', '-battery', '-xon', '-xoff', '-xstandby', - '-xsuspend', '-xinit', '-xreset', '-xstat'] + '-xsuspend', '-xinit', '-xreset', '-xstat', '-wifi'] if '-f' in sys.argv: sysvals.cgskip = sysvals.configFile('cgskip.txt') # loop through the command line arguments @@ -6200,6 +6372,10 @@ if __name__ == '__main__': sysvals.postdelay = getArgInt('-postdelay', args, 0, 60000) elif(arg == '-f'): sysvals.usecallgraph = True + elif(arg == '-ftop'): + sysvals.usecallgraph = True + sysvals.ftop = True + sysvals.usekprobes = False elif(arg == '-skiphtml'): sysvals.skiphtml = True elif(arg == '-cgdump'): @@ -6210,10 +6386,16 @@ if __name__ == '__main__': genhtml = True elif(arg == '-addlogs'): sysvals.dmesglog = sysvals.ftracelog = True + elif(arg == '-nologs'): + sysvals.dmesglog = sysvals.ftracelog = False elif(arg == '-addlogdmesg'): sysvals.dmesglog = True elif(arg == '-addlogftrace'): sysvals.ftracelog = True + elif(arg == '-turbostat'): + sysvals.tstat = True + if not sysvals.haveTurbostat(): + doError('Turbostat command not found') elif(arg == '-verbose'): sysvals.verbose = True elif(arg == '-proc'): @@ -6283,6 +6465,12 @@ if __name__ == '__main__': except: doError('No callgraph functions supplied', True) sysvals.setCallgraphFilter(val) + elif(arg == '-skipkprobe'): + try: + val = args.next() + except: + doError('No kprobe functions supplied', True) + sysvals.skipKprobes(val) elif(arg == '-cgskip'): try: val = args.next() @@ -6421,7 +6609,7 @@ if __name__ == '__main__': elif(cmd == 'devinfo'): deviceInfo() elif(cmd == 'modes'): - print getModes() + pprint(getModes()) elif(cmd == 'flist'): sysvals.getFtraceFilterFunctions(True) elif(cmd == 'flistall'): @@ -6433,11 +6621,18 @@ if __name__ == '__main__': ret = displayControl(cmd[1:]) elif(cmd == 'xstat'): pprint('Display Status: %s' % displayControl('stat').upper()) + elif(cmd == 'wifi'): + out = sysvals.checkWifi() + if 'device' not in out: + pprint('WIFI interface not found') + else: + for key in sorted(out): + pprint('%6s: %s' % (key.upper(), out[key])) sys.exit(ret) # if instructed, re-analyze existing data files if(sysvals.notestrun): - stamp = rerunTest() + stamp = rerunTest(sysvals.outdir) sysvals.outputResult(stamp) sys.exit(0) @@ -6474,7 +6669,7 @@ if __name__ == '__main__': s = 'suspend-x%d' % sysvals.multitest['count'] sysvals.outdir = datetime.now().strftime(s+'-%y%m%d-%H%M%S') if not os.path.isdir(sysvals.outdir): - os.mkdir(sysvals.outdir) + os.makedirs(sysvals.outdir) for i in range(sysvals.multitest['count']): if(i != 0): pprint('Waiting %d seconds...' % (sysvals.multitest['delay'])) From d5a5e4ec5b415e63dee9dd76653377455572ac09 Mon Sep 17 00:00:00 2001 From: Todd Brandt Date: Tue, 14 May 2019 10:53:59 -0700 Subject: [PATCH 05/13] Add README and update pm-graph and sleepgraph docs Config/man page/README files: - include README in the pm-graph folder - add more detail to the example config to describe more options - update the sleepgraph man page to document the new arguments Signed-off-by: Todd Brandt [ rjw: Subject ] Signed-off-by: Rafael J. Wysocki --- tools/power/pm-graph/README | 552 ++++++++++++++++++++++++ tools/power/pm-graph/config/example.cfg | 26 ++ tools/power/pm-graph/sleepgraph.8 | 16 +- 3 files changed, 592 insertions(+), 2 deletions(-) create mode 100644 tools/power/pm-graph/README diff --git a/tools/power/pm-graph/README b/tools/power/pm-graph/README new file mode 100644 index 000000000000..58a5591e3951 --- /dev/null +++ b/tools/power/pm-graph/README @@ -0,0 +1,552 @@ + p m - g r a p h + + pm-graph: suspend/resume/boot timing analysis tools + Version: 5.4 + Author: Todd Brandt + Home Page: https://01.org/pm-graph + + 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 + + - Config File Format: + https://01.org/pm-graph/documentation/3-config-file-format + + - upstream version in git: + https://github.com/intel/pm-graph/ + + Table of Contents + - Overview + - Setup + - Usage + - Basic Usage + - Dev Mode Usage + - Proc Mode Usage + - Configuration Files + - Usage Examples + - Config File Options + - Custom Timeline Entries + - Adding/Editing Timeline Functions + - Adding/Editing Dev Timeline Source Functions + - Verifying your Custom Functions + - Testing on consumer linux Operating Systems + - Android + +------------------------------------------------------------------ +| OVERVIEW | +------------------------------------------------------------------ + + This tool suite is designed to assist kernel and OS developers in optimizing + their linux stack's suspend/resume & boot time. Using a kernel image built + with a few extra options enabled, the tools will execute a suspend or boot, + and will capture dmesg and ftrace data. This data is transformed into a set of + timelines and a callgraph to give a quick and detailed view of which devices + and kernel processes are taking the most time in suspend/resume & boot. + +------------------------------------------------------------------ +| SETUP | +------------------------------------------------------------------ + + These packages are required to execute the scripts + - python + - python-requests + + Ubuntu: + sudo apt-get install python python-requests + + Fedora: + sudo dnf install python python-requests + + The tools can most easily be installed via git clone and make install + + $> git clone http://github.com/intel/pm-graph.git + $> cd pm-graph + $> sudo make install + $> man sleepgraph ; man bootgraph + + Setup involves some minor kernel configuration + + The following kernel build options are required for all kernels: + CONFIG_DEVMEM=y + CONFIG_PM_DEBUG=y + CONFIG_PM_SLEEP_DEBUG=y + CONFIG_FTRACE=y + CONFIG_FUNCTION_TRACER=y + CONFIG_FUNCTION_GRAPH_TRACER=y + CONFIG_KPROBES=y + CONFIG_KPROBES_ON_FTRACE=y + + In kernel 3.15.0, two patches were upstreamed which enable the + v3.0 behavior. These patches allow the tool to read all the + data from trace events instead of from dmesg. You can enable + this behavior on earlier kernels with these patches: + + (kernel/pre-3.15/enable_trace_events_suspend_resume.patch) + (kernel/pre-3.15/enable_trace_events_device_pm_callback.patch) + + If you're using a kernel older than 3.15.0, the following + additional kernel parameters are required: + (e.g. in file /etc/default/grub) + GRUB_CMDLINE_LINUX_DEFAULT="... initcall_debug log_buf_len=32M ..." + + If you're using a kernel older than 3.11-rc2, the following simple + patch must be applied to enable ftrace data: + in file: kernel/power/suspend.c + in function: int suspend_devices_and_enter(suspend_state_t state) + remove call to "ftrace_stop();" + remove call to "ftrace_start();" + + There is a patch which does this for kernel v3.8.0: + (kernel/pre-3.11-rc2/enable_ftrace_in_suspendresume.patch) + + + +------------------------------------------------------------------ +| USAGE | +------------------------------------------------------------------ + +Basic Usage +___________ + + 1) First configure a kernel using the instructions from the previous sections. + Then build, install, and boot with it. + 2) Open up a terminal window and execute the mode list command: + + %> sudo ./sleepgraph.py -modes + ['freeze', 'mem', 'disk'] + + Execute a test using one of the available power modes, e.g. mem (S3): + + %> sudo ./sleepgraph.py -m mem -rtcwake 15 + + or with a config file + + %> sudo ./sleepgraph.py -config config/suspend.cfg + + When the system comes back you'll see the script finishing up and + creating the output files in the test subdir. It generates output + files in subdirectory: suspend-mmddyy-HHMMSS. The ftrace file can + be used to regenerate the html timeline with different options + + HTML output: _.html + raw dmesg output: __dmesg.txt + raw ftrace output: __ftrace.txt + + View the html in firefox or chrome. + + +Dev Mode Usage +______________ + + Developer mode adds information on low level source calls to the timeline. + The tool sets kprobes on all delay and mutex calls to see which devices + are waiting for something and when. It also sets a suite of kprobes on + subsystem dependent calls to better fill out the timeline. + + The tool will also expose kernel threads that don't normally show up in the + timeline. This is useful in discovering dependent threads to get a better + idea of what each device is waiting for. For instance, the scsi_eh thread, + a.k.a. scsi resume error handler, is what each SATA disk device waits for + before it can continue resume. + + The timeline will be much larger if run with dev mode, so it can be useful + to set the -mindev option to clip out any device blocks that are too small + to see easily. The following command will give a nice dev mode run: + + %> sudo ./sleepgraph.py -m mem -rtcwake 15 -mindev 1 -dev + + or with a config file + + %> sudo ./sleepgraph.py -config config/suspend-dev.cfg + + +Proc Mode Usage +_______________ + + Proc mode adds user process info to the timeline. This is done in a manner + similar to the bootchart utility, which graphs init processes and their + execution as the system boots. This tool option does the same thing but for + the period before and after suspend/resume. + + In order to see any process info, there needs to be some delay before or + after resume since processes are frozen in suspend_prepare and thawed in + resume_complete. The predelay and postdelay args allow you to do this. It + can also be useful to run in x2 mode with an x2 delay, this way you can + see process activity before and after resume, and in between two + successive suspend/resumes. + + The command can be run like this: + + %> sudo ./sleepgraph.py -m mem -rtcwake 15 -x2 -x2delay 1000 -predelay 1000 -postdelay 1000 -proc + + or with a config file + + %> sudo ./sleepgraph.py -config config/suspend-proc.cfg + + +------------------------------------------------------------------ +| CONFIGURATION FILES | +------------------------------------------------------------------ + + Since 4.0 we've moved to using config files in lieu of command line options. + The config folder contains a collection of typical use cases. + There are corresponding configs for other power modes: + + Simple suspend/resume with basic timeline (mem/freeze/standby) + config/suspend.cfg + config/freeze.cfg + config/standby.cfg + + Dev mode suspend/resume with dev timeline (mem/freeze/standby) + config/suspend-dev.cfg + config/freeze-dev.cfg + config/standby-dev.cfg + + Simple suspend/resume with timeline and callgraph (mem/freeze/standby) + config/suspend-callgraph.cfg + config/freeze-callgraph.cfg + config/standby-callgraph.cfg + + Sample proc mode x2 run using mem suspend + config/suspend-x2-proc.cfg + + Sample for editing timeline funcs (moves internal functions into config) + config/custom-timeline-functions.cfg + + Sample debug config for serio subsystem + config/debug-serio-suspend.cfg + + +Usage Examples +______________ + + Run a simple mem suspend: + %> sudo ./sleepgraph.py -config config/suspend.cfg + + Run a mem suspend with callgraph data: + %> sudo ./sleepgraph.py -config config/suspend-callgraph.cfg + + Run a mem suspend with dev mode detail: + %> sudo ./sleepgraph.py -config config/suspend-dev.cfg + + +Config File Options +___________________ + + [Settings] + + # Verbosity: print verbose messages (def: false) + verbose: false + + # Suspend Mode: e.g. standby, mem, freeze, disk (def: mem) + mode: mem + + # Output Directory Format: {hostname}, {date}, {time} give current values + output-dir: suspend-{hostname}-{date}-{time} + + # Automatic Wakeup: use rtcwake to wakeup after X seconds (def: infinity) + rtcwake: 15 + + # Add Logs: add the dmesg and ftrace log to the html output (def: false) + addlogs: false + + # Sus/Res Gap: insert a gap between sus & res in the timeline (def: false) + srgap: false + + # Custom Command: Command to execute in lieu of suspend (def: "") + command: echo mem > /sys/power/state + + # Proc mode: graph user processes and cpu usage in the timeline (def: false) + proc: false + + # Dev mode: graph source functions in the timeline (def: false) + dev: false + + # Suspend/Resume x2: run 2 suspend/resumes back to back (def: false) + x2: false + + # x2 Suspend Delay: time delay between the two test runs in ms (def: 0 ms) + x2delay: 0 + + # Pre Suspend Delay: nclude an N ms delay before (1st) suspend (def: 0 ms) + predelay: 0 + + # Post Resume Delay: include an N ms delay after (last) resume (def: 0 ms) + postdelay: 0 + + # Min Device Length: graph only dev callbacks longer than min (def: 0.001 ms) + mindev: 0.001 + + # Callgraph: gather ftrace callgraph data on all timeline events (def: false) + callgraph: false + + # Expand Callgraph: pre-expand the callgraph treeviews in html (def: false) + expandcg: false + + # Min Callgraph Length: show callgraphs only if longer than min (def: 1 ms) + mincg: 1 + + # Timestamp Precision: number of sig digits in timestamps (0:S, [3:ms], 6:us) + timeprec: 3 + + # Device Filter: show only devs whose name/driver includes one of these strings + devicefilter: _cpu_up,_cpu_down,i915,usb + + # Override default timeline entries: + # Do not use the internal default functions for timeline entries (def: false) + # Set this to true if you intend to only use the ones defined in the config + override-timeline-functions: true + + # Override default dev timeline entries: + # Do not use the internal default functions for dev timeline entries (def: false) + # Set this to true if you intend to only use the ones defined in the config + override-dev-timeline-functions: true + + # Call Loop Max Gap (dev mode only) + # merge loops of the same call if each is less than maxgap apart (def: 100us) + callloop-maxgap: 0.0001 + + # Call Loop Max Length (dev mode only) + # merge loops of the same call if each is less than maxlen in length (def: 5ms) + callloop-maxlen: 0.005 + +------------------------------------------------------------------ +| CUSTOM TIMELINE ENTRIES | +------------------------------------------------------------------ + +Adding or Editing Timeline Functions +____________________________________ + + The tool uses an array of function names to fill out empty spaces in the + timeline where device callbacks don't appear. For instance, in suspend_prepare + the tool adds the sys_sync and freeze_processes calls as virtual device blocks + in the timeline to show you where the time is going. These calls should fill + the timeline with contiguous data so that most kernel execution is covered. + + It is possible to add new function calls to the timeline by adding them to + the config. It's also possible to copy the internal timeline functions into + the config so that you can override and edit them. Place them in the + timeline_functions_ARCH section with the name of your architecture appended. + i.e. for x86_64: [timeline_functions_x86_64] + + Use the override-timeline-functions option if you only want to use your + custom calls, or leave it false to append them to the internal ones. + + This section includes a list of functions (set using kprobes) which use both + symbol data and function arg data. The args are pulled directly from the + stack using this architecture's registers and stack formatting. Each entry + can include up to four pieces of info: The function name, a format string, + an argument list, and a color. But only a function name is required. + + For a full example config, see config/custom-timeline-functions.cfg. It pulls + all the internal timeline functions into the config and allows you to edit + them. + + Entry format: + + function: format{fn_arg1}_{fn_arg2} fn_arg1 fn_arg2 ... [color=purple] + + Required Arguments: + + function: The symbol name for the function you want probed, this is the + minimum required for an entry, it will show up as the function + name with no arguments. + + example: _cpu_up: + + Optional Arguments: + + format: The format to display the data on the timeline in. Use braces to + enclose the arg names. + + example: CPU_ON[{cpu}] + + color: The color of the entry block in the timeline. The default color is + transparent, so the entry shares the phase color. The color is an + html color string, either a word, or an RGB. + + example: [color=#CC00CC] + + arglist: A list of arguments from registers/stack addresses. See URL: + https://www.kernel.org/doc/Documentation/trace/kprobetrace.txt + + example: cpu=%di:s32 + + Here is a full example entry. It displays cpu resume calls in the timeline + in orange. They will appear as CPU_ON[0], CPU_ON[1], etc. + + [timeline_functions_x86_64] + _cpu_up: CPU_ON[{cpu}] cpu=%di:s32 [color=orange] + + +Adding or Editing Dev Mode Timeline Source Functions +____________________________________________________ + + In dev mode, the tool uses an array of function names to monitor source + execution within the timeline entries. + + The function calls are displayed inside the main device/call blocks in the + timeline. However, if a function call is not within a main timeline event, + it will spawn an entirely new event named after the caller's kernel thread. + These asynchronous kernel threads will populate in a separate section + beneath the main device/call section. + + The tool has a set of hard coded calls which focus on the most common use + cases: msleep, udelay, schedule_timeout, mutex_lock_slowpath, etc. These are + the functions that add a hardcoded time delay to the suspend/resume path. + The tool also includes some common functions native to important + subsystems: ata, i915, and ACPI, etc. + + It is possible to add new function calls to the dev timeline by adding them + to the config. It's also possible to copy the internal dev timeline + functions into the config so that you can override and edit them. Place them + in the dev_timeline_functions_ARCH section with the name of your architecture + appended. i.e. for x86_64: [dev_timeline_functions_x86_64] + + Use the override-dev-timeline-functions option if you only want to use your + custom calls, or leave it false to append them to the internal ones. + + The format is the same as the timeline_functions_x86_64 section. It's a + list of functions (set using kprobes) which use both symbol data and function + arg data. The args are pulled directly from the stack using this + architecture's registers and stack formatting. Each entry can include up + to four pieces of info: The function name, a format string, an argument list, + and a color. But only the function name is required. + + For a full example config, see config/custom-timeline-functions.cfg. It pulls + all the internal dev timeline functions into the config and allows you to edit + them. + + Here is a full example entry. It displays the ATA port reset calls as + ataN_port_reset in the timeline. This is where most of the SATA disk resume + time goes, so it can be helpful to see the low level call. + + [dev_timeline_functions_x86_64] + ata_eh_recover: ata{port}_port_reset port=+36(%di):s32 [color=#CC00CC] + + +Verifying your custom functions +_______________________________ + + Once you have a set of functions (kprobes) defined, it can be useful to + perform a quick check to see if you formatted them correctly and if the system + actually supports them. To do this, run the tool with your config file + and the -status option. The tool will go through all the kprobes (both + custom and internal if you haven't overridden them) and actually attempts + to set them in ftrace. It will then print out success or fail for you. + + Note that kprobes which don't actually exist in the kernel won't stop the + tool, they just wont show up. + + For example: + + sudo ./sleepgraph.py -config config/custom-timeline-functions.cfg -status + Checking this system (myhostname)... + have root access: YES + is sysfs mounted: YES + is "mem" a valid power mode: YES + is ftrace supported: YES + are kprobes supported: YES + timeline data source: FTRACE (all trace events found) + is rtcwake supported: YES + verifying timeline kprobes work: + _cpu_down: YES + _cpu_up: YES + acpi_pm_finish: YES + acpi_pm_prepare: YES + freeze_kernel_threads: YES + freeze_processes: YES + sys_sync: YES + thaw_processes: YES + verifying dev kprobes work: + __const_udelay: YES + __mutex_lock_slowpath: YES + acpi_os_stall: YES + acpi_ps_parse_aml: YES + intel_opregion_init: NO + intel_opregion_register: NO + intel_opregion_setup: NO + msleep: YES + schedule_timeout: YES + schedule_timeout_uninterruptible: YES + usleep_range: YES + + +------------------------------------------------------------------ +| TESTING ON CONSUMER LINUX OPERATING SYSTEMS | +------------------------------------------------------------------ + +Android +_______ + + The easiest way to execute on an android device is to run the android.sh + script on the device, then pull the ftrace log back to the host and run + sleepgraph.py on it. + + Here are the steps: + + [download and install the tool on the device] + + host%> wget https://raw.githubusercontent.com/intel/pm-graph/master/tools/android.sh + host%> adb connect 192.168.1.6 + host%> adb root + # push the script to a writeable location + host%> adb push android.sh /sdcard/ + + [check whether the tool will run on your device] + + host%> adb shell + dev%> cd /sdcard + dev%> sh android.sh status + host : asus_t100 + kernel : 3.14.0-i386-dirty + modes : freeze mem + rtcwake : supported + ftrace : supported + trace events { + suspend_resume: found + device_pm_callback_end: found + device_pm_callback_start: found + } + # the above is what you see on a system that's properly patched + + [execute the suspend] + + # NOTE: The suspend will only work if the screen isn't timed out, + # so you have to press some keys first to wake it up b4 suspend) + dev%> sh android.sh suspend mem + ------------------------------------ + Suspend/Resume timing test initiated + ------------------------------------ + hostname : asus_t100 + kernel : 3.14.0-i386-dirty + mode : mem + ftrace out : /mnt/shell/emulated/0/ftrace.txt + dmesg out : /mnt/shell/emulated/0/dmesg.txt + log file : /mnt/shell/emulated/0/log.txt + ------------------------------------ + INITIALIZING FTRACE........DONE + STARTING FTRACE + SUSPEND START @ 21:24:02 (rtcwake in 10 seconds) + + + [retrieve the data from the device] + + # I find that you have to actually kill the adb process and + # reconnect sometimes in order for the connection to work post-suspend + host%> adb connect 192.168.1.6 + # (required) get the ftrace data, this is the most important piece + host%> adb pull /sdcard/ftrace.txt + # (optional) get the dmesg data, this is for debugging + host%> adb pull /sdcard/dmesg.txt + # (optional) get the log, which just lists some test times for comparison + host%> adb pull /sdcard/log.txt + + [create an output html file using sleepgraph.py] + + host%> sleepgraph.py -ftrace ftrace.txt + + You should now have an output.html with the android data, enjoy! diff --git a/tools/power/pm-graph/config/example.cfg b/tools/power/pm-graph/config/example.cfg index 05b2efb9bb54..1ef3eb9383fa 100644 --- a/tools/power/pm-graph/config/example.cfg +++ b/tools/power/pm-graph/config/example.cfg @@ -98,12 +98,34 @@ postdelay: 0 # graph only devices longer than min in the timeline (default: 0.001 ms) mindev: 0.001 +# Call Loop Max Gap (dev mode only) +# merge loops of the same call if each is less than maxgap apart (def: 100us) +callloop-maxgap: 0.0001 + +# Call Loop Max Length (dev mode only) +# merge loops of the same call if each is less than maxlen in length (def: 5ms) +callloop-maxlen: 0.005 + +# Override default timeline entries: +# Do not use the internal default functions for timeline entries (def: false) +# Set this to true if you intend to only use the ones defined in the config +override-timeline-functions: true + +# Override default dev timeline entries: +# Do not use the internal default functions for dev timeline entries (def: false) +# Set this to true if you intend to only use the ones defined in the config +override-dev-timeline-functions: true + # ---- Debug Options ---- # Callgraph # gather detailed ftrace callgraph data on all timeline events (default: false) callgraph: false +# Max graph depth +# limit the callgraph trace to this depth (default: 0 = all) +maxdepth: 2 + # Callgraph phase filter # Only enable callgraphs for one phase, i.e. resume_noirq (default: all) cgphase: suspend @@ -131,3 +153,7 @@ timeprec: 6 # Add kprobe functions to the timeline # Add functions to the timeline from a text file (default: no-action) # fadd: file.txt + +# Ftrace buffer size +# Set trace buffer size to N kilo-bytes (default: all of free memory up to 3GB) +# bufsize: 1000 diff --git a/tools/power/pm-graph/sleepgraph.8 b/tools/power/pm-graph/sleepgraph.8 index 24a2e7d0ae63..9648be644d5f 100644 --- a/tools/power/pm-graph/sleepgraph.8 +++ b/tools/power/pm-graph/sleepgraph.8 @@ -53,6 +53,11 @@ disable rtcwake and require a user keypress to resume. Add the dmesg and ftrace logs to the html output. They will be viewable by clicking buttons in the timeline. .TP +\fB-turbostat\fR +Use turbostat to execute the command in freeze mode (default: disabled). This +will provide turbostat output in the log which will tell you which actual +power modes were entered. +.TP \fB-result \fIfile\fR Export a results table to a text file for parsing. .TP @@ -121,6 +126,10 @@ be created in a new subdirectory with a summary page: suspend-xN-{date}-{time}. Use ftrace to create device callgraphs (default: disabled). This can produce very large outputs, i.e. 10MB - 100MB. .TP +\fB-ftop\fR +Use ftrace on the top level call: "suspend_devices_and_enter" only (default: disabled). +This option implies -f and creates a single callgraph covering all of suspend/resume. +.TP \fB-maxdepth \fIlevel\fR limit the callgraph trace depth to \fIlevel\fR (default: 0=all). This is the best way to limit the output size when using callgraphs via -f. @@ -138,8 +147,8 @@ which are barely visible in the timeline. The value is a float: e.g. 0.001 represents 1 us. .TP \fB-cgfilter \fI"func1,func2,..."\fR -Reduce callgraph output in the timeline by limiting it to a list of calls. The -argument can be a single function name or a comma delimited list. +Reduce callgraph output in the timeline by limiting it certain devices. The +argument can be a single device name or a comma delimited list. (default: none) .TP \fB-cgskip \fIfile\fR @@ -183,6 +192,9 @@ Print out the contents of the ACPI Firmware Performance Data Table. \fB-battery\fR Print out battery status and current charge. .TP +\fB-wifi\fR +Print out wifi status and connection details. +.TP \fB-xon/-xoff/-xstandby/-xsuspend\fR Test xset by attempting to switch the display to the given mode. This is the same command which will be issued by \fB-display \fImode\fR. From 7e186d9de9290d57c90751ea252135f425f49e6e Mon Sep 17 00:00:00 2001 From: Kefeng Wang Date: Mon, 27 May 2019 20:05:35 +0800 Subject: [PATCH 06/13] drivers: base: power: clock_ops: Use of_clk_get_parent_count() Use of_clk_get_parent_count() instead of open coding. Reviewed-by: Geert Uytterhoeven Signed-off-by: Kefeng Wang Signed-off-by: Rafael J. Wysocki --- drivers/base/power/clock_ops.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/drivers/base/power/clock_ops.c b/drivers/base/power/clock_ops.c index 59d19dd64928..3e84e3085d43 100644 --- a/drivers/base/power/clock_ops.c +++ b/drivers/base/power/clock_ops.c @@ -12,6 +12,7 @@ #include #include #include +#include #include #include #include @@ -195,8 +196,7 @@ int of_pm_clk_add_clks(struct device *dev) if (!dev || !dev->of_node) return -EINVAL; - count = of_count_phandle_with_args(dev->of_node, "clocks", - "#clock-cells"); + count = of_clk_get_parent_count(dev->of_node); if (count <= 0) return -ENODEV; From 338c993f9aa2078e03c909464e963a31e086df69 Mon Sep 17 00:00:00 2001 From: Geert Uytterhoeven Date: Mon, 27 May 2019 14:27:51 +0200 Subject: [PATCH 07/13] PM / clk: Remove error message on out-of-memory condition There is no need to print an error message if kstrdup() fails, as the memory allocation core already takes care of that. Note that commit 59d84ca8c46a93ad ("PM / OPP / clk: Remove unnecessary OOM message") already removed similar error messages, but this one was forgotten. Signed-off-by: Geert Uytterhoeven Signed-off-by: Rafael J. Wysocki --- drivers/base/power/clock_ops.c | 2 -- 1 file changed, 2 deletions(-) diff --git a/drivers/base/power/clock_ops.c b/drivers/base/power/clock_ops.c index 3e84e3085d43..ced6863a16a5 100644 --- a/drivers/base/power/clock_ops.c +++ b/drivers/base/power/clock_ops.c @@ -93,8 +93,6 @@ static int __pm_clk_add(struct device *dev, const char *con_id, if (con_id) { ce->con_id = kstrdup(con_id, GFP_KERNEL); if (!ce->con_id) { - dev_err(dev, - "Not enough memory for clock connection ID.\n"); kfree(ce); return -ENOMEM; } From bd59ffb23b9de82d2ad3d2cd752520de245780c6 Mon Sep 17 00:00:00 2001 From: Nick Black Date: Thu, 18 Apr 2019 15:12:52 -0400 Subject: [PATCH 08/13] cpupower: correct spelling of interval Fix up multiple instances of "intervall" to correct "interval" (all save one Italian instance). Signed-off-by: Nick Black Signed-off-by: Shuah Khan --- tools/power/cpupower/man/cpupower-monitor.1 | 2 +- tools/power/cpupower/po/cs.po | 2 +- tools/power/cpupower/po/de.po | 2 +- tools/power/cpupower/po/fr.po | 2 +- tools/power/cpupower/po/it.po | 2 +- tools/power/cpupower/po/pt.po | 2 +- 6 files changed, 6 insertions(+), 6 deletions(-) diff --git a/tools/power/cpupower/man/cpupower-monitor.1 b/tools/power/cpupower/man/cpupower-monitor.1 index 914cbb9d9cd0..70a56476f4b0 100644 --- a/tools/power/cpupower/man/cpupower-monitor.1 +++ b/tools/power/cpupower/man/cpupower-monitor.1 @@ -61,7 +61,7 @@ Only display specific monitors. Use the monitor string(s) provided by \-l option .PP \-i seconds .RS 4 -Measure intervall. +Measure interval. .RE .PP \-c diff --git a/tools/power/cpupower/po/cs.po b/tools/power/cpupower/po/cs.po index cb22c45c5069..bfc7e1702ec9 100644 --- a/tools/power/cpupower/po/cs.po +++ b/tools/power/cpupower/po/cs.po @@ -98,7 +98,7 @@ msgstr "" #: utils/idle_monitor/cpupower-monitor.c:74 #, c-format -msgid "\t -i: time intervall to measure for in seconds (default 1)\n" +msgid "\t -i: time interval to measure for in seconds (default 1)\n" msgstr "" #: utils/idle_monitor/cpupower-monitor.c:75 diff --git a/tools/power/cpupower/po/de.po b/tools/power/cpupower/po/de.po index 840c17cc450a..70887bb8ba95 100644 --- a/tools/power/cpupower/po/de.po +++ b/tools/power/cpupower/po/de.po @@ -95,7 +95,7 @@ msgstr "" #: utils/idle_monitor/cpupower-monitor.c:74 #, c-format -msgid "\t -i: time intervall to measure for in seconds (default 1)\n" +msgid "\t -i: time interval to measure for in seconds (default 1)\n" msgstr "" #: utils/idle_monitor/cpupower-monitor.c:75 diff --git a/tools/power/cpupower/po/fr.po b/tools/power/cpupower/po/fr.po index b46ca2548f86..b6e505b34e4a 100644 --- a/tools/power/cpupower/po/fr.po +++ b/tools/power/cpupower/po/fr.po @@ -95,7 +95,7 @@ msgstr "" #: utils/idle_monitor/cpupower-monitor.c:74 #, c-format -msgid "\t -i: time intervall to measure for in seconds (default 1)\n" +msgid "\t -i: time interval to measure for in seconds (default 1)\n" msgstr "" #: utils/idle_monitor/cpupower-monitor.c:75 diff --git a/tools/power/cpupower/po/it.po b/tools/power/cpupower/po/it.po index f80c4ddb9bda..a1deeb52c9e0 100644 --- a/tools/power/cpupower/po/it.po +++ b/tools/power/cpupower/po/it.po @@ -95,7 +95,7 @@ msgstr "" #: utils/idle_monitor/cpupower-monitor.c:74 #, c-format -msgid "\t -i: time intervall to measure for in seconds (default 1)\n" +msgid "\t -i: time interval to measure for in seconds (default 1)\n" msgstr "" #: utils/idle_monitor/cpupower-monitor.c:75 diff --git a/tools/power/cpupower/po/pt.po b/tools/power/cpupower/po/pt.po index 990f5267ffe8..902186585bb9 100644 --- a/tools/power/cpupower/po/pt.po +++ b/tools/power/cpupower/po/pt.po @@ -93,7 +93,7 @@ msgstr "" #: utils/idle_monitor/cpupower-monitor.c:74 #, c-format -msgid "\t -i: time intervall to measure for in seconds (default 1)\n" +msgid "\t -i: time interval to measure for in seconds (default 1)\n" msgstr "" #: utils/idle_monitor/cpupower-monitor.c:75 From 04507c0a9385cc8280f794a36bfff567c8cc1042 Mon Sep 17 00:00:00 2001 From: Abhishek Goel Date: Wed, 29 May 2019 04:30:33 -0500 Subject: [PATCH 09/13] cpupower : frequency-set -r option misses the last cpu in related cpu list To set frequency on specific cpus using cpupower, following syntax can be used : cpupower -c #i frequency-set -f #f -r While setting frequency using cpupower frequency-set command, if we use '-r' option, it is expected to set frequency for all cpus related to cpu #i. But it is observed to be missing the last cpu in related cpu list. This patch fixes the problem. Signed-off-by: Abhishek Goel Reviewed-by: Thomas Renninger Signed-off-by: Shuah Khan --- tools/power/cpupower/utils/cpufreq-set.c | 2 ++ 1 file changed, 2 insertions(+) diff --git a/tools/power/cpupower/utils/cpufreq-set.c b/tools/power/cpupower/utils/cpufreq-set.c index f49bc4aa2a08..6ed82fba5aaa 100644 --- a/tools/power/cpupower/utils/cpufreq-set.c +++ b/tools/power/cpupower/utils/cpufreq-set.c @@ -305,6 +305,8 @@ int cmd_freq_set(int argc, char **argv) bitmask_setbit(cpus_chosen, cpus->cpu); cpus = cpus->next; } + /* Set the last cpu in related cpus list */ + bitmask_setbit(cpus_chosen, cpus->cpu); cpufreq_put_related_cpus(cpus); } } From b3e3759ee4abd72bedbf4b109ff1749d3aea6f21 Mon Sep 17 00:00:00 2001 From: Stephen Boyd Date: Wed, 20 Mar 2019 15:19:08 +0530 Subject: [PATCH 10/13] opp: Don't overwrite rounded clk rate The OPP table normally contains 'fmax' values corresponding to the voltage or performance levels of each OPP, but we don't necessarily want all the devices to run at fmax all the time. Running at fmax makes sense for devices like CPU/GPU, which have a finite amount of work to do and since a specific amount of energy is consumed at an OPP, its better to run at the highest possible frequency for that voltage value. On the other hand, we have IO devices which need to run at specific frequencies only for their proper functioning, instead of maximum possible frequency. The OPP core currently roundup to the next possible OPP for a frequency and select the fmax value. To support the IO devices by the OPP core, lets do the roundup to fetch the voltage or performance state values, but not use the OPP frequency value. Rather use the value returned by clk_round_rate(). The current user, cpufreq, of dev_pm_opp_set_rate() already does the rounding to the next OPP before calling this routine and it won't have any side affects because of this change. Signed-off-by: Stephen Boyd Signed-off-by: Rajendra Nayak [ Viresh: Massaged changelog, added comment and use temp_opp variable instead ] Signed-off-by: Viresh Kumar --- drivers/opp/core.c | 15 ++++++++++----- 1 file changed, 10 insertions(+), 5 deletions(-) diff --git a/drivers/opp/core.c b/drivers/opp/core.c index 764e05a2fa66..bae94bfa1e96 100644 --- a/drivers/opp/core.c +++ b/drivers/opp/core.c @@ -751,13 +751,16 @@ static int _set_required_opps(struct device *dev, * @dev: device for which we do this operation * @target_freq: frequency to achieve * - * This configures the power-supplies and clock source to the levels specified - * by the OPP corresponding to the target_freq. + * This configures the power-supplies to the levels specified by the OPP + * corresponding to the target_freq, and programs the clock to a value <= + * target_freq, as rounded by clk_round_rate(). Device wanting to run at fmax + * provided by the opp, should have already rounded to the target OPP's + * frequency. */ int dev_pm_opp_set_rate(struct device *dev, unsigned long target_freq) { struct opp_table *opp_table; - unsigned long freq, old_freq; + unsigned long freq, old_freq, temp_freq; struct dev_pm_opp *old_opp, *opp; struct clk *clk; int ret; @@ -796,13 +799,15 @@ int dev_pm_opp_set_rate(struct device *dev, unsigned long target_freq) goto put_opp_table; } - old_opp = _find_freq_ceil(opp_table, &old_freq); + temp_freq = old_freq; + old_opp = _find_freq_ceil(opp_table, &temp_freq); if (IS_ERR(old_opp)) { dev_err(dev, "%s: failed to find current OPP for freq %lu (%ld)\n", __func__, old_freq, PTR_ERR(old_opp)); } - opp = _find_freq_ceil(opp_table, &freq); + temp_freq = freq; + opp = _find_freq_ceil(opp_table, &temp_freq); if (IS_ERR(opp)) { ret = PTR_ERR(opp); dev_err(dev, "%s: failed to find OPP for freq %lu (%d)\n", From cd7ea582866f43324f3d60f0d4daac05e08f0f41 Mon Sep 17 00:00:00 2001 From: Rajendra Nayak Date: Wed, 20 Mar 2019 15:19:09 +0530 Subject: [PATCH 11/13] opp: Make dev_pm_opp_set_rate() handle freq = 0 to drop performance votes For devices with performance state, we use dev_pm_opp_set_rate() to set the appropriate clk rate and the performance state. We do need a way to remove the performance state vote when we idle the device and turn the clocks off. Use dev_pm_opp_set_rate() with freq = 0 to achieve this. Signed-off-by: Rajendra Nayak Signed-off-by: Stephen Boyd [ Viresh: Updated _set_required_opps() to handle the !opp case ] Signed-off-by: Viresh Kumar --- drivers/opp/core.c | 21 +++++++++++++-------- 1 file changed, 13 insertions(+), 8 deletions(-) diff --git a/drivers/opp/core.c b/drivers/opp/core.c index bae94bfa1e96..9fda9a0ec016 100644 --- a/drivers/opp/core.c +++ b/drivers/opp/core.c @@ -711,7 +711,7 @@ static int _set_required_opps(struct device *dev, /* Single genpd case */ if (!genpd_virt_devs) { - pstate = opp->required_opps[0]->pstate; + pstate = likely(opp) ? opp->required_opps[0]->pstate : 0; ret = dev_pm_genpd_set_performance_state(dev, pstate); if (ret) { dev_err(dev, "Failed to set performance state of %s: %d (%d)\n", @@ -729,7 +729,7 @@ static int _set_required_opps(struct device *dev, mutex_lock(&opp_table->genpd_virt_dev_lock); for (i = 0; i < opp_table->required_opp_count; i++) { - pstate = opp->required_opps[i]->pstate; + pstate = likely(opp) ? opp->required_opps[i]->pstate : 0; if (!genpd_virt_devs[i]) continue; @@ -765,18 +765,23 @@ int dev_pm_opp_set_rate(struct device *dev, unsigned long target_freq) struct clk *clk; int ret; - if (unlikely(!target_freq)) { - dev_err(dev, "%s: Invalid target frequency %lu\n", __func__, - target_freq); - return -EINVAL; - } - opp_table = _find_opp_table(dev); if (IS_ERR(opp_table)) { dev_err(dev, "%s: device opp doesn't exist\n", __func__); return PTR_ERR(opp_table); } + if (unlikely(!target_freq)) { + if (opp_table->required_opp_tables) { + ret = _set_required_opps(dev, opp_table, NULL); + } else { + dev_err(dev, "target frequency can't be 0\n"); + ret = -EINVAL; + } + + goto put_opp_table; + } + clk = opp_table->clk; if (IS_ERR(clk)) { dev_err(dev, "%s: No clock available for the device\n", From 8eb835e4789acb7c306d56ae9069e0e1134aa5b2 Mon Sep 17 00:00:00 2001 From: Greg Kroah-Hartman Date: Tue, 11 Jun 2019 20:05:47 +0200 Subject: [PATCH 12/13] power: avs: smartreflex: no need to check return value of debugfs_create functions When calling debugfs functions, there is no need to ever check the return value. The function can work or not, but the code logic should never do something different based on this. And even when not checking the return value, no need to cast away the call to (void), as these functions were never a "must check" type of a function, so remove that odd cast. Signed-off-by: Greg Kroah-Hartman Signed-off-by: Rafael J. Wysocki --- drivers/power/avs/smartreflex.c | 41 +++++++++------------------------ 1 file changed, 11 insertions(+), 30 deletions(-) diff --git a/drivers/power/avs/smartreflex.c b/drivers/power/avs/smartreflex.c index c96c01e09740..4684e7df833a 100644 --- a/drivers/power/avs/smartreflex.c +++ b/drivers/power/avs/smartreflex.c @@ -899,38 +899,19 @@ static int omap_sr_probe(struct platform_device *pdev) } dev_info(&pdev->dev, "%s: SmartReflex driver initialized\n", __func__); - if (!sr_dbg_dir) { + if (!sr_dbg_dir) sr_dbg_dir = debugfs_create_dir("smartreflex", NULL); - if (IS_ERR_OR_NULL(sr_dbg_dir)) { - ret = PTR_ERR(sr_dbg_dir); - pr_err("%s:sr debugfs dir creation failed(%d)\n", - __func__, ret); - goto err_list_del; - } - } sr_info->dbg_dir = debugfs_create_dir(sr_info->name, sr_dbg_dir); - if (IS_ERR_OR_NULL(sr_info->dbg_dir)) { - dev_err(&pdev->dev, "%s: Unable to create debugfs directory\n", - __func__); - ret = PTR_ERR(sr_info->dbg_dir); - goto err_debugfs; - } - (void) debugfs_create_file("autocomp", S_IRUGO | S_IWUSR, - sr_info->dbg_dir, (void *)sr_info, &pm_sr_fops); - (void) debugfs_create_x32("errweight", S_IRUGO, sr_info->dbg_dir, - &sr_info->err_weight); - (void) debugfs_create_x32("errmaxlimit", S_IRUGO, sr_info->dbg_dir, - &sr_info->err_maxlimit); + debugfs_create_file("autocomp", S_IRUGO | S_IWUSR, sr_info->dbg_dir, + (void *)sr_info, &pm_sr_fops); + debugfs_create_x32("errweight", S_IRUGO, sr_info->dbg_dir, + &sr_info->err_weight); + debugfs_create_x32("errmaxlimit", S_IRUGO, sr_info->dbg_dir, + &sr_info->err_maxlimit); nvalue_dir = debugfs_create_dir("nvalue", sr_info->dbg_dir); - if (IS_ERR_OR_NULL(nvalue_dir)) { - dev_err(&pdev->dev, "%s: Unable to create debugfs directory for n-values\n", - __func__); - ret = PTR_ERR(nvalue_dir); - goto err_debugfs; - } if (sr_info->nvalue_count == 0 || !sr_info->nvalue_table) { dev_warn(&pdev->dev, "%s: %s: No Voltage table for the corresponding vdd. Cannot create debugfs entries for n-values\n", @@ -945,12 +926,12 @@ static int omap_sr_probe(struct platform_device *pdev) snprintf(name, sizeof(name), "volt_%lu", sr_info->nvalue_table[i].volt_nominal); - (void) debugfs_create_x32(name, S_IRUGO | S_IWUSR, nvalue_dir, - &(sr_info->nvalue_table[i].nvalue)); + debugfs_create_x32(name, S_IRUGO | S_IWUSR, nvalue_dir, + &(sr_info->nvalue_table[i].nvalue)); snprintf(name, sizeof(name), "errminlimit_%lu", sr_info->nvalue_table[i].volt_nominal); - (void) debugfs_create_x32(name, S_IRUGO | S_IWUSR, nvalue_dir, - &(sr_info->nvalue_table[i].errminlimit)); + debugfs_create_x32(name, S_IRUGO | S_IWUSR, nvalue_dir, + &(sr_info->nvalue_table[i].errminlimit)); } From 560d1bcad715c215e7ffe5d7cffe045974b623d0 Mon Sep 17 00:00:00 2001 From: Dmitry Osipenko Date: Sun, 23 Jun 2019 20:50:53 +0300 Subject: [PATCH 13/13] opp: Don't use IS_ERR on invalid supplies _set_opp_custom() receives a set of OPP supplies as its arguments and the caller of it passes NULL when the supplies are not valid. But _set_opp_custom(), by mistake, checks for error by performing IS_ERR(old_supply) on it which will always evaluate to false. The problem was spotted during of testing of upcoming update for the NVIDIA Tegra CPUFreq driver. Cc: stable Fixes: 7e535993fa4f ("OPP: Separate out custom OPP handler specific code") Reported-by: Marc Dietrich Signed-off-by: Dmitry Osipenko [ Viresh: Massaged changelog ] Signed-off-by: Viresh Kumar --- drivers/opp/core.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/drivers/opp/core.c b/drivers/opp/core.c index 9fda9a0ec016..89ec6aa220cf 100644 --- a/drivers/opp/core.c +++ b/drivers/opp/core.c @@ -685,7 +685,7 @@ static int _set_opp_custom(const struct opp_table *opp_table, data->old_opp.rate = old_freq; size = sizeof(*old_supply) * opp_table->regulator_count; - if (IS_ERR(old_supply)) + if (!old_supply) memset(data->old_opp.supplies, 0, size); else memcpy(data->old_opp.supplies, old_supply, size);