diff options
author | Rafael J. Wysocki <rafael.j.wysocki@intel.com> | 2017-09-04 00:07:36 +0200 |
---|---|---|
committer | Rafael J. Wysocki <rafael.j.wysocki@intel.com> | 2017-09-04 00:07:36 +0200 |
commit | d97561f461e4cb5b2e170bc33b466cffbddc8719 (patch) | |
tree | 7be9749e40f2db48c0cebbc1d0eeadbda36c7ce9 | |
parent | 4afbce7b39d2b326616f0a87a6246b1383237868 (diff) | |
parent | d0e4a193c33adaa4f91128d5393aa3589c2f3e9e (diff) | |
download | linux-d97561f461e4cb5b2e170bc33b466cffbddc8719.tar.gz linux-d97561f461e4cb5b2e170bc33b466cffbddc8719.tar.bz2 linux-d97561f461e4cb5b2e170bc33b466cffbddc8719.zip |
Merge branch 'pm-tools'
* pm-tools:
tools/power/cpupower: allow running without cpu0
pm-graph: package makefile and man pages
pm-graph: AnalyzeBoot v2.1
pm-graph: AnalyzeSuspend v4.7
-rw-r--r-- | tools/power/cpupower/utils/cpupower.c | 15 | ||||
-rw-r--r-- | tools/power/cpupower/utils/helpers/cpuid.c | 4 | ||||
-rw-r--r-- | tools/power/cpupower/utils/helpers/helpers.h | 5 | ||||
-rw-r--r-- | tools/power/cpupower/utils/helpers/misc.c | 2 | ||||
-rw-r--r-- | tools/power/cpupower/utils/idle_monitor/hsw_ext_idle.c | 4 | ||||
-rw-r--r-- | tools/power/cpupower/utils/idle_monitor/mperf_monitor.c | 3 | ||||
-rw-r--r-- | tools/power/cpupower/utils/idle_monitor/nhm_idle.c | 8 | ||||
-rw-r--r-- | tools/power/cpupower/utils/idle_monitor/snb_idle.c | 4 | ||||
-rw-r--r-- | tools/power/pm-graph/Makefile | 19 | ||||
-rwxr-xr-x | tools/power/pm-graph/analyze_boot.py | 586 | ||||
-rwxr-xr-x | tools/power/pm-graph/analyze_suspend.py | 534 | ||||
-rw-r--r-- | tools/power/pm-graph/bootgraph.8 | 61 | ||||
-rw-r--r-- | tools/power/pm-graph/sleepgraph.8 | 48 |
13 files changed, 880 insertions, 413 deletions
diff --git a/tools/power/cpupower/utils/cpupower.c b/tools/power/cpupower/utils/cpupower.c index 9ea914378985..2dccf4998599 100644 --- a/tools/power/cpupower/utils/cpupower.c +++ b/tools/power/cpupower/utils/cpupower.c @@ -12,6 +12,7 @@ #include <string.h> #include <unistd.h> #include <errno.h> +#include <sched.h> #include <sys/types.h> #include <sys/stat.h> #include <sys/utsname.h> @@ -31,6 +32,7 @@ static int cmd_help(int argc, const char **argv); */ struct cpupower_cpu_info cpupower_cpu_info; int run_as_root; +int base_cpu; /* Affected cpus chosen by -c/--cpu param */ struct bitmask *cpus_chosen; @@ -174,6 +176,7 @@ int main(int argc, const char *argv[]) unsigned int i, ret; struct stat statbuf; struct utsname uts; + char pathname[32]; cpus_chosen = bitmask_alloc(sysconf(_SC_NPROCESSORS_CONF)); @@ -198,17 +201,23 @@ int main(int argc, const char *argv[]) argv[0] = cmd = "help"; } - get_cpu_info(0, &cpupower_cpu_info); + base_cpu = sched_getcpu(); + if (base_cpu < 0) { + fprintf(stderr, _("No valid cpus found.\n")); + return EXIT_FAILURE; + } + + get_cpu_info(&cpupower_cpu_info); run_as_root = !geteuid(); if (run_as_root) { ret = uname(&uts); + sprintf(pathname, "/dev/cpu/%d/msr", base_cpu); if (!ret && !strcmp(uts.machine, "x86_64") && - stat("/dev/cpu/0/msr", &statbuf) != 0) { + stat(pathname, &statbuf) != 0) { if (system("modprobe msr") == -1) fprintf(stderr, _("MSR access not available.\n")); } } - for (i = 0; i < ARRAY_SIZE(commands); i++) { struct cmd_struct *p = commands + i; diff --git a/tools/power/cpupower/utils/helpers/cpuid.c b/tools/power/cpupower/utils/helpers/cpuid.c index 39c2c7d067bb..32d37c9be791 100644 --- a/tools/power/cpupower/utils/helpers/cpuid.c +++ b/tools/power/cpupower/utils/helpers/cpuid.c @@ -42,7 +42,7 @@ cpuid_func(edx); * * TBD: Should there be a cpuid alternative for this if /proc is not mounted? */ -int get_cpu_info(unsigned int cpu, struct cpupower_cpu_info *cpu_info) +int get_cpu_info(struct cpupower_cpu_info *cpu_info) { FILE *fp; char value[64]; @@ -70,7 +70,7 @@ int get_cpu_info(unsigned int cpu, struct cpupower_cpu_info *cpu_info) if (!strncmp(value, "processor\t: ", 12)) sscanf(value, "processor\t: %u", &proc); - if (proc != cpu) + if (proc != (unsigned int)base_cpu) continue; /* Get CPU vendor */ diff --git a/tools/power/cpupower/utils/helpers/helpers.h b/tools/power/cpupower/utils/helpers/helpers.h index 799a18be60aa..41da392be448 100644 --- a/tools/power/cpupower/utils/helpers/helpers.h +++ b/tools/power/cpupower/utils/helpers/helpers.h @@ -34,6 +34,7 @@ /* Internationalization ****************************/ extern int run_as_root; +extern int base_cpu; extern struct bitmask *cpus_chosen; /* Global verbose (-d) stuff *********************************/ @@ -87,11 +88,11 @@ struct cpupower_cpu_info { * * Extract CPU vendor, family, model, stepping info from /proc/cpuinfo * - * Returns 0 on success or a negativ error code + * Returns 0 on success or a negative error code * Only used on x86, below global's struct values are zero/unknown on * other archs */ -extern int get_cpu_info(unsigned int cpu, struct cpupower_cpu_info *cpu_info); +extern int get_cpu_info(struct cpupower_cpu_info *cpu_info); extern struct cpupower_cpu_info cpupower_cpu_info; /* cpuid and cpuinfo helpers **************************/ diff --git a/tools/power/cpupower/utils/helpers/misc.c b/tools/power/cpupower/utils/helpers/misc.c index 601d719d4e60..a5e7ddf19dbd 100644 --- a/tools/power/cpupower/utils/helpers/misc.c +++ b/tools/power/cpupower/utils/helpers/misc.c @@ -13,7 +13,7 @@ int cpufreq_has_boost_support(unsigned int cpu, int *support, int *active, *support = *active = *states = 0; - ret = get_cpu_info(0, &cpu_info); + ret = get_cpu_info(&cpu_info); if (ret) return ret; diff --git a/tools/power/cpupower/utils/idle_monitor/hsw_ext_idle.c b/tools/power/cpupower/utils/idle_monitor/hsw_ext_idle.c index ebeaba6571a3..f794d6bbb7e9 100644 --- a/tools/power/cpupower/utils/idle_monitor/hsw_ext_idle.c +++ b/tools/power/cpupower/utils/idle_monitor/hsw_ext_idle.c @@ -123,7 +123,7 @@ static int hsw_ext_start(void) previous_count[num][cpu] = val; } } - hsw_ext_get_count(TSC, &tsc_at_measure_start, 0); + hsw_ext_get_count(TSC, &tsc_at_measure_start, base_cpu); return 0; } @@ -132,7 +132,7 @@ static int hsw_ext_stop(void) unsigned long long val; int num, cpu; - hsw_ext_get_count(TSC, &tsc_at_measure_end, 0); + hsw_ext_get_count(TSC, &tsc_at_measure_end, base_cpu); for (num = 0; num < HSW_EXT_CSTATE_COUNT; num++) { for (cpu = 0; cpu < cpu_count; cpu++) { diff --git a/tools/power/cpupower/utils/idle_monitor/mperf_monitor.c b/tools/power/cpupower/utils/idle_monitor/mperf_monitor.c index c83f1606970b..d7c2a6d13dea 100644 --- a/tools/power/cpupower/utils/idle_monitor/mperf_monitor.c +++ b/tools/power/cpupower/utils/idle_monitor/mperf_monitor.c @@ -80,7 +80,8 @@ static int *is_valid; static int mperf_get_tsc(unsigned long long *tsc) { int ret; - ret = read_msr(0, MSR_TSC, tsc); + + ret = read_msr(base_cpu, MSR_TSC, tsc); if (ret) dprint("Reading TSC MSR failed, returning %llu\n", *tsc); return ret; diff --git a/tools/power/cpupower/utils/idle_monitor/nhm_idle.c b/tools/power/cpupower/utils/idle_monitor/nhm_idle.c index d2a91dd0d563..abf8cb5f7349 100644 --- a/tools/power/cpupower/utils/idle_monitor/nhm_idle.c +++ b/tools/power/cpupower/utils/idle_monitor/nhm_idle.c @@ -129,7 +129,7 @@ static int nhm_start(void) int num, cpu; unsigned long long dbg, val; - nhm_get_count(TSC, &tsc_at_measure_start, 0); + nhm_get_count(TSC, &tsc_at_measure_start, base_cpu); for (num = 0; num < NHM_CSTATE_COUNT; num++) { for (cpu = 0; cpu < cpu_count; cpu++) { @@ -137,7 +137,7 @@ static int nhm_start(void) previous_count[num][cpu] = val; } } - nhm_get_count(TSC, &dbg, 0); + nhm_get_count(TSC, &dbg, base_cpu); dprint("TSC diff: %llu\n", dbg - tsc_at_measure_start); return 0; } @@ -148,7 +148,7 @@ static int nhm_stop(void) unsigned long long dbg; int num, cpu; - nhm_get_count(TSC, &tsc_at_measure_end, 0); + nhm_get_count(TSC, &tsc_at_measure_end, base_cpu); for (num = 0; num < NHM_CSTATE_COUNT; num++) { for (cpu = 0; cpu < cpu_count; cpu++) { @@ -156,7 +156,7 @@ static int nhm_stop(void) current_count[num][cpu] = val; } } - nhm_get_count(TSC, &dbg, 0); + nhm_get_count(TSC, &dbg, base_cpu); dprint("TSC diff: %llu\n", dbg - tsc_at_measure_end); return 0; diff --git a/tools/power/cpupower/utils/idle_monitor/snb_idle.c b/tools/power/cpupower/utils/idle_monitor/snb_idle.c index efc8a69c9aba..a2b45219648d 100644 --- a/tools/power/cpupower/utils/idle_monitor/snb_idle.c +++ b/tools/power/cpupower/utils/idle_monitor/snb_idle.c @@ -120,7 +120,7 @@ static int snb_start(void) previous_count[num][cpu] = val; } } - snb_get_count(TSC, &tsc_at_measure_start, 0); + snb_get_count(TSC, &tsc_at_measure_start, base_cpu); return 0; } @@ -129,7 +129,7 @@ static int snb_stop(void) unsigned long long val; int num, cpu; - snb_get_count(TSC, &tsc_at_measure_end, 0); + snb_get_count(TSC, &tsc_at_measure_end, base_cpu); for (num = 0; num < SNB_CSTATE_COUNT; num++) { for (cpu = 0; cpu < cpu_count; cpu++) { diff --git a/tools/power/pm-graph/Makefile b/tools/power/pm-graph/Makefile index 4d0ccc89e6c6..32f40eacdafe 100644 --- a/tools/power/pm-graph/Makefile +++ b/tools/power/pm-graph/Makefile @@ -4,7 +4,7 @@ DESTDIR ?= all: @echo "Nothing to build" -install : +install : uninstall install -d $(DESTDIR)$(PREFIX)/lib/pm-graph install analyze_suspend.py $(DESTDIR)$(PREFIX)/lib/pm-graph install analyze_boot.py $(DESTDIR)$(PREFIX)/lib/pm-graph @@ -17,12 +17,15 @@ install : install sleepgraph.8 $(DESTDIR)$(PREFIX)/share/man/man8 uninstall : - rm $(DESTDIR)$(PREFIX)/share/man/man8/bootgraph.8 - rm $(DESTDIR)$(PREFIX)/share/man/man8/sleepgraph.8 + rm -f $(DESTDIR)$(PREFIX)/share/man/man8/bootgraph.8 + rm -f $(DESTDIR)$(PREFIX)/share/man/man8/sleepgraph.8 - rm $(DESTDIR)$(PREFIX)/bin/bootgraph - rm $(DESTDIR)$(PREFIX)/bin/sleepgraph + rm -f $(DESTDIR)$(PREFIX)/bin/bootgraph + rm -f $(DESTDIR)$(PREFIX)/bin/sleepgraph - rm $(DESTDIR)$(PREFIX)/lib/pm-graph/analyze_boot.py - rm $(DESTDIR)$(PREFIX)/lib/pm-graph/analyze_suspend.py - rmdir $(DESTDIR)$(PREFIX)/lib/pm-graph + rm -f $(DESTDIR)$(PREFIX)/lib/pm-graph/analyze_boot.py + rm -f $(DESTDIR)$(PREFIX)/lib/pm-graph/analyze_suspend.py + rm -f $(DESTDIR)$(PREFIX)/lib/pm-graph/*.pyc + if [ -d $(DESTDIR)$(PREFIX)/lib/pm-graph ] ; then \ + rmdir $(DESTDIR)$(PREFIX)/lib/pm-graph; \ + fi; diff --git a/tools/power/pm-graph/analyze_boot.py b/tools/power/pm-graph/analyze_boot.py index 3e1dcbbf1adc..e83df141a597 100755 --- a/tools/power/pm-graph/analyze_boot.py +++ b/tools/power/pm-graph/analyze_boot.py @@ -42,7 +42,7 @@ import analyze_suspend as aslib # store system values and test parameters class SystemValues(aslib.SystemValues): title = 'BootGraph' - version = 2.0 + version = '2.1' hostname = 'localhost' testtime = '' kernel = '' @@ -50,9 +50,14 @@ class SystemValues(aslib.SystemValues): ftracefile = '' htmlfile = 'bootgraph.html' outfile = '' - phoronix = False - addlogs = False + testdir = '' + testdirprefix = 'boot' + embedded = False + testlog = False + dmesglog = False + ftracelog = False useftrace = False + usecallgraph = False usedevsrc = True suspendmode = 'boot' max_graph_depth = 2 @@ -61,10 +66,12 @@ class SystemValues(aslib.SystemValues): manual = False iscronjob = False timeformat = '%.6f' + bootloader = 'grub' + blexec = [] def __init__(self): if('LOG_FILE' in os.environ and 'TEST_RESULTS_IDENTIFIER' in os.environ): - self.phoronix = True - self.addlogs = True + self.embedded = True + self.dmesglog = True self.outfile = os.environ['LOG_FILE'] self.htmlfile = os.environ['LOG_FILE'] self.hostname = platform.node() @@ -76,42 +83,80 @@ class SystemValues(aslib.SystemValues): self.kernel = self.kernelVersion(val) else: self.kernel = 'unknown' + self.testdir = datetime.now().strftime('boot-%y%m%d-%H%M%S') def kernelVersion(self, msg): return msg.split()[2] + def checkFtraceKernelVersion(self): + val = tuple(map(int, self.kernel.split('-')[0].split('.'))) + if val >= (4, 10, 0): + return True + return False def kernelParams(self): cmdline = 'initcall_debug log_buf_len=32M' if self.useftrace: - cmdline += ' trace_buf_size=128M trace_clock=global '\ + if self.cpucount > 0: + bs = min(self.memtotal / 2, 2*1024*1024) / self.cpucount + else: + bs = 131072 + cmdline += ' trace_buf_size=%dK trace_clock=global '\ 'trace_options=nooverwrite,funcgraph-abstime,funcgraph-cpu,'\ 'funcgraph-duration,funcgraph-proc,funcgraph-tail,'\ 'nofuncgraph-overhead,context-info,graph-time '\ 'ftrace=function_graph '\ 'ftrace_graph_max_depth=%d '\ 'ftrace_graph_filter=%s' % \ - (self.max_graph_depth, self.graph_filter) + (bs, self.max_graph_depth, self.graph_filter) return cmdline def setGraphFilter(self, val): - fp = open(self.tpath+'available_filter_functions') - master = fp.read().split('\n') - fp.close() + master = self.getBootFtraceFilterFunctions() + fs = '' for i in val.split(','): func = i.strip() + if func == '': + doError('badly formatted filter function string') + if '[' in func or ']' in func: + doError('loadable module functions not allowed - "%s"' % func) + if ' ' in func: + doError('spaces found in filter functions - "%s"' % func) if func not in master: doError('function "%s" not available for ftrace' % func) - self.graph_filter = val + if not fs: + fs = func + else: + fs += ','+func + if not fs: + doError('badly formatted filter function string') + self.graph_filter = fs + def getBootFtraceFilterFunctions(self): + self.rootCheck(True) + fp = open(self.tpath+'available_filter_functions') + fulllist = fp.read().split('\n') + fp.close() + list = [] + for i in fulllist: + if not i or ' ' in i or '[' in i or ']' in i: + continue + list.append(i) + return list + def myCronJob(self, line): + if '@reboot' not in line: + return False + if 'bootgraph' in line or 'analyze_boot.py' in line or '-cronjob' in line: + return True + return False def cronjobCmdString(self): cmdline = '%s -cronjob' % os.path.abspath(sys.argv[0]) args = iter(sys.argv[1:]) for arg in args: if arg in ['-h', '-v', '-cronjob', '-reboot']: continue - elif arg in ['-o', '-dmesg', '-ftrace', '-filter']: + elif arg in ['-o', '-dmesg', '-ftrace', '-func']: args.next() continue cmdline += ' '+arg if self.graph_filter != 'do_one_initcall': - cmdline += ' -filter "%s"' % self.graph_filter - cmdline += ' -o "%s"' % os.path.abspath(self.htmlfile) + cmdline += ' -func "%s"' % self.graph_filter + cmdline += ' -o "%s"' % os.path.abspath(self.testdir) return cmdline def manualRebootRequired(self): cmdline = self.kernelParams() @@ -121,6 +166,39 @@ class SystemValues(aslib.SystemValues): print '3. After reboot, re-run this tool with the same arguments but no command (w/o -reboot or -manual).\n' print 'CMDLINE="%s"' % cmdline sys.exit() + def getExec(self, cmd): + dirlist = ['/sbin', '/bin', '/usr/sbin', '/usr/bin', + '/usr/local/sbin', '/usr/local/bin'] + for path in dirlist: + cmdfull = os.path.join(path, cmd) + if os.path.exists(cmdfull): + return cmdfull + return '' + def blGrub(self): + blcmd = '' + for cmd in ['update-grub', 'grub-mkconfig', 'grub2-mkconfig']: + if blcmd: + break + blcmd = self.getExec(cmd) + if not blcmd: + doError('[GRUB] missing update command') + if not os.path.exists('/etc/default/grub'): + doError('[GRUB] missing /etc/default/grub') + if 'grub2' in blcmd: + cfg = '/boot/grub2/grub.cfg' + else: + cfg = '/boot/grub/grub.cfg' + if not os.path.exists(cfg): + doError('[GRUB] missing %s' % cfg) + if 'update-grub' in blcmd: + self.blexec = [blcmd] + else: + self.blexec = [blcmd, '-o', cfg] + def getBootLoader(self): + if self.bootloader == 'grub': + self.blGrub() + else: + doError('unknown boot loader: %s' % self.bootloader) sysvals = SystemValues() @@ -136,20 +214,23 @@ class Data(aslib.Data): idstr = '' html_device_id = 0 valid = False - initstart = 0.0 + tUserMode = 0.0 boottime = '' - phases = ['boot'] + phases = ['kernel', 'user'] do_one_initcall = False def __init__(self, num): self.testnumber = num self.idstr = 'a' self.dmesgtext = [] self.dmesg = { - 'boot': {'list': dict(), 'start': -1.0, 'end': -1.0, 'row': 0, 'color': '#dddddd'} + 'kernel': {'list': dict(), 'start': -1.0, 'end': -1.0, 'row': 0, + 'order': 0, 'color': 'linear-gradient(to bottom, #fff, #bcf)'}, + 'user': {'list': dict(), 'start': -1.0, 'end': -1.0, 'row': 0, + 'order': 1, 'color': '#fff'} } def deviceTopology(self): return '' - def newAction(self, phase, name, start, end, ret, ulen): + def newAction(self, phase, name, pid, start, end, ret, ulen): # new device callback for a specific phase self.html_device_id += 1 devid = '%s%d' % (self.idstr, self.html_device_id) @@ -163,41 +244,46 @@ class Data(aslib.Data): name = '%s[%d]' % (origname, i) i += 1 list[name] = {'name': name, 'start': start, 'end': end, - 'pid': 0, 'length': length, 'row': 0, 'id': devid, + 'pid': pid, 'length': length, 'row': 0, 'id': devid, 'ret': ret, 'ulen': ulen } return name - def deviceMatch(self, cg): + def deviceMatch(self, pid, cg): if cg.end - cg.start == 0: return True - list = self.dmesg['boot']['list'] - for devname in list: - dev = list[devname] - if cg.name == 'do_one_initcall': - if(cg.start <= dev['start'] and cg.end >= dev['end'] and dev['length'] > 0): - dev['ftrace'] = cg - self.do_one_initcall = True - return True - else: - if(cg.start > dev['start'] and cg.end < dev['end']): - if 'ftraces' not in dev: - dev['ftraces'] = [] - dev['ftraces'].append(cg) - return True + for p in data.phases: + list = self.dmesg[p]['list'] + for devname in list: + dev = list[devname] + if pid != dev['pid']: + continue + if cg.name == 'do_one_initcall': + if(cg.start <= dev['start'] and cg.end >= dev['end'] and dev['length'] > 0): + dev['ftrace'] = cg + self.do_one_initcall = True + return True + else: + if(cg.start > dev['start'] and cg.end < dev['end']): + if 'ftraces' not in dev: + dev['ftraces'] = [] + dev['ftraces'].append(cg) + return True return False # ----------------- FUNCTIONS -------------------- -# Function: loadKernelLog +# Function: parseKernelLog # Description: -# Load a raw kernel log from dmesg -def loadKernelLog(): +# parse a kernel log for boot data +def parseKernelLog(): + phase = 'kernel' data = Data(0) - data.dmesg['boot']['start'] = data.start = ktime = 0.0 + data.dmesg['kernel']['start'] = data.start = ktime = 0.0 sysvals.stamp = { 'time': datetime.now().strftime('%B %d %Y, %I:%M:%S %p'), 'host': sysvals.hostname, 'mode': 'boot', 'kernel': ''} + tp = aslib.TestProps() devtemp = dict() if(sysvals.dmesgfile): lf = open(sysvals.dmesgfile, 'r') @@ -205,6 +291,13 @@ def loadKernelLog(): lf = Popen('dmesg', stdout=PIPE).stdout for line in lf: 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 idx = line.find('[') if idx > 1: line = line[idx:] @@ -215,7 +308,6 @@ def loadKernelLog(): if(ktime > 120): break msg = m.group('msg') - data.end = data.initstart = ktime data.dmesgtext.append(line) if(ktime == 0.0 and re.match('^Linux version .*', msg)): if(not sysvals.stamp['kernel']): @@ -228,43 +320,39 @@ def loadKernelLog(): data.boottime = bt.strftime('%Y-%m-%d_%H:%M:%S') sysvals.stamp['time'] = bt.strftime('%B %d %Y, %I:%M:%S %p') continue - m = re.match('^calling *(?P<f>.*)\+.*', msg) + m = re.match('^calling *(?P<f>.*)\+.* @ (?P<p>[0-9]*)', msg) if(m): - devtemp[m.group('f')] = ktime + func = m.group('f') + pid = int(m.group('p')) + devtemp[func] = (ktime, pid) continue m = re.match('^initcall *(?P<f>.*)\+.* returned (?P<r>.*) after (?P<t>.*) usecs', msg) if(m): data.valid = True + data.end = ktime f, r, t = m.group('f', 'r', 't') if(f in devtemp): - data.newAction('boot', f, devtemp[f], ktime, int(r), int(t)) - data.end = ktime + start, pid = devtemp[f] + data.newAction(phase, f, pid, start, ktime, int(r), int(t)) del devtemp[f] continue if(re.match('^Freeing unused kernel memory.*', msg)): - break - - data.dmesg['boot']['end'] = data.end + data.tUserMode = ktime + data.dmesg['kernel']['end'] = ktime + data.dmesg['user']['start'] = ktime + phase = 'user' + + if tp.stamp: + sysvals.stamp = 0 + tp.parseStamp(data, sysvals) + data.dmesg['user']['end'] = data.end lf.close() return data -# Function: loadTraceLog +# Function: parseTraceLog # Description: # Check if trace is available and copy to a temp file -def loadTraceLog(data): - # load the data to a temp file if none given - if not sysvals.ftracefile: - lib = aslib.sysvals - aslib.rootCheck(True) - if not lib.verifyFtrace(): - doError('ftrace not available') - if lib.fgetVal('current_tracer').strip() != 'function_graph': - doError('ftrace not configured for a boot callgraph') - sysvals.ftracefile = '/tmp/boot_ftrace.%s.txt' % os.getpid() - call('cat '+lib.tpath+'trace > '+sysvals.ftracefile, shell=True) - if not sysvals.ftracefile: - doError('No trace data available') - +def parseTraceLog(data): # parse the trace log ftemp = dict() tp = aslib.TestProps() @@ -306,9 +394,29 @@ def loadTraceLog(data): print('Sanity check failed for %s-%d' % (proc, pid)) continue # match cg data to devices - if not data.deviceMatch(cg): + if not data.deviceMatch(pid, cg): print ' BAD: %s %s-%d [%f - %f]' % (cg.name, proc, pid, cg.start, cg.end) +# Function: retrieveLogs +# Description: +# Create copies of dmesg and/or ftrace for later processing +def retrieveLogs(): + # check ftrace is configured first + if sysvals.useftrace: + tracer = sysvals.fgetVal('current_tracer').strip() + if tracer != 'function_graph': + doError('ftrace not configured for a boot callgraph') + # create the folder and get dmesg + sysvals.systemInfo(aslib.dmidecode(sysvals.mempath)) + sysvals.initTestOutput('boot') + sysvals.writeDatafileHeader(sysvals.dmesgfile) + call('dmesg >> '+sysvals.dmesgfile, shell=True) + if not sysvals.useftrace: + return + # get ftrace + sysvals.writeDatafileHeader(sysvals.ftracefile) + call('cat '+sysvals.tpath+'trace >> '+sysvals.ftracefile, shell=True) + # Function: colorForName # Description: # Generate a repeatable color from a list for a given name @@ -353,18 +461,19 @@ def cgOverview(cg, minlen): # testruns: array of Data objects from parseKernelLog or parseTraceLog # Output: # True if the html file was created, false if it failed -def createBootGraph(data, embedded): +def createBootGraph(data): # html function templates html_srccall = '<div id={6} title="{5}" class="srccall" style="left:{1}%;top:{2}px;height:{3}px;width:{4}%;line-height:{3}px;">{0}</div>\n' html_timetotal = '<table class="time1">\n<tr>'\ - '<td class="blue">Time from Kernel Boot to start of User Mode: <b>{0} ms</b></td>'\ + '<td class="blue">Init process starts @ <b>{0} ms</b></td>'\ + '<td class="blue">Last initcall ends @ <b>{1} ms</b></td>'\ '</tr>\n</table>\n' # device timeline devtl = aslib.Timeline(100, 20) # write the test title and general info header - devtl.createHeader(sysvals, 'noftrace') + devtl.createHeader(sysvals) # Generate the header for this timeline t0 = data.start @@ -373,84 +482,98 @@ def createBootGraph(data, embedded): if(tTotal == 0): print('ERROR: No timeline data') return False - boot_time = '%.0f'%(tTotal*1000) - devtl.html += html_timetotal.format(boot_time) + user_mode = '%.0f'%(data.tUserMode*1000) + last_init = '%.0f'%(tTotal*1000) + devtl.html += html_timetotal.format(user_mode, last_init) # determine the maximum number of rows we need to draw - phase = 'boot' - list = data.dmesg[phase]['list'] devlist = [] - for devname in list: - d = aslib.DevItem(0, phase, list[devname]) - devlist.append(d) - devtl.getPhaseRows(devlist) + for p in data.phases: + list = data.dmesg[p]['list'] + for devname in list: + d = aslib.DevItem(0, p, list[devname]) + devlist.append(d) + devtl.getPhaseRows(devlist, 0, 'start') devtl.calcTotalRows() # draw the timeline background devtl.createZoomBox() - boot = data.dmesg[phase] - length = boot['end']-boot['start'] - left = '%.3f' % (((boot['start']-t0)*100.0)/tTotal) - width = '%.3f' % ((length*100.0)/tTotal) - devtl.html += devtl.html_tblock.format(phase, left, width, devtl.scaleH) - devtl.html += devtl.html_phase.format('0', '100', \ - '%.3f'%devtl.scaleH, '%.3f'%devtl.bodyH, \ - 'white', '') + devtl.html += devtl.html_tblock.format('boot', '0', '100', devtl.scaleH) + for p in data.phases: + phase = data.dmesg[p] + length = phase['end']-phase['start'] + left = '%.3f' % (((phase['start']-t0)*100.0)/tTotal) + width = '%.3f' % ((length*100.0)/tTotal) + devtl.html += devtl.html_phase.format(left, width, \ + '%.3f'%devtl.scaleH, '%.3f'%devtl.bodyH, \ + phase['color'], '') # draw the device timeline num = 0 devstats = dict() - for devname in sorted(list): - cls, color = colorForName(devname) - dev = list[devname] - info = '@|%.3f|%.3f|%.3f|%d' % (dev['start']*1000.0, dev['end']*1000.0, - dev['ulen']/1000.0, dev['ret']) - devstats[dev['id']] = {'info':info} - dev['color'] = color - height = devtl.phaseRowHeight(0, phase, dev['row']) - top = '%.6f' % ((dev['row']*height) + devtl.scaleH) - left = '%.6f' % (((dev['start']-t0)*100)/tTotal) - width = '%.6f' % (((dev['end']-dev['start'])*100)/tTotal) - length = ' (%0.3f ms) ' % ((dev['end']-dev['start'])*1000) - devtl.html += devtl.html_device.format(dev['id'], - devname+length+'kernel_mode', left, top, '%.3f'%height, - width, devname, ' '+cls, '') - rowtop = devtl.phaseRowTop(0, phase, dev['row']) - height = '%.6f' % (devtl.rowH / 2) - top = '%.6f' % (rowtop + devtl.scaleH + (devtl.rowH / 2)) - if data.do_one_initcall: - if('ftrace' not in dev): + for phase in data.phases: + list = data.dmesg[phase]['list'] + for devname in sorted(list): + cls, color = colorForName(devname) + dev = list[devname] + info = '@|%.3f|%.3f|%.3f|%d' % (dev['start']*1000.0, dev['end']*1000.0, + dev['ulen']/1000.0, dev['ret']) + devstats[dev['id']] = {'info':info} + dev['color'] = color + height = devtl.phaseRowHeight(0, phase, dev['row']) + top = '%.6f' % ((dev['row']*height) + devtl.scaleH) + left = '%.6f' % (((dev['start']-t0)*100)/tTotal) + width = '%.6f' % (((dev['end']-dev['start'])*100)/tTotal) + length = ' (%0.3f ms) ' % ((dev['end']-dev['start'])*1000) + devtl.html += devtl.html_device.format(dev['id'], + devname+length+phase+'_mode', left, top, '%.3f'%height, + width, devname, ' '+cls, '') + rowtop = devtl.phaseRowTop(0, phase, dev['row']) + height = '%.6f' % (devtl.rowH / 2) + top = '%.6f' % (rowtop + devtl.scaleH + (devtl.rowH / 2)) + if data.do_one_initcall: + if('ftrace' not in dev): + continue + cg = dev['ftrace'] + large, stats = cgOverview(cg, 0.001) + devstats[dev['id']]['fstat'] = stats + for l in large: + left = '%f' % (((l.time-t0)*100)/tTotal) + width = '%f' % (l.length*100/tTotal) + title = '%s (%0.3fms)' % (l.name, l.length * 1000.0) + devtl.html += html_srccall.format(l.name, left, + top, height, width, title, 'x%d'%num) + num += 1 + continue + if('ftraces' not in dev): continue - cg = dev['ftrace'] - large, stats = cgOverview(cg, 0.001) - devstats[dev['id']]['fstat'] = stats - for l in large: - left = '%f' % (((l.time-t0)*100)/tTotal) - width = '%f' % (l.length*100/tTotal) - title = '%s (%0.3fms)' % (l.name, l.length * 1000.0) - devtl.html += html_srccall.format(l.name, left, - top, height, width, title, 'x%d'%num) + for cg in dev['ftraces']: + left = '%f' % (((cg.start-t0)*100)/tTotal) + width = '%f' % ((cg.end-cg.start)*100/tTotal) + cglen = (cg.end - cg.start) * 1000.0 + title = '%s (%0.3fms)' % (cg.name, cglen) + cg.id = 'x%d' % num + devtl.html += html_srccall.format(cg.name, left, + top, height, width, title, dev['id']+cg.id) num += 1 - continue - if('ftraces' not in dev): - continue - for cg in dev['ftraces']: - left = '%f' % (((cg.start-t0)*100)/tTotal) - width = '%f' % ((cg.end-cg.start)*100/tTotal) - cglen = (cg.end - cg.start) * 1000.0 - title = '%s (%0.3fms)' % (cg.name, cglen) - cg.id = 'x%d' % num - devtl.html += html_srccall.format(cg.name, left, - top, height, width, title, dev['id']+cg.id) - num += 1 # draw the time scale, try to make the number of labels readable - devtl.createTimeScale(t0, tMax, tTotal, phase) + devtl.createTimeScale(t0, tMax, tTotal, 'boot') devtl.html += '</div>\n' # timeline is finished devtl.html += '</div>\n</div>\n' + # draw a legend which describes the phases by color + devtl.html += '<div class="legend">\n' + pdelta = 20.0 + pmargin = 36.0 + for phase in data.phases: + order = '%.2f' % ((data.dmesg[phase]['order'] * pdelta) + pmargin) + devtl.html += devtl.html_legend.format(order, \ + data.dmesg[phase]['color'], phase+'_mode', phase[0]) + devtl.html += '</div>\n' + if(sysvals.outfile == sysvals.htmlfile): hf = open(sysvals.htmlfile, 'a') else: @@ -474,7 +597,7 @@ def createBootGraph(data, embedded): .fstat td {text-align:left;width:35px;}\n\ .srccall {position:absolute;font-size:10px;z-index:7;overflow:hidden;color:black;text-align:center;white-space:nowrap;border-radius:5px;border:1px solid black;background:linear-gradient(to bottom right,#CCC,#969696);}\n\ .srccall:hover {color:white;font-weight:bold;border:1px solid white;}\n' - if(not embedded): + if(not sysvals.embedded): aslib.addCSS(hf, sysvals, 1, False, extra) # write the device timeline @@ -495,9 +618,11 @@ def createBootGraph(data, embedded): html = \ '<div id="devicedetailtitle"></div>\n'\ '<div id="devicedetail" style="display:none;">\n'\ - '<div id="devicedetail0">\n'\ - '<div id="kernel_mode" class="phaselet" style="left:0%;width:100%;background:#DDDDDD"></div>\n'\ - '</div>\n</div>\n'\ + '<div id="devicedetail0">\n' + for p in data.phases: + phase = data.dmesg[p] + html += devtl.html_phaselet.format(p+'_mode', '0', '100', phase['color']) + html += '</div>\n</div>\n'\ '<script type="text/javascript">\n'+statinfo+\ '</script>\n' hf.write(html) @@ -507,21 +632,21 @@ def createBootGraph(data, embedded): aslib.addCallgraphs(sysvals, hf, data) # add the dmesg log as a hidden div - if sysvals.addlogs: + if sysvals.dmesglog: hf.write('<div id="dmesglog" style="display:none;">\n') for line in data.dmesgtext: line = line.replace('<', '<').replace('>', '>') hf.write(line) hf.write('</div>\n') - if(not embedded): + if(not sysvals.embedded): # write the footer and close aslib.addScriptCode(hf, [data]) hf.write('</body>\n</html>\n') else: # embedded out will be loaded in a page, skip the js hf.write('<div id=bounds style=display:none>%f,%f</div>' % \ - (data.start*1000, data.initstart*1000)) + (data.start*1000, data.end*1000)) hf.close() return True @@ -533,17 +658,20 @@ def updateCron(restore=False): if not restore: sysvals.rootUser(True) crondir = '/var/spool/cron/crontabs/' - cronfile = crondir+'root' - backfile = crondir+'root-analyze_boot-backup' + if not os.path.exists(crondir): + crondir = '/var/spool/cron/' if not os.path.exists(crondir): doError('%s not found' % crondir) - out = Popen(['which', 'crontab'], stdout=PIPE).stdout.read() - if not out: + cronfile = crondir+'root' + backfile = crondir+'root-analyze_boot-backup' + cmd = sysvals.getExec('crontab') + if not cmd: doError('crontab not found') # on restore: move the backup cron back into place if restore: if os.path.exists(backfile): shutil.move(backfile, cronfile) + call([cmd, cronfile]) return # backup current cron and install new one with reboot if os.path.exists(cronfile): @@ -556,13 +684,13 @@ def updateCron(restore=False): fp = open(backfile, 'r') op = open(cronfile, 'w') for line in fp: - if '@reboot' not in line: + if not sysvals.myCronJob(line): op.write(line) continue fp.close() op.write('@reboot python %s\n' % sysvals.cronjobCmdString()) op.close() - res = call('crontab %s' % cronfile, shell=True) + res = call([cmd, cronfile]) except Exception, e: print 'Exception: %s' % str(e) shutil.move(backfile, cronfile) @@ -577,25 +705,16 @@ def updateGrub(restore=False): # call update-grub on restore if restore: try: - call(['update-grub'], stderr=PIPE, stdout=PIPE, + call(sysvals.blexec, stderr=PIPE, stdout=PIPE, env={'PATH': '.:/sbin:/usr/sbin:/usr/bin:/sbin:/bin'}) except Exception, e: print 'Exception: %s\n' % str(e) return - # verify we can do this - sysvals.rootUser(True) - grubfile = '/etc/default/grub' - if not os.path.exists(grubfile): - print 'ERROR: Unable to set the kernel parameters via grub.\n' - sysvals.manualRebootRequired() - out = Popen(['which', 'update-grub'], stdout=PIPE).stdout.read() - if not out: - print 'ERROR: Unable to set the kernel parameters via grub.\n' - sysvals.manualRebootRequired() - # extract the option and create a grub config without it + sysvals.rootUser(True) tgtopt = 'GRUB_CMDLINE_LINUX_DEFAULT' cmdline = '' + grubfile = '/etc/default/grub' tempfile = '/etc/default/grub.analyze_boot' shutil.move(grubfile, tempfile) res = -1 @@ -622,7 +741,7 @@ def updateGrub(restore=False): # if the target option value is in quotes, strip them sp = '"' val = cmdline.strip() - if val[0] == '\'' or val[0] == '"': + if val and (val[0] == '\'' or val[0] == '"'): sp = val[0] val = val.strip(sp) cmdline = val @@ -633,7 +752,7 @@ def updateGrub(restore=False): # write out the updated target option op.write('\n%s=%s%s%s\n' % (tgtopt, sp, cmdline, sp)) op.close() - res = call('update-grub') + res = call(sysvals.blexec) os.remove(grubfile) except Exception, e: print 'Exception: %s' % str(e) @@ -641,10 +760,18 @@ def updateGrub(restore=False): # cleanup shutil.move(tempfile, grubfile) if res != 0: - doError('update-grub failed') + doError('update grub failed') -# Function: doError +# Function: updateKernelParams # Description: +# update boot conf for all kernels with our parameters +def updateKernelParams(restore=False): + # find the boot loader + sysvals.getBootLoader() + if sysvals.bootloader == 'grub': + updateGrub(restore) + +# Function: doError Description: # generic error function for catastrphic failures # Arguments: # msg: the error message to print @@ -660,7 +787,7 @@ def doError(msg, help=False): # print out the help text def printHelp(): print('') - print('%s v%.1f' % (sysvals.title, sysvals.version)) + print('%s v%s' % (sysvals.title, sysvals.version)) print('Usage: bootgraph <options> <command>') print('') print('Description:') @@ -669,13 +796,19 @@ def printHelp(): print(' the start of the init process.') print('') print(' If no specific command is given the tool reads the current dmesg') - print(' and/or ftrace log and outputs bootgraph.html') + print(' and/or ftrace log and creates a timeline') + print('') + print(' Generates output files in subdirectory: boot-yymmdd-HHMMSS') + print(' HTML output: <hostname>_boot.html') + print(' raw dmesg output: <hostname>_boot_dmesg.txt') + print(' raw ftrace output: <hostname>_boot_ftrace.txt') print('') print('Options:') print(' -h Print this help text') print(' -v Print the current tool version') print(' -addlogs Add the dmesg log to the html output') - print(' -o file Html timeline name (default: bootgraph.html)') + print(' -o name Overrides the output subdirectory name when running a new test') + print(' default: boot-{date}-{time}') print(' [advanced]') print(' -f Use ftrace to add function detail (default: disabled)') print(' -callgraph Add callgraph detail, can be very large (default: disabled)') @@ -683,13 +816,18 @@ def printHelp(): print(' -mincg ms Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)') print(' -timeprec N Number of significant digits in timestamps (0:S, 3:ms, [6:us])') print(' -expandcg pre-expand the callgraph data in the html output (default: disabled)') - print(' -filter list Limit ftrace to comma-delimited list of functions (default: do_one_initcall)') - print(' [commands]') + print(' -func list Limit ftrace to comma-delimited list of functions (default: do_one_initcall)') + print(' -cgfilter S Filter the callgraph output in the timeline') + print(' -bl name Use the following boot loader for kernel params (default: grub)') print(' -reboot Reboot the machine automatically and generate a new timeline') - print(' -manual Show the requirements to generate a new timeline manually') - print(' -dmesg file Load a stored dmesg file (used with -ftrace)') - print(' -ftrace file Load a stored ftrace file (used with -dmesg)') + print(' -manual Show the steps to generate a new timeline manually (used with -reboot)') + print('') + print('Other commands:') print(' -flistall Print all functions capable of being captured in ftrace') + print(' -sysinfo Print out system info extracted from BIOS') + print(' [redo]') + print(' -dmesg file Create HTML output using dmesg input (used with -ftrace)') + print(' -ftrace file Create HTML output using ftrace input (used with -dmesg)') print('') return True @@ -698,14 +836,15 @@ def printHelp(): if __name__ == '__main__': # loop through the command line arguments cmd = '' - simplecmds = ['-updategrub', '-flistall'] + testrun = True + simplecmds = ['-sysinfo', '-kpupdate', '-flistall', '-checkbl'] args = iter(sys.argv[1:]) for arg in args: if(arg == '-h'): printHelp() sys.exit() elif(arg == '-v'): - print("Version %.1f" % sysvals.version) + print("Version %s" % sysvals.version) sys.exit() elif(arg in simplecmds): cmd = arg[1:] @@ -716,16 +855,32 @@ if __name__ == '__main__': sysvals.usecallgraph = True elif(arg == '-mincg'): sysvals.mincglen = aslib.getArgFloat('-mincg', args, 0.0, 10000.0) + elif(arg == '-cgfilter'): + try: + val = args.next() + except: + doError('No callgraph functions supplied', True) + sysvals.setDeviceFilter(val) + elif(arg == '-bl'): + try: + val = args.next() + except: + doError('No boot loader name supplied', True) + if val.lower() not in ['grub']: + doError('Unknown boot loader: %s' % val, True) + sysvals.bootloader = val.lower() elif(arg == '-timeprec'): sysvals.setPrecision(aslib.getArgInt('-timeprec', args, 0, 6)) elif(arg == '-maxdepth'): sysvals.max_graph_depth = aslib.getArgInt('-maxdepth', args, 0, 1000) - elif(arg == '-filter'): + elif(arg == '-func'): try: val = args.next() except: doError('No filter functions supplied', True) - aslib.rootCheck(True) + sysvals.useftrace = True + sysvals.usecallgraph = True + sysvals.rootCheck(True) sysvals.setGraphFilter(val) elif(arg == '-ftrace'): try: @@ -734,9 +889,10 @@ if __name__ == '__main__': doError('No ftrace file supplied', True) if(os.path.exists(val) == False): doError('%s does not exist' % val) + testrun = False sysvals.ftracefile = val elif(arg == '-addlogs'): - sysvals.addlogs = True + sysvals.dmesglog = True elif(arg == '-expandcg'): sysvals.cgexp = True elif(arg == '-dmesg'): @@ -748,18 +904,15 @@ if __name__ == '__main__': doError('%s does not exist' % val) if(sysvals.htmlfile == val or sysvals.outfile == val): doError('Output filename collision') + testrun = False sysvals.dmesgfile = val elif(arg == '-o'): try: val = args.next() except: - doError('No HTML filename supplied', True) - if(sysvals.dmesgfile == val or sysvals.ftracefile == val): - doError('Output filename collision') - sysvals.htmlfile = val + doError('No subdirectory name supplied', True) + sysvals.testdir = sysvals.setOutputFolder(val) elif(arg == '-reboot'): - if sysvals.iscronjob: - doError('-reboot and -cronjob are incompatible') sysvals.reboot = True elif(arg == '-manual'): sysvals.reboot = True @@ -767,58 +920,93 @@ if __name__ == '__main__': # remaining options are only for cron job use elif(arg == '-cronjob'): sysvals.iscronjob = True - if sysvals.reboot: - doError('-reboot and -cronjob are incompatible') else: doError('Invalid argument: '+arg, True) + # compatibility errors and access checks + if(sysvals.iscronjob and (sysvals.reboot or \ + sysvals.dmesgfile or sysvals.ftracefile or cmd)): + doError('-cronjob is meant for batch purposes only') + if(sysvals.reboot and (sysvals.dmesgfile or sysvals.ftracefile)): + doError('-reboot and -dmesg/-ftrace are incompatible') + if cmd or sysvals.reboot or sysvals.iscronjob or testrun: + sysvals.rootCheck(True) + if (testrun and sysvals.useftrace) or cmd == 'flistall': + if not sysvals.verifyFtrace(): + doError('Ftrace is not properly enabled') + + # run utility commands + sysvals.cpuInfo() if cmd != '': - if cmd == 'updategrub': - updateGrub() + if cmd == 'kpupdate': + updateKernelParams() elif cmd == 'flistall': - sysvals.getFtraceFilterFunctions(False) + for f in sysvals.getBootFtraceFilterFunctions(): + print f + elif cmd == 'checkbl': + sysvals.getBootLoader() + print 'Boot Loader: %s\n%s' % (sysvals.bootloader, sysvals.blexec) + elif(cmd == 'sysinfo'): + sysvals.printSystemInfo() sys.exit() - # update grub, setup a cronjob, and reboot + # reboot: update grub, setup a cronjob, and reboot if sysvals.reboot: + if (sysvals.useftrace or sysvals.usecallgraph) and \ + not sysvals.checkFtraceKernelVersion(): + doError('Ftrace functionality requires kernel v4.10 or newer') if not sysvals.manual: - updateGrub() + updateKernelParams() updateCron() call('reboot') else: sysvals.manualRebootRequired() sys.exit() - # disable the cronjob + # cronjob: remove the cronjob, grub changes, and disable ftrace if sysvals.iscronjob: updateCron(True) - updateGrub(True) + updateKernelParams(True) + try: + sysvals.fsetVal('0', 'tracing_on') + except: + pass - data = loadKernelLog() - if sysvals.useftrace: - loadTraceLog(data) - if sysvals.iscronjob: - try: - sysvals.fsetVal('0', 'tracing_on') - except: - pass + # testrun: generate copies of the logs + if testrun: + retrieveLogs() + else: + sysvals.setOutputFile() - if(sysvals.outfile and sysvals.phoronix): - fp = open(sysvals.outfile, 'w') - fp.write('pass %s initstart %.3f end %.3f boot %s\n' % - (data.valid, data.initstart*1000, data.end*1000, data.boottime)) - fp.close() - if(not data.valid): - if sysvals.dmesgfile: + # process the log data + if sysvals.dmesgfile: + data = parseKernelLog() + if(not data.valid): doError('No initcall data found in %s' % sysvals.dmesgfile) - else: - doError('No initcall data found, is initcall_debug enabled?') + if sysvals.useftrace and sysvals.ftracefile: + parseTraceLog(data) + else: + doError('dmesg file required') print(' Host: %s' % sysvals.hostname) print(' Test time: %s' % sysvals.testtime) print(' Boot time: %s' % data.boottime) print('Kernel Version: %s' % sysvals.kernel) print(' Kernel start: %.3f' % (data.start * 1000)) - print(' init start: %.3f' % (data.initstart * 1000)) + print('Usermode start: %.3f' % (data.tUserMode * 1000)) + print('Last Init Call: %.3f' % (data.end * 1000)) + + # handle embedded output logs + if(sysvals.outfile and sysvals.embedded): + fp = open(sysvals.outfile, 'w') + fp.write('pass %s initstart %.3f end %.3f boot %s\n' % + (data.valid, data.tUserMode*1000, data.end*1000, data.boottime)) + fp.close() + + createBootGraph(data) - createBootGraph(data, sysvals.phoronix) + # if running as root, change output dir owner to sudo_user + if testrun and os.path.isdir(sysvals.testdir) and \ + os.getuid() == 0 and 'SUDO_USER' in os.environ: + cmd = 'chown -R {0}:{0} {1} > /dev/null 2>&1' + call(cmd.format(os.environ['SUDO_USER'], sysvals.testdir), shell=True) diff --git a/tools/power/pm-graph/analyze_suspend.py b/tools/power/pm-graph/analyze_suspend.py index a9206e67fc1f..1b60fe203741 100755 --- a/tools/power/pm-graph/analyze_suspend.py +++ b/tools/power/pm-graph/analyze_suspend.py @@ -68,10 +68,12 @@ from subprocess import call, Popen, PIPE # store system values and test parameters class SystemValues: title = 'SleepGraph' - version = '4.6' + version = '4.7' ansi = False verbose = False - addlogs = False + testlog = True + dmesglog = False + ftracelog = False mindevlen = 0.0 mincglen = 0.0 cgphase = '' @@ -79,10 +81,11 @@ class SystemValues: max_graph_depth = 0 callloopmaxgap = 0.0001 callloopmaxlen = 0.005 + cpucount = 0 + memtotal = 204800 srgap = 0 cgexp = False - outdir = '' - testdir = '.' + testdir = '' tpath = '/sys/kernel/debug/tracing/' fpdtpath = '/sys/firmware/acpi/tables/FPDT' epath = '/sys/kernel/debug/tracing/events/power/' @@ -95,14 +98,17 @@ class SystemValues: testcommand = '' mempath = '/dev/mem' powerfile = '/sys/power/state' + mempowerfile = '/sys/power/mem_sleep' suspendmode = 'mem' + memmode = '' hostname = 'localhost' prefix = 'test' teststamp = '' + sysstamp = '' dmesgstart = 0.0 dmesgfile = '' ftracefile = '' - htmlfile = '' + htmlfile = 'output.html' embedded = False rtcwake = True rtcwaketime = 15 @@ -127,9 +133,6 @@ class SystemValues: devpropfmt = '# Device Properties: .*' tracertypefmt = '# tracer: (?P<t>.*)' firmwarefmt = '# fwsuspend (?P<s>[0-9]*) fwresume (?P<r>[0-9]*)$' - stampfmt = '# suspend-(?P<m>[0-9]{2})(?P<d>[0-9]{2})(?P<y>[0-9]{2})-'+\ - '(?P<H>[0-9]{2})(?P<M>[0-9]{2})(?P<S>[0-9]{2})'+\ - ' (?P<host>.*) (?P<mode>.*) (?P<kernel>.*)$' tracefuncs = { 'sys_sync': dict(), 'pm_prepare_console': dict(), @@ -218,7 +221,7 @@ class SystemValues: # if this is a phoronix test run, set some default options if('LOG_FILE' in os.environ and 'TEST_RESULTS_IDENTIFIER' in os.environ): self.embedded = True - self.addlogs = True + self.dmesglog = self.ftracelog = True self.htmlfile = os.environ['LOG_FILE'] self.archargs = 'args_'+platform.machine() self.hostname = platform.node() @@ -233,6 +236,13 @@ class SystemValues: self.rtcpath = rtc if (hasattr(sys.stdout, 'isatty') and sys.stdout.isatty()): self.ansi = True + self.testdir = datetime.now().strftime('suspend-%y%m%d-%H%M%S') + def rootCheck(self, fatal=True): + if(os.access(self.powerfile, os.W_OK)): + return True + if fatal: + doError('This command requires sysfs mount and root access') + return False def rootUser(self, fatal=False): if 'USER' in os.environ and os.environ['USER'] == 'root': return True @@ -249,30 +259,60 @@ class SystemValues: args['date'] = n.strftime('%y%m%d') args['time'] = n.strftime('%H%M%S') args['hostname'] = self.hostname - self.outdir = value.format(**args) + return value.format(**args) def setOutputFile(self): - if((self.htmlfile == '') and (self.dmesgfile != '')): + if self.dmesgfile != '': m = re.match('(?P<name>.*)_dmesg\.txt$', self.dmesgfile) if(m): self.htmlfile = m.group('name')+'.html' - if((self.htmlfile == '') and (self.ftracefile != '')): + if self.ftracefile != '': m = re.match('(?P<name>.*)_ftrace\.txt$', self.ftracefile) if(m): self.htmlfile = m.group('name')+'.html' - if(self.htmlfile == ''): - self.htmlfile = 'output.html' - def initTestOutput(self, subdir, testpath=''): + def systemInfo(self, info): + p = c = m = b = '' + if 'baseboard-manufacturer' in info: + 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: + p = info['system-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' % \ + (m, p, c, b, self.cpucount, self.memtotal) + def printSystemInfo(self): + self.rootCheck(True) + out = dmidecode(self.mempath, True) + 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)) + def cpuInfo(self): + self.cpucount = 0 + fp = open('/proc/cpuinfo', 'r') + for line in fp: + if re.match('^processor[ \t]*:[ \t]*[0-9]*', line): + self.cpucount += 1 + fp.close() + fp = open('/proc/meminfo', 'r') + for line in fp: + m = re.match('^MemTotal:[ \t]*(?P<sz>[0-9]*) *kB', line) + if m: + self.memtotal = int(m.group('sz')) + break + fp.close() + def initTestOutput(self, name): self.prefix = self.hostname v = open('/proc/version', 'r').read().strip() kver = string.split(v)[2] - n = datetime.now() - testtime = n.strftime('suspend-%m%d%y-%H%M%S') - if not testpath: - testpath = n.strftime('suspend-%y%m%d-%H%M%S') - if(subdir != "."): - self.testdir = subdir+"/"+testpath - else: - self.testdir = testpath + fmt = name+'-%m%d%y-%H%M%S' + testtime = datetime.now().strftime(fmt) self.teststamp = \ '# '+testtime+' '+self.prefix+' '+self.suspendmode+' '+kver if(self.embedded): @@ -355,7 +395,7 @@ class SystemValues: continue self.tracefuncs[i] = dict() def getFtraceFilterFunctions(self, current): - rootCheck(True) + self.rootCheck(True) if not current: call('cat '+self.tpath+'available_filter_functions', shell=True) return @@ -453,7 +493,7 @@ class SystemValues: val += '\nr:%s_ret %s $retval\n' % (name, func) return val def addKprobes(self, output=False): - if len(sysvals.kprobes) < 1: + if len(self.kprobes) < 1: return if output: print(' kprobe functions in this kernel:') @@ -525,7 +565,7 @@ class SystemValues: fp.flush() fp.close() except: - pass + return False return True def fgetVal(self, path): file = self.tpath+path @@ -566,9 +606,15 @@ class SystemValues: self.cleanupFtrace() # set the trace clock to global self.fsetVal('global', 'trace_clock') - # set trace buffer to a huge value self.fsetVal('nop', 'current_tracer') - self.fsetVal('131073', 'buffer_size_kb') + # set trace buffer to a huge value + if self.usecallgraph or self.usedevsrc: + tgtsize = min(self.memtotal / 2, 2*1024*1024) + maxbuf = '%d' % (tgtsize / max(1, self.cpucount)) + if self.cpucount < 1 or not self.fsetVal(maxbuf, 'buffer_size_kb'): + self.fsetVal('131072', 'buffer_size_kb') + else: + self.fsetVal('16384', 'buffer_size_kb') # go no further if this is just a status check if testing: return @@ -641,6 +687,15 @@ class SystemValues: if not self.ansi: return str return '\x1B[%d;40m%s\x1B[m' % (color, str) + def writeDatafileHeader(self, filename, fwdata=[]): + fp = open(filename, 'w') + fp.write(self.teststamp+'\n') + fp.write(self.sysstamp+'\n') + if(self.suspendmode == 'mem' or self.suspendmode == 'command'): + for fw in fwdata: + if(fw): + fp.write('# fwsuspend %u fwresume %u\n' % (fw[0], fw[1])) + fp.close() sysvals = SystemValues() suspendmodename = { @@ -1008,6 +1063,12 @@ class Data: else: self.trimTime(self.tSuspended, \ self.tResumed-self.tSuspended, False) + def getTimeValues(self): + sktime = (self.dmesg['suspend_machine']['end'] - \ + self.tKernSus) * 1000 + rktime = (self.dmesg['resume_complete']['end'] - \ + self.dmesg['resume_machine']['start']) * 1000 + return (sktime, rktime) def setPhase(self, phase, ktime, isbegin): if(isbegin): self.dmesg[phase]['start'] = ktime @@ -1517,7 +1578,7 @@ class FTraceCallGraph: prelinedep += 1 last = 0 lasttime = line.time - virtualfname = 'execution_misalignment' + virtualfname = 'missing_function_name' if len(self.list) > 0: last = self.list[-1] lasttime = last.time @@ -1773,24 +1834,30 @@ class Timeline: html_device = '<div id="{0}" title="{1}" class="thread{7}" style="left:{2}%;top:{3}px;height:{4}px;width:{5}%;{8}">{6}</div>\n' html_phase = '<div class="phase" style="left:{0}%;width:{1}%;top:{2}px;height:{3}px;background:{4}">{5}</div>\n' html_phaselet = '<div id="{0}" class="phaselet" style="left:{1}%;width:{2}%;background:{3}"></div>\n' + html_legend = '<div id="p{3}" class="square" style="left:{0}%;background:{1}"> {2}</div>\n' def __init__(self, rowheight, scaleheight): self.rowH = rowheight self.scaleH = scaleheight self.html = '' - def createHeader(self, sv, suppress=''): + def createHeader(self, sv): if(not sv.stamp['time']): return self.html += '<div class="version"><a href="https://01.org/suspendresume">%s v%s</a></div>' \ % (sv.title, sv.version) - if sv.logmsg and 'log' not in suppress: - self.html += '<button id="showtest" class="logbtn">log</button>' - if sv.addlogs and 'dmesg' not in suppress: - self.html += '<button id="showdmesg" class="logbtn">dmesg</button>' - if sv.addlogs and sv.ftracefile and 'ftrace' not in suppress: - self.html += '<button id="showftrace" class="logbtn">ftrace</button>' + if sv.logmsg and sv.testlog: + self.html += '<button id="showtest" class="logbtn btnfmt">log</button>' + if sv.dmesglog: + self.html += '<button id="showdmesg" class="logbtn btnfmt">dmesg</button>' + if sv.ftracelog: + self.html += '<button id="showftrace" class="logbtn btnfmt">ftrace</button>' headline_stamp = '<div class="stamp">{0} {1} {2} {3}</div>\n' self.html += headline_stamp.format(sv.stamp['host'], sv.stamp['kernel'], sv.stamp['mode'], sv.stamp['time']) + if 'man' in sv.stamp and 'plat' in sv.stamp and 'cpu' in sv.stamp: + headline_sysinfo = '<div class="stamp sysinfo">{0} {1} <i>with</i> {2}</div>\n' + self.html += headline_sysinfo.format(sv.stamp['man'], + sv.stamp['plat'], sv.stamp['cpu']) + # Function: getDeviceRows # Description: # determine how may rows the device funcs will take @@ -1839,7 +1906,7 @@ class Timeline: # devlist: the list of devices/actions in a group of contiguous phases # Output: # The total number of rows needed to display this phase of the timeline - def getPhaseRows(self, devlist, row=0): + def getPhaseRows(self, devlist, row=0, sortby='length'): # clear all rows and set them to undefined remaining = len(devlist) rowdata = dict() @@ -1852,8 +1919,12 @@ class Timeline: if tp not in myphases: myphases.append(tp) dev['row'] = -1 - # sort by length 1st, then name 2nd - sortdict[item] = (float(dev['end']) - float(dev['start']), item.dev['name']) + if sortby == 'start': + # sort by start 1st, then length 2nd + sortdict[item] = (-1*float(dev['start']), float(dev['end']) - float(dev['start'])) + else: + # sort by length 1st, then name 2nd + sortdict[item] = (float(dev['end']) - float(dev['start']), item.dev['name']) if 'src' in dev: dev['devrows'] = self.getDeviceRows(dev['src']) # sort the devlist by length so that large items graph on top @@ -1995,8 +2066,13 @@ class Timeline: # A list of values describing the properties of these test runs class TestProps: stamp = '' + sysinfo = '' S0i3 = False fwdata = [] + stampfmt = '# [a-z]*-(?P<m>[0-9]{2})(?P<d>[0-9]{2})(?P<y>[0-9]{2})-'+\ + '(?P<H>[0-9]{2})(?P<M>[0-9]{2})(?P<S>[0-9]{2})'+\ + ' (?P<host>.*) (?P<mode>.*) (?P<kernel>.*)$' + sysinfofmt = '^# sysinfo .*' ftrace_line_fmt_fg = \ '^ *(?P<time>[0-9\.]*) *\| *(?P<cpu>[0-9]*)\)'+\ ' *(?P<proc>.*)-(?P<pid>[0-9]*) *\|'+\ @@ -2019,6 +2095,36 @@ class TestProps: self.ftrace_line_fmt = self.ftrace_line_fmt_nop else: doError('Invalid tracer format: [%s]' % tracer) + def parseStamp(self, data, sv): + m = re.match(self.stampfmt, self.stamp) + data.stamp = {'time': '', 'host': '', 'mode': ''} + dt = datetime(int(m.group('y'))+2000, int(m.group('m')), + int(m.group('d')), int(m.group('H')), int(m.group('M')), + int(m.group('S'))) + data.stamp['time'] = dt.strftime('%B %d %Y, %I:%M:%S %p') + data.stamp['host'] = m.group('host') + data.stamp['mode'] = m.group('mode') + data.stamp['kernel'] = m.group('kernel') + if re.match(self.sysinfofmt, self.sysinfo): + for f in self.sysinfo.split('|'): + if '#' in f: + continue + tmp = f.strip().split(':', 1) + key = tmp[0] + val = tmp[1] + data.stamp[key] = val + sv.hostname = data.stamp['host'] + sv.suspendmode = data.stamp['mode'] + if sv.suspendmode == 'command' and sv.ftracefile != '': + modes = ['on', 'freeze', 'standby', 'mem'] + out = Popen(['grep', 'suspend_enter', sv.ftracefile], + stderr=PIPE, stdout=PIPE).stdout.read() + m = re.match('.* suspend_enter\[(?P<mode>.*)\]', out) + if m and m.group('mode') in ['1', '2', '3']: + sv.suspendmode = modes[int(m.group('mode'))] + data.stamp['mode'] = sv.suspendmode + if not sv.stamp: + sv.stamp = data.stamp # Class: TestRun # Description: @@ -2090,35 +2196,6 @@ def vprint(msg): if(sysvals.verbose): print(msg) -# Function: parseStamp -# Description: -# Pull in the stamp comment line from the data file(s), -# create the stamp, and add it to the global sysvals object -# Arguments: -# m: the valid re.match output for the stamp line -def parseStamp(line, data): - m = re.match(sysvals.stampfmt, line) - data.stamp = {'time': '', 'host': '', 'mode': ''} - dt = datetime(int(m.group('y'))+2000, int(m.group('m')), - int(m.group('d')), int(m.group('H')), int(m.group('M')), - int(m.group('S'))) - data.stamp['time'] = dt.strftime('%B %d %Y, %I:%M:%S %p') - data.stamp['host'] = m.group('host') - data.stamp['mode'] = m.group('mode') - data.stamp['kernel'] = m.group('kernel') - sysvals.hostname = data.stamp['host'] - sysvals.suspendmode = data.stamp['mode'] - if sysvals.suspendmode == 'command' and sysvals.ftracefile != '': - modes = ['on', 'freeze', 'standby', 'mem'] - out = Popen(['grep', 'suspend_enter', sysvals.ftracefile], - stderr=PIPE, stdout=PIPE).stdout.read() - m = re.match('.* suspend_enter\[(?P<mode>.*)\]', out) - if m and m.group('mode') in ['1', '2', '3']: - sysvals.suspendmode = modes[int(m.group('mode'))] - data.stamp['mode'] = sysvals.suspendmode - if not sysvals.stamp: - sysvals.stamp = data.stamp - # Function: doesTraceLogHaveTraceEvents # Description: # Quickly determine if the ftrace log has some or all of the trace events @@ -2136,11 +2213,6 @@ def doesTraceLogHaveTraceEvents(): sysvals.usekprobes = True out = Popen(['head', '-1', sysvals.ftracefile], stderr=PIPE, stdout=PIPE).stdout.read().replace('\n', '') - m = re.match(sysvals.stampfmt, out) - if m and m.group('mode') == 'command': - sysvals.usetraceeventsonly = True - sysvals.usetraceevents = True - return # figure out what level of trace events are supported sysvals.usetraceeventsonly = True sysvals.usetraceevents = False @@ -2182,11 +2254,13 @@ def appendIncompleteTraceLog(testruns): for line in tf: # remove any latent carriage returns line = line.replace('\r\n', '') - # grab the time stamp - m = re.match(sysvals.stampfmt, line) - if(m): + # 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 # determine the trace data type (required for further parsing) m = re.match(sysvals.tracertypefmt, line) if(m): @@ -2219,7 +2293,7 @@ def appendIncompleteTraceLog(testruns): # look for the suspend start marker if(t.startMarker()): data = testrun[testidx].data - parseStamp(tp.stamp, data) + tp.parseStamp(data, sysvals) data.setStart(t.time) continue if(not data): @@ -2389,11 +2463,13 @@ def parseTraceLog(): for line in tf: # remove any latent carriage returns line = line.replace('\r\n', '') - # stamp line: each stamp means a new test run - m = re.match(sysvals.stampfmt, line) - if(m): + # stamp and sysinfo lines + if re.match(tp.stampfmt, line): tp.stamp = line continue + elif re.match(tp.sysinfofmt, line): + tp.sysinfo = line + continue # firmware line: pull out any firmware data m = re.match(sysvals.firmwarefmt, line) if(m): @@ -2439,7 +2515,7 @@ def parseTraceLog(): testdata.append(data) testrun = TestRun(data) testruns.append(testrun) - parseStamp(tp.stamp, data) + tp.parseStamp(data, sysvals) data.setStart(t.time) data.tKernSus = t.time continue @@ -2820,10 +2896,13 @@ def loadKernelLog(justtext=False): idx = line.find('[') if idx > 1: line = line[idx:] - m = re.match(sysvals.stampfmt, line) - if(m): + # 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 m = re.match(sysvals.firmwarefmt, line) if(m): tp.fwdata.append((int(m.group('s')), int(m.group('r')))) @@ -2839,7 +2918,7 @@ def loadKernelLog(justtext=False): if(data): testruns.append(data) data = Data(len(testruns)) - parseStamp(tp.stamp, data) + tp.parseStamp(data, sysvals) if len(tp.fwdata) > data.testnumber: data.fwSuspend, data.fwResume = tp.fwdata[data.testnumber] if(data.fwSuspend > 0 or data.fwResume > 0): @@ -3170,6 +3249,8 @@ def addCallgraphs(sv, hf, data): continue list = data.dmesg[p]['list'] for devname in data.sortedDevices(p): + if len(sv.devicefilter) > 0 and devname not in sv.devicefilter: + continue dev = list[devname] color = 'white' if 'color' in data.dmesg[p]: @@ -3309,7 +3390,6 @@ def createHTML(testruns): html_error = '<div id="{1}" title="kernel error/warning" class="err" style="right:{0}%">ERROR→</div>\n' html_traceevent = '<div title="{0}" class="traceevent{6}" style="left:{1}%;top:{2}px;height:{3}px;width:{4}%;line-height:{3}px;{7}">{5}</div>\n' html_cpuexec = '<div class="jiffie" style="left:{0}%;top:{1}px;height:{2}px;width:{3}%;background:{4};"></div>\n' - html_legend = '<div id="p{3}" class="square" style="left:{0}%;background:{1}"> {2}</div>\n' html_timetotal = '<table class="time1">\n<tr>'\ '<td class="green" title="{3}">{2} Suspend Time: <b>{0} ms</b></td>'\ '<td class="yellow" title="{4}">{2} Resume Time: <b>{1} ms</b></td>'\ @@ -3346,10 +3426,7 @@ def createHTML(testruns): # Generate the header for this timeline for data in testruns: tTotal = data.end - data.start - sktime = (data.dmesg['suspend_machine']['end'] - \ - data.tKernSus) * 1000 - rktime = (data.dmesg['resume_complete']['end'] - \ - data.dmesg['resume_machine']['start']) * 1000 + sktime, rktime = data.getTimeValues() if(tTotal == 0): print('ERROR: No timeline data') sys.exit() @@ -3581,7 +3658,7 @@ def createHTML(testruns): id += tmp[1][0] order = '%.2f' % ((data.dmesg[phase]['order'] * pdelta) + pmargin) name = string.replace(phase, '_', ' ') - devtl.html += html_legend.format(order, \ + devtl.html += devtl.html_legend.format(order, \ data.dmesg[phase]['color'], name, id) devtl.html += '</div>\n' @@ -3628,10 +3705,10 @@ def createHTML(testruns): addCallgraphs(sysvals, hf, data) # add the test log as a hidden div - if sysvals.logmsg: + if sysvals.testlog and sysvals.logmsg: hf.write('<div id="testlog" style="display:none;">\n'+sysvals.logmsg+'</div>\n') # add the dmesg log as a hidden div - if sysvals.addlogs and sysvals.dmesgfile: + if sysvals.dmesglog and sysvals.dmesgfile: hf.write('<div id="dmesglog" style="display:none;">\n') lf = open(sysvals.dmesgfile, 'r') for line in lf: @@ -3640,7 +3717,7 @@ def createHTML(testruns): lf.close() hf.write('</div>\n') # add the ftrace log as a hidden div - if sysvals.addlogs and sysvals.ftracefile: + if sysvals.ftracelog and sysvals.ftracefile: hf.write('<div id="ftracelog" style="display:none;">\n') lf = open(sysvals.ftracefile, 'r') for line in lf: @@ -3701,6 +3778,7 @@ def addCSS(hf, sv, testcount=1, kerror=False, extra=''): <style type=\'text/css\'>\n\ body {overflow-y:scroll;}\n\ .stamp {width:100%;text-align:center;background:gray;line-height:30px;color:white;font:25px Arial;}\n\ + .stamp.sysinfo {font:10px Arial;}\n\ .callgraph {margin-top:30px;box-shadow:5px 5px 20px black;}\n\ .callgraph article * {padding-left:28px;}\n\ h1 {color:black;font:bold 30px Times;}\n\ @@ -3746,7 +3824,7 @@ def addCSS(hf, sv, testcount=1, kerror=False, extra=''): .legend {position:relative; width:100%; height:40px; text-align:center;margin-bottom:20px}\n\ .legend .square {position:absolute;cursor:pointer;top:10px; width:0px;height:20px;border:1px solid;padding-left:20px;}\n\ button {height:40px;width:200px;margin-bottom:20px;margin-top:20px;font-size:24px;}\n\ - .logbtn {position:relative;float:right;height:25px;width:50px;margin-top:3px;margin-bottom:0;font-size:10px;text-align:center;}\n\ + .btnfmt {position:relative;float:right;height:25px;width:auto;margin-top:3px;margin-bottom:0;font-size:10px;text-align:center;}\n\ .devlist {position:'+devlistpos+';width:190px;}\n\ a:link {color:white;text-decoration:none;}\n\ a:visited {color:white;}\n\ @@ -4084,8 +4162,6 @@ def addScriptCode(hf, testruns): ' win.document.write(title+"<pre>"+log.innerHTML+"</pre>");\n'\ ' win.document.close();\n'\ ' }\n'\ - ' function onClickPhase(e) {\n'\ - ' }\n'\ ' function onMouseDown(e) {\n'\ ' dragval[0] = e.clientX;\n'\ ' dragval[1] = document.getElementById("dmesgzoombox").scrollLeft;\n'\ @@ -4120,9 +4196,6 @@ def addScriptCode(hf, testruns): ' document.getElementById("zoomin").onclick = zoomTimeline;\n'\ ' document.getElementById("zoomout").onclick = zoomTimeline;\n'\ ' document.getElementById("zoomdef").onclick = zoomTimeline;\n'\ - ' var list = document.getElementsByClassName("square");\n'\ - ' for (var i = 0; i < list.length; i++)\n'\ - ' list[i].onclick = onClickPhase;\n'\ ' var list = document.getElementsByClassName("err");\n'\ ' for (var i = 0; i < list.length; i++)\n'\ ' list[i].onclick = errWindow;\n'\ @@ -4193,8 +4266,14 @@ def executeSuspend(): if sysvals.testcommand != '': call(sysvals.testcommand+' 2>&1', shell=True); else: + mode = sysvals.suspendmode + if sysvals.memmode and os.path.exists(sysvals.mempowerfile): + mode = 'mem' + pf = open(sysvals.mempowerfile, 'w') + pf.write(sysvals.memmode) + pf.close() pf = open(sysvals.powerfile, 'w') - pf.write(sysvals.suspendmode) + pf.write(mode) # execution will pause here try: pf.close() @@ -4219,24 +4298,15 @@ def executeSuspend(): pm.stop() sysvals.fsetVal('0', 'tracing_on') print('CAPTURING TRACE') - writeDatafileHeader(sysvals.ftracefile, fwdata) + sysvals.writeDatafileHeader(sysvals.ftracefile, fwdata) call('cat '+tp+'trace >> '+sysvals.ftracefile, shell=True) sysvals.fsetVal('', 'trace') devProps() # grab a copy of the dmesg output print('CAPTURING DMESG') - writeDatafileHeader(sysvals.dmesgfile, fwdata) + sysvals.writeDatafileHeader(sysvals.dmesgfile, fwdata) sysvals.getdmesg() -def writeDatafileHeader(filename, fwdata): - fp = open(filename, 'a') - fp.write(sysvals.teststamp+'\n') - if(sysvals.suspendmode == 'mem' or sysvals.suspendmode == 'command'): - for fw in fwdata: - if(fw): - fp.write('# fwsuspend %u fwresume %u\n' % (fw[0], fw[1])) - fp.close() - # Function: setUSBDevicesAuto # Description: # Set the autosuspend control parameter of all USB devices to auto @@ -4244,7 +4314,7 @@ def writeDatafileHeader(filename, fwdata): # to always-on since the kernel cant determine if the device can # properly autosuspend def setUSBDevicesAuto(): - rootCheck(True) + sysvals.rootCheck(True) for dirname, dirnames, filenames in os.walk('/sys/devices'): if(re.match('.*/usb[0-9]*.*', dirname) and 'idVendor' in filenames and 'idProduct' in filenames): @@ -4467,13 +4537,146 @@ def devProps(data=0): # Output: # A string list of the available modes def getModes(): - modes = '' + modes = [] if(os.path.exists(sysvals.powerfile)): fp = open(sysvals.powerfile, 'r') modes = string.split(fp.read()) fp.close() + if(os.path.exists(sysvals.mempowerfile)): + deep = False + fp = open(sysvals.mempowerfile, 'r') + for m in string.split(fp.read()): + memmode = m.strip('[]') + if memmode == 'deep': + deep = True + else: + modes.append('mem-%s' % memmode) + fp.close() + if 'mem' in modes and not deep: + modes.remove('mem') return modes +# Function: dmidecode +# Description: +# Read the bios tables and pull out system info +# Arguments: +# mempath: /dev/mem or custom mem path +# fatal: True to exit on error, False to return empty dict +# Output: +# A dict object with all available key/values +def dmidecode(mempath, fatal=False): + out = dict() + + # the list of values to retrieve, with hardcoded (type, idx) + info = { + 'bios-vendor': (0, 4), + 'bios-version': (0, 5), + 'bios-release-date': (0, 8), + 'system-manufacturer': (1, 4), + 'system-product-name': (1, 5), + 'system-version': (1, 6), + 'system-serial-number': (1, 7), + 'baseboard-manufacturer': (2, 4), + 'baseboard-product-name': (2, 5), + 'baseboard-version': (2, 6), + 'baseboard-serial-number': (2, 7), + 'chassis-manufacturer': (3, 4), + 'chassis-type': (3, 5), + 'chassis-version': (3, 6), + 'chassis-serial-number': (3, 7), + 'processor-manufacturer': (4, 7), + 'processor-version': (4, 16), + } + if(not os.path.exists(mempath)): + if(fatal): + doError('file does not exist: %s' % mempath) + return out + if(not os.access(mempath, os.R_OK)): + if(fatal): + doError('file is not readable: %s' % mempath) + return out + + # by default use legacy scan, but try to use EFI first + memaddr = 0xf0000 + memsize = 0x10000 + for ep in ['/sys/firmware/efi/systab', '/proc/efi/systab']: + if not os.path.exists(ep) or not os.access(ep, os.R_OK): + continue + fp = open(ep, 'r') + buf = fp.read() + fp.close() + i = buf.find('SMBIOS=') + if i >= 0: + try: + memaddr = int(buf[i+7:], 16) + memsize = 0x20 + except: + continue + + # read in the memory for scanning + fp = open(mempath, 'rb') + try: + fp.seek(memaddr) + buf = fp.read(memsize) + except: + if(fatal): + doError('DMI table is unreachable, sorry') + else: + return out + fp.close() + + # search for either an SM table or DMI table + i = base = length = num = 0 + while(i < memsize): + if buf[i:i+4] == '_SM_' and i < memsize - 16: + length = struct.unpack('H', buf[i+22:i+24])[0] + base, num = struct.unpack('IH', buf[i+24:i+30]) + break + elif buf[i:i+5] == '_DMI_': + length = struct.unpack('H', buf[i+6:i+8])[0] + base, num = struct.unpack('IH', buf[i+8:i+14]) + break + i += 16 + if base == 0 and length == 0 and num == 0: + if(fatal): + doError('Neither SMBIOS nor DMI were found') + else: + return out + + # read in the SM or DMI table + fp = open(mempath, 'rb') + try: + fp.seek(base) + buf = fp.read(length) + except: + if(fatal): + doError('DMI table is unreachable, sorry') + else: + return out + fp.close() + + # scan the table for the values we want + count = i = 0 + while(count < num and i <= len(buf) - 4): + type, size, handle = struct.unpack('BBH', buf[i:i+4]) + n = i + size + while n < len(buf) - 1: + if 0 == struct.unpack('H', buf[n:n+2])[0]: + break + n += 1 + data = buf[i+size:n+2].split('\0') + for name in info: + itype, idxadr = info[name] + if itype == type: + idx = struct.unpack('B', buf[i+idxadr])[0] + if idx > 0 and idx < len(data) - 1: + s = data[idx-1].strip() + if s and s.lower() != 'to be filled by o.e.m.': + out[name] = data[idx-1] + i = n + 2 + count += 1 + return out + # Function: getFPDT # Description: # Read the acpi bios tables and pull out FPDT, the firmware data @@ -4487,7 +4690,7 @@ def getFPDT(output): prectype[0] = 'Basic S3 Resume Performance Record' prectype[1] = 'Basic S3 Suspend Performance Record' - rootCheck(True) + sysvals.rootCheck(True) if(not os.path.exists(sysvals.fpdtpath)): if(output): doError('file does not exist: %s' % sysvals.fpdtpath) @@ -4617,7 +4820,7 @@ def statusCheck(probecheck=False): # check we have root access res = sysvals.colorText('NO (No features of this tool will work!)') - if(rootCheck(False)): + if(sysvals.rootCheck(False)): res = 'YES' print(' have root access: %s' % res) if(res != 'YES'): @@ -4716,16 +4919,6 @@ def doError(msg, help=False): print('ERROR: %s\n') % msg sys.exit() -# Function: rootCheck -# Description: -# quick check to see if we have root access -def rootCheck(fatal): - if(os.access(sysvals.powerfile, os.W_OK)): - return True - if fatal: - doError('This command requires sysfs mount and root access') - return False - # Function: getArgInt # Description: # pull out an integer argument from the command line with checks @@ -4779,6 +4972,7 @@ def processData(): if(sysvals.ftracefile and (sysvals.usecallgraph or sysvals.usetraceevents)): appendIncompleteTraceLog(testruns) createHTML(testruns) + return testruns # Function: rerunTest # Description: @@ -4790,17 +4984,20 @@ def rerunTest(): doError('recreating this html output requires a dmesg file') sysvals.setOutputFile() vprint('Output file: %s' % sysvals.htmlfile) - if(os.path.exists(sysvals.htmlfile) and not os.access(sysvals.htmlfile, os.W_OK)): - doError('missing permission to write to %s' % sysvals.htmlfile) - processData() + if os.path.exists(sysvals.htmlfile): + if not os.path.isfile(sysvals.htmlfile): + doError('a directory already exists with this name: %s' % sysvals.htmlfile) + elif not os.access(sysvals.htmlfile, os.W_OK): + doError('missing permission to write to %s' % sysvals.htmlfile) + return processData() # Function: runTest # Description: # execute a suspend/resume, gather the logs, and generate the output -def runTest(subdir, testpath=''): +def runTest(): # prepare for the test sysvals.initFtrace() - sysvals.initTestOutput(subdir, testpath) + sysvals.initTestOutput('suspend') vprint('Output files:\n\t%s\n\t%s\n\t%s' % \ (sysvals.dmesgfile, sysvals.ftracefile, sysvals.htmlfile)) @@ -4897,7 +5094,7 @@ def configFromFile(file): if(opt.lower() == 'verbose'): sysvals.verbose = checkArgBool(value) elif(opt.lower() == 'addlogs'): - sysvals.addlogs = checkArgBool(value) + sysvals.dmesglog = sysvals.ftracelog = checkArgBool(value) elif(opt.lower() == 'dev'): sysvals.usedevsrc = checkArgBool(value) elif(opt.lower() == 'proc'): @@ -4947,7 +5144,7 @@ def configFromFile(file): elif(opt.lower() == 'mincg'): sysvals.mincglen = getArgFloat('-mincg', value, 0.0, 10000.0, False) elif(opt.lower() == 'output-dir'): - sysvals.setOutputFolder(value) + sysvals.testdir = sysvals.setOutputFolder(value) if sysvals.suspendmode == 'command' and not sysvals.testcommand: doError('No command supplied for mode "command"') @@ -5030,8 +5227,6 @@ def configFromFile(file): # Description: # print out the help text def printHelp(): - modes = getModes() - print('') print('%s v%s' % (sysvals.title, sysvals.version)) print('Usage: sudo sleepgraph <options> <commands>') @@ -5048,7 +5243,7 @@ def printHelp(): print(' If no specific command is given, the default behavior is to initiate') print(' a suspend/resume and capture the dmesg/ftrace output as an html timeline.') print('') - print(' Generates output files in subdirectory: suspend-mmddyy-HHMMSS') + print(' Generates output files in subdirectory: suspend-yymmdd-HHMMSS') print(' HTML output: <hostname>_<mode>.html') print(' raw dmesg output: <hostname>_<mode>_dmesg.txt') print(' raw ftrace output: <hostname>_<mode>_ftrace.txt') @@ -5058,8 +5253,9 @@ def printHelp(): print(' -v Print the current tool version') print(' -config fn Pull arguments and config options from file fn') print(' -verbose Print extra information during execution and analysis') - print(' -m mode Mode to initiate for suspend %s (default: %s)') % (modes, sysvals.suspendmode) - print(' -o subdir Override the output subdirectory') + print(' -m mode Mode to initiate for suspend (default: %s)') % (sysvals.suspendmode) + print(' -o name Overrides the output subdirectory name when running a new test') + print(' default: suspend-{date}-{time}') print(' -rtcwake t Wakeup t seconds after suspend, set t to "off" to disable (default: 15)') print(' -addlogs Add the dmesg and ftrace logs to the html output') print(' -srgap Add a visible gap in the timeline between sus/res (default: disabled)') @@ -5084,17 +5280,20 @@ def printHelp(): print(' -cgphase P Only show callgraph data for phase P (e.g. suspend_late)') print(' -cgtest N Only show callgraph data for test N (e.g. 0 or 1 in an x2 run)') print(' -timeprec N Number of significant digits in timestamps (0:S, [3:ms], 6:us)') - print(' [commands]') - print(' -ftrace ftracefile Create HTML output using ftrace input (used with -dmesg)') - print(' -dmesg dmesgfile Create HTML output using dmesg (used with -ftrace)') - print(' -summary directory Create a summary of all test in this dir') + print('') + print('Other commands:') print(' -modes List available suspend modes') print(' -status Test to see if the system is enabled to run this tool') print(' -fpdt Print out the contents of the ACPI Firmware Performance Data Table') + print(' -sysinfo Print out system info extracted from BIOS') print(' -usbtopo Print out the current USB topology with power info') print(' -usbauto Enable autosuspend for all connected USB devices') print(' -flist Print the list of functions currently being captured in ftrace') print(' -flistall Print all functions capable of being captured in ftrace') + print(' -summary directory Create a summary of all test in this dir') + print(' [redo]') + print(' -ftrace ftracefile Create HTML output using ftrace input (used with -dmesg)') + print(' -dmesg dmesgfile Create HTML output using dmesg (used with -ftrace)') print('') return True @@ -5102,9 +5301,9 @@ def printHelp(): # exec start (skipped if script is loaded as library) if __name__ == '__main__': cmd = '' - cmdarg = '' + outdir = '' multitest = {'run': False, 'count': 0, 'delay': 0} - simplecmds = ['-modes', '-fpdt', '-flist', '-flistall', '-usbtopo', '-usbauto', '-status'] + simplecmds = ['-sysinfo', '-modes', '-fpdt', '-flist', '-flistall', '-usbtopo', '-usbauto', '-status'] # loop through the command line arguments args = iter(sys.argv[1:]) for arg in args: @@ -5135,7 +5334,7 @@ if __name__ == '__main__': elif(arg == '-f'): sysvals.usecallgraph = True elif(arg == '-addlogs'): - sysvals.addlogs = True + sysvals.dmesglog = sysvals.ftracelog = True elif(arg == '-verbose'): sysvals.verbose = True elif(arg == '-proc'): @@ -5195,7 +5394,7 @@ if __name__ == '__main__': val = args.next() except: doError('No subdirectory name supplied', True) - sysvals.setOutputFolder(val) + outdir = sysvals.setOutputFolder(val) elif(arg == '-config'): try: val = args.next() @@ -5236,7 +5435,7 @@ if __name__ == '__main__': except: doError('No directory supplied', True) cmd = 'summary' - cmdarg = val + outdir = val sysvals.notestrun = True if(os.path.isdir(val) == False): doError('%s is not accesible' % val) @@ -5260,11 +5459,14 @@ if __name__ == '__main__': sysvals.mincglen = sysvals.mindevlen # just run a utility command and exit + sysvals.cpuInfo() if(cmd != ''): if(cmd == 'status'): statusCheck(True) elif(cmd == 'fpdt'): getFPDT(True) + elif(cmd == 'sysinfo'): + sysvals.printSystemInfo() elif(cmd == 'usbtopo'): detectUSB() elif(cmd == 'modes'): @@ -5276,7 +5478,7 @@ if __name__ == '__main__': elif(cmd == 'usbauto'): setUSBDevicesAuto() elif(cmd == 'summary'): - runSummary(cmdarg, True) + runSummary(outdir, True) sys.exit() # if instructed, re-analyze existing data files @@ -5289,21 +5491,43 @@ if __name__ == '__main__': print('Check FAILED, aborting the test run!') sys.exit() + # extract mem modes and convert + mode = sysvals.suspendmode + if 'mem' == mode[:3]: + if '-' in mode: + memmode = mode.split('-')[-1] + else: + memmode = 'deep' + if memmode == 'shallow': + mode = 'standby' + elif memmode == 's2idle': + mode = 'freeze' + else: + mode = 'mem' + sysvals.memmode = memmode + sysvals.suspendmode = mode + + sysvals.systemInfo(dmidecode(sysvals.mempath)) + if multitest['run']: # run multiple tests in a separate subdirectory - s = 'x%d' % multitest['count'] - if not sysvals.outdir: - sysvals.outdir = datetime.now().strftime('suspend-'+s+'-%m%d%y-%H%M%S') - if not os.path.isdir(sysvals.outdir): - os.mkdir(sysvals.outdir) + if not outdir: + s = 'suspend-x%d' % multitest['count'] + outdir = datetime.now().strftime(s+'-%y%m%d-%H%M%S') + if not os.path.isdir(outdir): + os.mkdir(outdir) for i in range(multitest['count']): if(i != 0): print('Waiting %d seconds...' % (multitest['delay'])) time.sleep(multitest['delay']) print('TEST (%d/%d) START' % (i+1, multitest['count'])) - runTest(sysvals.outdir) + fmt = 'suspend-%y%m%d-%H%M%S' + sysvals.testdir = os.path.join(outdir, datetime.now().strftime(fmt)) + runTest() print('TEST (%d/%d) COMPLETE' % (i+1, multitest['count'])) - runSummary(sysvals.outdir, False) + runSummary(outdir, False) else: + if outdir: + sysvals.testdir = outdir # run the test in the current directory - runTest('.', sysvals.outdir) + runTest() diff --git a/tools/power/pm-graph/bootgraph.8 b/tools/power/pm-graph/bootgraph.8 index 55272a67b0e7..dbdafcf546df 100644 --- a/tools/power/pm-graph/bootgraph.8 +++ b/tools/power/pm-graph/bootgraph.8 @@ -8,14 +8,23 @@ bootgraph \- Kernel boot timing analysis .RB [ COMMAND ] .SH DESCRIPTION \fBbootgraph \fP reads the dmesg log from kernel boot and -creates an html representation of the initcall timeline up to the start -of the init process. +creates an html representation of the initcall timeline. It graphs +every module init call found, through both kernel and user modes. The +timeline is split into two phases: kernel mode & user mode. kernel mode +represents a single process run on a single cpu with serial init calls. +Once user mode begins, the init process is called, and the init calls +start working in parallel. .PP If no specific command is given, the tool reads the current dmesg log and -outputs bootgraph.html. +outputs a new timeline. .PP The tool can also augment the timeline with ftrace data on custom target functions as well as full trace callgraphs. +.PP +Generates output files in subdirectory: boot-yymmdd-HHMMSS + html timeline : <hostname>_boot.html + raw dmesg file : <hostname>_boot_dmesg.txt + raw ftrace file : <hostname>_boot_ftrace.txt .SH OPTIONS .TP \fB-h\fR @@ -28,15 +37,18 @@ Print the current tool version Add the dmesg log to the html output. It will be viewable by clicking a button in the timeline. .TP -\fB-o \fIfile\fR -Override the HTML output filename (default: bootgraph.html) -.SS "Ftrace Debug" +\fB-o \fIname\fR +Overrides the output subdirectory name when running a new test. +Use {date}, {time}, {hostname} for current values. +.sp +e.g. boot-{hostname}-{date}-{time} +.SS "advanced" .TP \fB-f\fR Use ftrace to add function detail (default: disabled) .TP \fB-callgraph\fR -Use ftrace to create initcall callgraphs (default: disabled). If -filter +Use ftrace to create initcall callgraphs (default: disabled). If -func is not used there will be one callgraph per initcall. This can produce very large outputs, i.e. 10MB - 100MB. .TP @@ -50,16 +62,19 @@ This reduces the html file size as there can be many tiny callgraphs 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. +(default: none) +.TP \fB-timeprec \fIn\fR Number of significant digits in timestamps (0:S, 3:ms, [6:us]) .TP \fB-expandcg\fR pre-expand the callgraph data in the html output (default: disabled) .TP -\fB-filter \fI"func1,func2,..."\fR +\fB-func \fI"func1,func2,..."\fR Instead of tracing each initcall, trace a custom list of functions (default: do_one_initcall) - -.SH COMMANDS .TP \fB-reboot\fR Reboot the machine and generate a new timeline automatically. Works in 4 steps. @@ -73,16 +88,23 @@ Show the requirements to generate a new timeline manually. Requires 3 steps. 1. append the string to the kernel command line via your native boot manager. 2. reboot the system 3. after startup, re-run the tool with the same arguments and no command + +.SH COMMANDS +.SS "rebuild" .TP \fB-dmesg \fIfile\fR Create HTML output from an existing dmesg file. .TP \fB-ftrace \fIfile\fR Create HTML output from an existing ftrace file (used with -dmesg). +.SS "other" .TP \fB-flistall\fR Print all ftrace functions capable of being captured. These are all the -possible values you can add to trace via the -filter argument. +possible values you can add to trace via the -func argument. +.TP +\fB-sysinfo\fR +Print out system info extracted from BIOS. Reads /dev/mem directly instead of going through dmidecode. .SH EXAMPLES Create a timeline using the current dmesg log. @@ -93,13 +115,13 @@ Create a timeline using the current dmesg and ftrace log. .IP \f(CW$ bootgraph -callgraph\fR .PP -Create a timeline using the current dmesg, add the log to the html and change the name. +Create a timeline using the current dmesg, add the log to the html and change the folder. .IP -\f(CW$ bootgraph -addlogs -o myboot.html\fR +\f(CW$ bootgraph -addlogs -o "myboot-{date}-{time}"\fR .PP Capture a new boot timeline by automatically rebooting the machine. .IP -\f(CW$ sudo bootgraph -reboot -addlogs -o latestboot.html\fR +\f(CW$ sudo bootgraph -reboot -addlogs -o "latest-{hostname)"\fR .PP Capture a new boot timeline with function trace data. .IP @@ -111,7 +133,7 @@ Capture a new boot timeline with trace & callgraph data. Skip callgraphs smaller .PP Capture a new boot timeline with callgraph data over custom functions. .IP -\f(CW$ sudo bootgraph -reboot -callgraph -filter "acpi_ps_parse_aml,msleep"\fR +\f(CW$ sudo bootgraph -reboot -callgraph -func "acpi_ps_parse_aml,msleep"\fR .PP Capture a brand new boot timeline with manual reboot. .IP @@ -123,6 +145,15 @@ Capture a brand new boot timeline with manual reboot. .IP \f(CW$ sudo bootgraph -callgraph # re-run the tool after restart\fR .PP +.SS "rebuild timeline from logs" +.PP +Rebuild the html from a previous run's logs, using the same options. +.IP +\f(CW$ bootgraph -dmesg dmesg.txt -ftrace ftrace.txt -callgraph\fR +.PP +Rebuild the html with different options. +.IP +\f(CW$ bootgraph -dmesg dmesg.txt -ftrace ftrace.txt -addlogs\fR .SH "SEE ALSO" dmesg(1), update-grub(8), crontab(1), reboot(8) diff --git a/tools/power/pm-graph/sleepgraph.8 b/tools/power/pm-graph/sleepgraph.8 index 610e72ebbc06..fbe7bd3eae8e 100644 --- a/tools/power/pm-graph/sleepgraph.8 +++ b/tools/power/pm-graph/sleepgraph.8 @@ -39,8 +39,9 @@ Pull arguments and config options from a file. \fB-m \fImode\fR Mode to initiate for suspend e.g. standby, freeze, mem (default: mem). .TP -\fB-o \fIsubdir\fR -Override the output subdirectory. Use {date}, {time}, {hostname} for current values. +\fB-o \fIname\fR +Overrides the output subdirectory name when running a new test. +Use {date}, {time}, {hostname} for current values. .sp e.g. suspend-{hostname}-{date}-{time} .TP @@ -52,7 +53,7 @@ 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. -.SS "Advanced" +.SS "advanced" .TP \fB-cmd \fIstr\fR Run the timeline over a custom suspend command, e.g. pm-suspend. By default @@ -91,7 +92,7 @@ Include \fIt\fR ms delay after last resume (default: 0 ms). Execute \fIn\fR consecutive tests at \fId\fR seconds intervals. The outputs will be created in a new subdirectory with a summary page: suspend-xN-{date}-{time}. -.SS "Ftrace Debug" +.SS "ftrace debug" .TP \fB-f\fR Use ftrace to create device callgraphs (default: disabled). This can produce @@ -124,12 +125,6 @@ Number of significant digits in timestamps (0:S, [3:ms], 6:us). .SH COMMANDS .TP -\fB-ftrace \fIfile\fR -Create HTML output from an existing ftrace file. -.TP -\fB-dmesg \fIfile\fR -Create HTML output from an existing dmesg file. -.TP \fB-summary \fIindir\fR Create a summary page of all tests in \fIindir\fR. Creates summary.html in the current folder. The output page is a table of tests with @@ -146,6 +141,9 @@ with any options you intend to use to see if they will work. \fB-fpdt\fR Print out the contents of the ACPI Firmware Performance Data Table. .TP +\fB-sysinfo\fR +Print out system info extracted from BIOS. Reads /dev/mem directly instead of going through dmidecode. +.TP \fB-usbtopo\fR Print out the current USB topology with power info. .TP @@ -162,9 +160,16 @@ with -fadd they will also be checked. \fB-flistall\fR Print all ftrace functions capable of being captured. These are all the possible values you can add to trace via the -fadd argument. +.SS "rebuild" +.TP +\fB-ftrace \fIfile\fR +Create HTML output from an existing ftrace file. +.TP +\fB-dmesg \fIfile\fR +Create HTML output from an existing dmesg file. .SH EXAMPLES -.SS "Simple Commands" +.SS "simple commands" Check which suspend modes are currently supported. .IP \f(CW$ sleepgraph -modes\fR @@ -185,12 +190,8 @@ Generate a summary of all timelines in a particular folder. .IP \f(CW$ sleepgraph -summary ~/workspace/myresults/\fR .PP -Re-generate the html output from a previous run's dmesg and ftrace log. -.IP -\f(CW$ sleepgraph -dmesg myhost_mem_dmesg.txt -ftrace myhost_mem_ftrace.txt\fR -.PP -.SS "Capturing Simple Timelines" +.SS "capturing basic timelines" Execute a mem suspend with a 15 second wakeup. Include the logs in the html. .IP \f(CW$ sudo sleepgraph -rtcwake 15 -addlogs\fR @@ -204,7 +205,7 @@ Execute a freeze with no wakeup (require keypress). Change output folder name. \f(CW$ sudo sleepgraph -m freeze -rtcwake off -o "freeze-{hostname}-{date}-{time}"\fR .PP -.SS "Capturing Advanced Timelines" +.SS "capturing advanced timelines" Execute a suspend & include dev mode source calls, limit callbacks to 5ms or larger. .IP \f(CW$ sudo sleepgraph -m mem -rtcwake 15 -dev -mindev 5\fR @@ -222,8 +223,7 @@ Execute a suspend using a custom command. \f(CW$ sudo sleepgraph -cmd "echo mem > /sys/power/state" -rtcwake 15\fR .PP - -.SS "Capturing Timelines with Callgraph Data" +.SS "adding callgraph data" Add device callgraphs. Limit the trace depth and only show callgraphs 10ms or larger. .IP \f(CW$ sudo sleepgraph -m mem -rtcwake 15 -f -maxdepth 5 -mincg 10\fR @@ -235,6 +235,16 @@ Capture a full callgraph across all suspend, then filter the html by a single ph \f(CW$ sleepgraph -dmesg host_mem_dmesg.txt -ftrace host_mem_ftrace.txt -f -cgphase resume .PP +.SS "rebuild timeline from logs" +.PP +Rebuild the html from a previous run's logs, using the same options. +.IP +\f(CW$ sleepgraph -dmesg dmesg.txt -ftrace ftrace.txt -callgraph\fR +.PP +Rebuild the html with different options. +.IP +\f(CW$ sleepgraph -dmesg dmesg.txt -ftrace ftrace.txt -addlogs -srgap\fR + .SH "SEE ALSO" dmesg(1) .PP |