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 #include #include +#include #include #include #include @@ -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.*)\+.*', msg) + m = re.match('^calling *(?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.*)\+.* returned (?P.*) after (?P.*) 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.tUserMode = ktime + data.dmesg['kernel']['end'] = ktime + data.dmesg['user']['start'] = ktime + phase = 'user' - data.dmesg['boot']['end'] = data.end + 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 = '

{0}
\n' html_timetotal = '\n'\ - ''\ + ''\ + ''\ '\n
Time from Kernel Boot to start of User Mode: {0} msInit process starts @ {0} msLast initcall ends @ {1} ms
\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 - 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) + 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 - 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 += '\n' # timeline is finished devtl.html += '\n\n' + # draw a legend which describes the phases by color + devtl.html += '
\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 += '
\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 = \ '
\n'\ '\n'\ + '
\n' + for p in data.phases: + phase = data.dmesg[p] + html += devtl.html_phaselet.format(p+'_mode', '0', '100', phase['color']) + html += '
\n\n'\ '\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('\n') - if(not embedded): + if(not sysvals.embedded): # write the footer and close aslib.addScriptCode(hf, [data]) hf.write('\n\n') else: # embedded out will be loaded in a page, skip the js hf.write('' % \ - (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 ') 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: _boot.html') + print(' raw dmesg output: _boot_dmesg.txt') + print(' raw ftrace output: _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)) - createBootGraph(data, sysvals.phoronix) + # 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) + + # 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.*)' firmwarefmt = '# fwsuspend (?P[0-9]*) fwresume (?P[0-9]*)$' - stampfmt = '# suspend-(?P[0-9]{2})(?P[0-9]{2})(?P[0-9]{2})-'+\ - '(?P[0-9]{2})(?P[0-9]{2})(?P[0-9]{2})'+\ - ' (?P.*) (?P.*) (?P.*)$' 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.*)_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.*)_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[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 = '
{6}
\n' html_phase = '
{5}
\n' html_phaselet = '
\n' + html_legend = '
 {2}
\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 += '
%s v%s
' \ % (sv.title, sv.version) - if sv.logmsg and 'log' not in suppress: - self.html += '' - if sv.addlogs and 'dmesg' not in suppress: - self.html += '' - if sv.addlogs and sv.ftracefile and 'ftrace' not in suppress: - self.html += '' + if sv.logmsg and sv.testlog: + self.html += '' + if sv.dmesglog: + self.html += '' + if sv.ftracelog: + self.html += '' headline_stamp = '
{0} {1} {2} {3}
\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 = '
{0} {1} with {2}
\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[0-9]{2})(?P[0-9]{2})(?P[0-9]{2})-'+\ + '(?P[0-9]{2})(?P[0-9]{2})(?P[0-9]{2})'+\ + ' (?P.*) (?P.*) (?P.*)$' + sysinfofmt = '^# sysinfo .*' ftrace_line_fmt_fg = \ '^ *(?P