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
This commit is contained in:
Rafael J. Wysocki 2017-09-04 00:07:36 +02:00
commit d97561f461
13 changed files with 879 additions and 412 deletions

View File

@ -12,6 +12,7 @@
#include <string.h> #include <string.h>
#include <unistd.h> #include <unistd.h>
#include <errno.h> #include <errno.h>
#include <sched.h>
#include <sys/types.h> #include <sys/types.h>
#include <sys/stat.h> #include <sys/stat.h>
#include <sys/utsname.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; struct cpupower_cpu_info cpupower_cpu_info;
int run_as_root; int run_as_root;
int base_cpu;
/* Affected cpus chosen by -c/--cpu param */ /* Affected cpus chosen by -c/--cpu param */
struct bitmask *cpus_chosen; struct bitmask *cpus_chosen;
@ -174,6 +176,7 @@ int main(int argc, const char *argv[])
unsigned int i, ret; unsigned int i, ret;
struct stat statbuf; struct stat statbuf;
struct utsname uts; struct utsname uts;
char pathname[32];
cpus_chosen = bitmask_alloc(sysconf(_SC_NPROCESSORS_CONF)); cpus_chosen = bitmask_alloc(sysconf(_SC_NPROCESSORS_CONF));
@ -198,17 +201,23 @@ int main(int argc, const char *argv[])
argv[0] = cmd = "help"; 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(); run_as_root = !geteuid();
if (run_as_root) { if (run_as_root) {
ret = uname(&uts); ret = uname(&uts);
sprintf(pathname, "/dev/cpu/%d/msr", base_cpu);
if (!ret && !strcmp(uts.machine, "x86_64") && if (!ret && !strcmp(uts.machine, "x86_64") &&
stat("/dev/cpu/0/msr", &statbuf) != 0) { stat(pathname, &statbuf) != 0) {
if (system("modprobe msr") == -1) if (system("modprobe msr") == -1)
fprintf(stderr, _("MSR access not available.\n")); fprintf(stderr, _("MSR access not available.\n"));
} }
} }
for (i = 0; i < ARRAY_SIZE(commands); i++) { for (i = 0; i < ARRAY_SIZE(commands); i++) {
struct cmd_struct *p = commands + i; struct cmd_struct *p = commands + i;

View File

@ -42,7 +42,7 @@ cpuid_func(edx);
* *
* TBD: Should there be a cpuid alternative for this if /proc is not mounted? * 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; FILE *fp;
char value[64]; 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)) if (!strncmp(value, "processor\t: ", 12))
sscanf(value, "processor\t: %u", &proc); sscanf(value, "processor\t: %u", &proc);
if (proc != cpu) if (proc != (unsigned int)base_cpu)
continue; continue;
/* Get CPU vendor */ /* Get CPU vendor */

View File

@ -34,6 +34,7 @@
/* Internationalization ****************************/ /* Internationalization ****************************/
extern int run_as_root; extern int run_as_root;
extern int base_cpu;
extern struct bitmask *cpus_chosen; extern struct bitmask *cpus_chosen;
/* Global verbose (-d) stuff *********************************/ /* Global verbose (-d) stuff *********************************/
@ -87,11 +88,11 @@ struct cpupower_cpu_info {
* *
* Extract CPU vendor, family, model, stepping info from /proc/cpuinfo * 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 * Only used on x86, below global's struct values are zero/unknown on
* other archs * 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; extern struct cpupower_cpu_info cpupower_cpu_info;
/* cpuid and cpuinfo helpers **************************/ /* cpuid and cpuinfo helpers **************************/

View File

@ -13,7 +13,7 @@ int cpufreq_has_boost_support(unsigned int cpu, int *support, int *active,
*support = *active = *states = 0; *support = *active = *states = 0;
ret = get_cpu_info(0, &cpu_info); ret = get_cpu_info(&cpu_info);
if (ret) if (ret)
return ret; return ret;

View File

@ -123,7 +123,7 @@ static int hsw_ext_start(void)
previous_count[num][cpu] = val; 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; return 0;
} }
@ -132,7 +132,7 @@ static int hsw_ext_stop(void)
unsigned long long val; unsigned long long val;
int num, cpu; 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 (num = 0; num < HSW_EXT_CSTATE_COUNT; num++) {
for (cpu = 0; cpu < cpu_count; cpu++) { for (cpu = 0; cpu < cpu_count; cpu++) {

View File

@ -80,7 +80,8 @@ static int *is_valid;
static int mperf_get_tsc(unsigned long long *tsc) static int mperf_get_tsc(unsigned long long *tsc)
{ {
int ret; int ret;
ret = read_msr(0, MSR_TSC, tsc);
ret = read_msr(base_cpu, MSR_TSC, tsc);
if (ret) if (ret)
dprint("Reading TSC MSR failed, returning %llu\n", *tsc); dprint("Reading TSC MSR failed, returning %llu\n", *tsc);
return ret; return ret;

View File

@ -129,7 +129,7 @@ static int nhm_start(void)
int num, cpu; int num, cpu;
unsigned long long dbg, val; 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 (num = 0; num < NHM_CSTATE_COUNT; num++) {
for (cpu = 0; cpu < cpu_count; cpu++) { for (cpu = 0; cpu < cpu_count; cpu++) {
@ -137,7 +137,7 @@ static int nhm_start(void)
previous_count[num][cpu] = val; 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); dprint("TSC diff: %llu\n", dbg - tsc_at_measure_start);
return 0; return 0;
} }
@ -148,7 +148,7 @@ static int nhm_stop(void)
unsigned long long dbg; unsigned long long dbg;
int num, cpu; 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 (num = 0; num < NHM_CSTATE_COUNT; num++) {
for (cpu = 0; cpu < cpu_count; cpu++) { for (cpu = 0; cpu < cpu_count; cpu++) {
@ -156,7 +156,7 @@ static int nhm_stop(void)
current_count[num][cpu] = val; 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); dprint("TSC diff: %llu\n", dbg - tsc_at_measure_end);
return 0; return 0;

View File

@ -120,7 +120,7 @@ static int snb_start(void)
previous_count[num][cpu] = val; 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; return 0;
} }
@ -129,7 +129,7 @@ static int snb_stop(void)
unsigned long long val; unsigned long long val;
int num, cpu; 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 (num = 0; num < SNB_CSTATE_COUNT; num++) {
for (cpu = 0; cpu < cpu_count; cpu++) { for (cpu = 0; cpu < cpu_count; cpu++) {

View File

@ -4,7 +4,7 @@ DESTDIR ?=
all: all:
@echo "Nothing to build" @echo "Nothing to build"
install : install : uninstall
install -d $(DESTDIR)$(PREFIX)/lib/pm-graph install -d $(DESTDIR)$(PREFIX)/lib/pm-graph
install analyze_suspend.py $(DESTDIR)$(PREFIX)/lib/pm-graph install analyze_suspend.py $(DESTDIR)$(PREFIX)/lib/pm-graph
install analyze_boot.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 install sleepgraph.8 $(DESTDIR)$(PREFIX)/share/man/man8
uninstall : uninstall :
rm $(DESTDIR)$(PREFIX)/share/man/man8/bootgraph.8 rm -f $(DESTDIR)$(PREFIX)/share/man/man8/bootgraph.8
rm $(DESTDIR)$(PREFIX)/share/man/man8/sleepgraph.8 rm -f $(DESTDIR)$(PREFIX)/share/man/man8/sleepgraph.8
rm $(DESTDIR)$(PREFIX)/bin/bootgraph rm -f $(DESTDIR)$(PREFIX)/bin/bootgraph
rm $(DESTDIR)$(PREFIX)/bin/sleepgraph rm -f $(DESTDIR)$(PREFIX)/bin/sleepgraph
rm $(DESTDIR)$(PREFIX)/lib/pm-graph/analyze_boot.py rm -f $(DESTDIR)$(PREFIX)/lib/pm-graph/analyze_boot.py
rm $(DESTDIR)$(PREFIX)/lib/pm-graph/analyze_suspend.py rm -f $(DESTDIR)$(PREFIX)/lib/pm-graph/analyze_suspend.py
rmdir $(DESTDIR)$(PREFIX)/lib/pm-graph rm -f $(DESTDIR)$(PREFIX)/lib/pm-graph/*.pyc
if [ -d $(DESTDIR)$(PREFIX)/lib/pm-graph ] ; then \
rmdir $(DESTDIR)$(PREFIX)/lib/pm-graph; \
fi;

View File

@ -42,7 +42,7 @@ import analyze_suspend as aslib
# store system values and test parameters # store system values and test parameters
class SystemValues(aslib.SystemValues): class SystemValues(aslib.SystemValues):
title = 'BootGraph' title = 'BootGraph'
version = 2.0 version = '2.1'
hostname = 'localhost' hostname = 'localhost'
testtime = '' testtime = ''
kernel = '' kernel = ''
@ -50,9 +50,14 @@ class SystemValues(aslib.SystemValues):
ftracefile = '' ftracefile = ''
htmlfile = 'bootgraph.html' htmlfile = 'bootgraph.html'
outfile = '' outfile = ''
phoronix = False testdir = ''
addlogs = False testdirprefix = 'boot'
embedded = False
testlog = False
dmesglog = False
ftracelog = False
useftrace = False useftrace = False
usecallgraph = False
usedevsrc = True usedevsrc = True
suspendmode = 'boot' suspendmode = 'boot'
max_graph_depth = 2 max_graph_depth = 2
@ -61,10 +66,12 @@ class SystemValues(aslib.SystemValues):
manual = False manual = False
iscronjob = False iscronjob = False
timeformat = '%.6f' timeformat = '%.6f'
bootloader = 'grub'
blexec = []
def __init__(self): def __init__(self):
if('LOG_FILE' in os.environ and 'TEST_RESULTS_IDENTIFIER' in os.environ): if('LOG_FILE' in os.environ and 'TEST_RESULTS_IDENTIFIER' in os.environ):
self.phoronix = True self.embedded = True
self.addlogs = True self.dmesglog = True
self.outfile = os.environ['LOG_FILE'] self.outfile = os.environ['LOG_FILE']
self.htmlfile = os.environ['LOG_FILE'] self.htmlfile = os.environ['LOG_FILE']
self.hostname = platform.node() self.hostname = platform.node()
@ -76,42 +83,80 @@ class SystemValues(aslib.SystemValues):
self.kernel = self.kernelVersion(val) self.kernel = self.kernelVersion(val)
else: else:
self.kernel = 'unknown' self.kernel = 'unknown'
self.testdir = datetime.now().strftime('boot-%y%m%d-%H%M%S')
def kernelVersion(self, msg): def kernelVersion(self, msg):
return msg.split()[2] 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): def kernelParams(self):
cmdline = 'initcall_debug log_buf_len=32M' cmdline = 'initcall_debug log_buf_len=32M'
if self.useftrace: 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,'\ 'trace_options=nooverwrite,funcgraph-abstime,funcgraph-cpu,'\
'funcgraph-duration,funcgraph-proc,funcgraph-tail,'\ 'funcgraph-duration,funcgraph-proc,funcgraph-tail,'\
'nofuncgraph-overhead,context-info,graph-time '\ 'nofuncgraph-overhead,context-info,graph-time '\
'ftrace=function_graph '\ 'ftrace=function_graph '\
'ftrace_graph_max_depth=%d '\ 'ftrace_graph_max_depth=%d '\
'ftrace_graph_filter=%s' % \ 'ftrace_graph_filter=%s' % \
(self.max_graph_depth, self.graph_filter) (bs, self.max_graph_depth, self.graph_filter)
return cmdline return cmdline
def setGraphFilter(self, val): def setGraphFilter(self, val):
fp = open(self.tpath+'available_filter_functions') master = self.getBootFtraceFilterFunctions()
master = fp.read().split('\n') fs = ''
fp.close()
for i in val.split(','): for i in val.split(','):
func = i.strip() 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: if func not in master:
doError('function "%s" not available for ftrace' % func) 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): def cronjobCmdString(self):
cmdline = '%s -cronjob' % os.path.abspath(sys.argv[0]) cmdline = '%s -cronjob' % os.path.abspath(sys.argv[0])
args = iter(sys.argv[1:]) args = iter(sys.argv[1:])
for arg in args: for arg in args:
if arg in ['-h', '-v', '-cronjob', '-reboot']: if arg in ['-h', '-v', '-cronjob', '-reboot']:
continue continue
elif arg in ['-o', '-dmesg', '-ftrace', '-filter']: elif arg in ['-o', '-dmesg', '-ftrace', '-func']:
args.next() args.next()
continue continue
cmdline += ' '+arg cmdline += ' '+arg
if self.graph_filter != 'do_one_initcall': if self.graph_filter != 'do_one_initcall':
cmdline += ' -filter "%s"' % self.graph_filter cmdline += ' -func "%s"' % self.graph_filter
cmdline += ' -o "%s"' % os.path.abspath(self.htmlfile) cmdline += ' -o "%s"' % os.path.abspath(self.testdir)
return cmdline return cmdline
def manualRebootRequired(self): def manualRebootRequired(self):
cmdline = self.kernelParams() 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 '3. After reboot, re-run this tool with the same arguments but no command (w/o -reboot or -manual).\n'
print 'CMDLINE="%s"' % cmdline print 'CMDLINE="%s"' % cmdline
sys.exit() 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() sysvals = SystemValues()
@ -136,20 +214,23 @@ class Data(aslib.Data):
idstr = '' idstr = ''
html_device_id = 0 html_device_id = 0
valid = False valid = False
initstart = 0.0 tUserMode = 0.0
boottime = '' boottime = ''
phases = ['boot'] phases = ['kernel', 'user']
do_one_initcall = False do_one_initcall = False
def __init__(self, num): def __init__(self, num):
self.testnumber = num self.testnumber = num
self.idstr = 'a' self.idstr = 'a'
self.dmesgtext = [] self.dmesgtext = []
self.dmesg = { 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): def deviceTopology(self):
return '' 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 # new device callback for a specific phase
self.html_device_id += 1 self.html_device_id += 1
devid = '%s%d' % (self.idstr, self.html_device_id) devid = '%s%d' % (self.idstr, self.html_device_id)
@ -163,41 +244,46 @@ class Data(aslib.Data):
name = '%s[%d]' % (origname, i) name = '%s[%d]' % (origname, i)
i += 1 i += 1
list[name] = {'name': name, 'start': start, 'end': end, 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 } 'ret': ret, 'ulen': ulen }
return name return name
def deviceMatch(self, cg): def deviceMatch(self, pid, cg):
if cg.end - cg.start == 0: if cg.end - cg.start == 0:
return True return True
list = self.dmesg['boot']['list'] for p in data.phases:
for devname in list: list = self.dmesg[p]['list']
dev = list[devname] for devname in list:
if cg.name == 'do_one_initcall': dev = list[devname]
if(cg.start <= dev['start'] and cg.end >= dev['end'] and dev['length'] > 0): if pid != dev['pid']:
dev['ftrace'] = cg continue
self.do_one_initcall = True if cg.name == 'do_one_initcall':
return True if(cg.start <= dev['start'] and cg.end >= dev['end'] and dev['length'] > 0):
else: dev['ftrace'] = cg
if(cg.start > dev['start'] and cg.end < dev['end']): self.do_one_initcall = True
if 'ftraces' not in dev: return True
dev['ftraces'] = [] else:
dev['ftraces'].append(cg) if(cg.start > dev['start'] and cg.end < dev['end']):
return True if 'ftraces' not in dev:
dev['ftraces'] = []
dev['ftraces'].append(cg)
return True
return False return False
# ----------------- FUNCTIONS -------------------- # ----------------- FUNCTIONS --------------------
# Function: loadKernelLog # Function: parseKernelLog
# Description: # Description:
# Load a raw kernel log from dmesg # parse a kernel log for boot data
def loadKernelLog(): def parseKernelLog():
phase = 'kernel'
data = Data(0) data = Data(0)
data.dmesg['boot']['start'] = data.start = ktime = 0.0 data.dmesg['kernel']['start'] = data.start = ktime = 0.0
sysvals.stamp = { sysvals.stamp = {
'time': datetime.now().strftime('%B %d %Y, %I:%M:%S %p'), 'time': datetime.now().strftime('%B %d %Y, %I:%M:%S %p'),
'host': sysvals.hostname, 'host': sysvals.hostname,
'mode': 'boot', 'kernel': ''} 'mode': 'boot', 'kernel': ''}
tp = aslib.TestProps()
devtemp = dict() devtemp = dict()
if(sysvals.dmesgfile): if(sysvals.dmesgfile):
lf = open(sysvals.dmesgfile, 'r') lf = open(sysvals.dmesgfile, 'r')
@ -205,6 +291,13 @@ def loadKernelLog():
lf = Popen('dmesg', stdout=PIPE).stdout lf = Popen('dmesg', stdout=PIPE).stdout
for line in lf: for line in lf:
line = line.replace('\r\n', '') 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('[') idx = line.find('[')
if idx > 1: if idx > 1:
line = line[idx:] line = line[idx:]
@ -215,7 +308,6 @@ def loadKernelLog():
if(ktime > 120): if(ktime > 120):
break break
msg = m.group('msg') msg = m.group('msg')
data.end = data.initstart = ktime
data.dmesgtext.append(line) data.dmesgtext.append(line)
if(ktime == 0.0 and re.match('^Linux version .*', msg)): if(ktime == 0.0 and re.match('^Linux version .*', msg)):
if(not sysvals.stamp['kernel']): if(not sysvals.stamp['kernel']):
@ -228,43 +320,39 @@ def loadKernelLog():
data.boottime = bt.strftime('%Y-%m-%d_%H:%M:%S') data.boottime = bt.strftime('%Y-%m-%d_%H:%M:%S')
sysvals.stamp['time'] = bt.strftime('%B %d %Y, %I:%M:%S %p') sysvals.stamp['time'] = bt.strftime('%B %d %Y, %I:%M:%S %p')
continue continue
m = re.match('^calling *(?P<f>.*)\+.*', msg) m = re.match('^calling *(?P<f>.*)\+.* @ (?P<p>[0-9]*)', msg)
if(m): if(m):
devtemp[m.group('f')] = ktime func = m.group('f')
pid = int(m.group('p'))
devtemp[func] = (ktime, pid)
continue continue
m = re.match('^initcall *(?P<f>.*)\+.* returned (?P<r>.*) after (?P<t>.*) usecs', msg) m = re.match('^initcall *(?P<f>.*)\+.* returned (?P<r>.*) after (?P<t>.*) usecs', msg)
if(m): if(m):
data.valid = True data.valid = True
data.end = ktime
f, r, t = m.group('f', 'r', 't') f, r, t = m.group('f', 'r', 't')
if(f in devtemp): if(f in devtemp):
data.newAction('boot', f, devtemp[f], ktime, int(r), int(t)) start, pid = devtemp[f]
data.end = ktime data.newAction(phase, f, pid, start, ktime, int(r), int(t))
del devtemp[f] del devtemp[f]
continue continue
if(re.match('^Freeing unused kernel memory.*', msg)): 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() lf.close()
return data return data
# Function: loadTraceLog # Function: parseTraceLog
# Description: # Description:
# Check if trace is available and copy to a temp file # Check if trace is available and copy to a temp file
def loadTraceLog(data): def parseTraceLog(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')
# parse the trace log # parse the trace log
ftemp = dict() ftemp = dict()
tp = aslib.TestProps() tp = aslib.TestProps()
@ -306,9 +394,29 @@ def loadTraceLog(data):
print('Sanity check failed for %s-%d' % (proc, pid)) print('Sanity check failed for %s-%d' % (proc, pid))
continue continue
# match cg data to devices # 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) 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 # Function: colorForName
# Description: # Description:
# Generate a repeatable color from a list for a given name # 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 # testruns: array of Data objects from parseKernelLog or parseTraceLog
# Output: # Output:
# True if the html file was created, false if it failed # True if the html file was created, false if it failed
def createBootGraph(data, embedded): def createBootGraph(data):
# html function templates # 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_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>'\ 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' '</tr>\n</table>\n'
# device timeline # device timeline
devtl = aslib.Timeline(100, 20) devtl = aslib.Timeline(100, 20)
# write the test title and general info header # write the test title and general info header
devtl.createHeader(sysvals, 'noftrace') devtl.createHeader(sysvals)
# Generate the header for this timeline # Generate the header for this timeline
t0 = data.start t0 = data.start
@ -373,84 +482,98 @@ def createBootGraph(data, embedded):
if(tTotal == 0): if(tTotal == 0):
print('ERROR: No timeline data') print('ERROR: No timeline data')
return False return False
boot_time = '%.0f'%(tTotal*1000) user_mode = '%.0f'%(data.tUserMode*1000)
devtl.html += html_timetotal.format(boot_time) last_init = '%.0f'%(tTotal*1000)
devtl.html += html_timetotal.format(user_mode, last_init)
# determine the maximum number of rows we need to draw # determine the maximum number of rows we need to draw
phase = 'boot'
list = data.dmesg[phase]['list']
devlist = [] devlist = []
for devname in list: for p in data.phases:
d = aslib.DevItem(0, phase, list[devname]) list = data.dmesg[p]['list']
devlist.append(d) for devname in list:
devtl.getPhaseRows(devlist) d = aslib.DevItem(0, p, list[devname])
devlist.append(d)
devtl.getPhaseRows(devlist, 0, 'start')
devtl.calcTotalRows() devtl.calcTotalRows()
# draw the timeline background # draw the timeline background
devtl.createZoomBox() devtl.createZoomBox()
boot = data.dmesg[phase] devtl.html += devtl.html_tblock.format('boot', '0', '100', devtl.scaleH)
length = boot['end']-boot['start'] for p in data.phases:
left = '%.3f' % (((boot['start']-t0)*100.0)/tTotal) phase = data.dmesg[p]
width = '%.3f' % ((length*100.0)/tTotal) length = phase['end']-phase['start']
devtl.html += devtl.html_tblock.format(phase, left, width, devtl.scaleH) left = '%.3f' % (((phase['start']-t0)*100.0)/tTotal)
devtl.html += devtl.html_phase.format('0', '100', \ width = '%.3f' % ((length*100.0)/tTotal)
'%.3f'%devtl.scaleH, '%.3f'%devtl.bodyH, \ devtl.html += devtl.html_phase.format(left, width, \
'white', '') '%.3f'%devtl.scaleH, '%.3f'%devtl.bodyH, \
phase['color'], '')
# draw the device timeline # draw the device timeline
num = 0 num = 0
devstats = dict() devstats = dict()
for devname in sorted(list): for phase in data.phases:
cls, color = colorForName(devname) list = data.dmesg[phase]['list']
dev = list[devname] for devname in sorted(list):
info = '@|%.3f|%.3f|%.3f|%d' % (dev['start']*1000.0, dev['end']*1000.0, cls, color = colorForName(devname)
dev['ulen']/1000.0, dev['ret']) dev = list[devname]
devstats[dev['id']] = {'info':info} info = '@|%.3f|%.3f|%.3f|%d' % (dev['start']*1000.0, dev['end']*1000.0,
dev['color'] = color dev['ulen']/1000.0, dev['ret'])
height = devtl.phaseRowHeight(0, phase, dev['row']) devstats[dev['id']] = {'info':info}
top = '%.6f' % ((dev['row']*height) + devtl.scaleH) dev['color'] = color
left = '%.6f' % (((dev['start']-t0)*100)/tTotal) height = devtl.phaseRowHeight(0, phase, dev['row'])
width = '%.6f' % (((dev['end']-dev['start'])*100)/tTotal) top = '%.6f' % ((dev['row']*height) + devtl.scaleH)
length = ' (%0.3f ms) ' % ((dev['end']-dev['start'])*1000) left = '%.6f' % (((dev['start']-t0)*100)/tTotal)
devtl.html += devtl.html_device.format(dev['id'], width = '%.6f' % (((dev['end']-dev['start'])*100)/tTotal)
devname+length+'kernel_mode', left, top, '%.3f'%height, length = ' (%0.3f ms) ' % ((dev['end']-dev['start'])*1000)
width, devname, ' '+cls, '') devtl.html += devtl.html_device.format(dev['id'],
rowtop = devtl.phaseRowTop(0, phase, dev['row']) devname+length+phase+'_mode', left, top, '%.3f'%height,
height = '%.6f' % (devtl.rowH / 2) width, devname, ' '+cls, '')
top = '%.6f' % (rowtop + devtl.scaleH + (devtl.rowH / 2)) rowtop = devtl.phaseRowTop(0, phase, dev['row'])
if data.do_one_initcall: height = '%.6f' % (devtl.rowH / 2)
if('ftrace' not in dev): 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 continue
cg = dev['ftrace'] if('ftraces' not in dev):
large, stats = cgOverview(cg, 0.001) continue
devstats[dev['id']]['fstat'] = stats for cg in dev['ftraces']:
for l in large: left = '%f' % (((cg.start-t0)*100)/tTotal)
left = '%f' % (((l.time-t0)*100)/tTotal) width = '%f' % ((cg.end-cg.start)*100/tTotal)
width = '%f' % (l.length*100/tTotal) cglen = (cg.end - cg.start) * 1000.0
title = '%s (%0.3fms)' % (l.name, l.length * 1000.0) title = '%s (%0.3fms)' % (cg.name, cglen)
devtl.html += html_srccall.format(l.name, left, cg.id = 'x%d' % num
top, height, width, title, 'x%d'%num) devtl.html += html_srccall.format(cg.name, left,
top, height, width, title, dev['id']+cg.id)
num += 1 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 # 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' devtl.html += '</div>\n'
# timeline is finished # timeline is finished
devtl.html += '</div>\n</div>\n' 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): if(sysvals.outfile == sysvals.htmlfile):
hf = open(sysvals.htmlfile, 'a') hf = open(sysvals.htmlfile, 'a')
else: else:
@ -474,7 +597,7 @@ def createBootGraph(data, embedded):
.fstat td {text-align:left;width:35px;}\n\ .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 {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' .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) aslib.addCSS(hf, sysvals, 1, False, extra)
# write the device timeline # write the device timeline
@ -495,9 +618,11 @@ def createBootGraph(data, embedded):
html = \ html = \
'<div id="devicedetailtitle"></div>\n'\ '<div id="devicedetailtitle"></div>\n'\
'<div id="devicedetail" style="display:none;">\n'\ '<div id="devicedetail" style="display:none;">\n'\
'<div id="devicedetail0">\n'\ '<div id="devicedetail0">\n'
'<div id="kernel_mode" class="phaselet" style="left:0%;width:100%;background:#DDDDDD"></div>\n'\ for p in data.phases:
'</div>\n</div>\n'\ 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 type="text/javascript">\n'+statinfo+\
'</script>\n' '</script>\n'
hf.write(html) hf.write(html)
@ -507,21 +632,21 @@ def createBootGraph(data, embedded):
aslib.addCallgraphs(sysvals, hf, data) aslib.addCallgraphs(sysvals, hf, data)
# add the dmesg log as a hidden div # add the dmesg log as a hidden div
if sysvals.addlogs: if sysvals.dmesglog:
hf.write('<div id="dmesglog" style="display:none;">\n') hf.write('<div id="dmesglog" style="display:none;">\n')
for line in data.dmesgtext: for line in data.dmesgtext:
line = line.replace('<', '&lt').replace('>', '&gt') line = line.replace('<', '&lt').replace('>', '&gt')
hf.write(line) hf.write(line)
hf.write('</div>\n') hf.write('</div>\n')
if(not embedded): if(not sysvals.embedded):
# write the footer and close # write the footer and close
aslib.addScriptCode(hf, [data]) aslib.addScriptCode(hf, [data])
hf.write('</body>\n</html>\n') hf.write('</body>\n</html>\n')
else: else:
# embedded out will be loaded in a page, skip the js # embedded out will be loaded in a page, skip the js
hf.write('<div id=bounds style=display:none>%f,%f</div>' % \ 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() hf.close()
return True return True
@ -533,17 +658,20 @@ def updateCron(restore=False):
if not restore: if not restore:
sysvals.rootUser(True) sysvals.rootUser(True)
crondir = '/var/spool/cron/crontabs/' crondir = '/var/spool/cron/crontabs/'
cronfile = crondir+'root' if not os.path.exists(crondir):
backfile = crondir+'root-analyze_boot-backup' crondir = '/var/spool/cron/'
if not os.path.exists(crondir): if not os.path.exists(crondir):
doError('%s not found' % crondir) doError('%s not found' % crondir)
out = Popen(['which', 'crontab'], stdout=PIPE).stdout.read() cronfile = crondir+'root'
if not out: backfile = crondir+'root-analyze_boot-backup'
cmd = sysvals.getExec('crontab')
if not cmd:
doError('crontab not found') doError('crontab not found')
# on restore: move the backup cron back into place # on restore: move the backup cron back into place
if restore: if restore:
if os.path.exists(backfile): if os.path.exists(backfile):
shutil.move(backfile, cronfile) shutil.move(backfile, cronfile)
call([cmd, cronfile])
return return
# backup current cron and install new one with reboot # backup current cron and install new one with reboot
if os.path.exists(cronfile): if os.path.exists(cronfile):
@ -556,13 +684,13 @@ def updateCron(restore=False):
fp = open(backfile, 'r') fp = open(backfile, 'r')
op = open(cronfile, 'w') op = open(cronfile, 'w')
for line in fp: for line in fp:
if '@reboot' not in line: if not sysvals.myCronJob(line):
op.write(line) op.write(line)
continue continue
fp.close() fp.close()
op.write('@reboot python %s\n' % sysvals.cronjobCmdString()) op.write('@reboot python %s\n' % sysvals.cronjobCmdString())
op.close() op.close()
res = call('crontab %s' % cronfile, shell=True) res = call([cmd, cronfile])
except Exception, e: except Exception, e:
print 'Exception: %s' % str(e) print 'Exception: %s' % str(e)
shutil.move(backfile, cronfile) shutil.move(backfile, cronfile)
@ -577,25 +705,16 @@ def updateGrub(restore=False):
# call update-grub on restore # call update-grub on restore
if restore: if restore:
try: try:
call(['update-grub'], stderr=PIPE, stdout=PIPE, call(sysvals.blexec, stderr=PIPE, stdout=PIPE,
env={'PATH': '.:/sbin:/usr/sbin:/usr/bin:/sbin:/bin'}) env={'PATH': '.:/sbin:/usr/sbin:/usr/bin:/sbin:/bin'})
except Exception, e: except Exception, e:
print 'Exception: %s\n' % str(e) print 'Exception: %s\n' % str(e)
return 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 # extract the option and create a grub config without it
sysvals.rootUser(True)
tgtopt = 'GRUB_CMDLINE_LINUX_DEFAULT' tgtopt = 'GRUB_CMDLINE_LINUX_DEFAULT'
cmdline = '' cmdline = ''
grubfile = '/etc/default/grub'
tempfile = '/etc/default/grub.analyze_boot' tempfile = '/etc/default/grub.analyze_boot'
shutil.move(grubfile, tempfile) shutil.move(grubfile, tempfile)
res = -1 res = -1
@ -622,7 +741,7 @@ def updateGrub(restore=False):
# if the target option value is in quotes, strip them # if the target option value is in quotes, strip them
sp = '"' sp = '"'
val = cmdline.strip() val = cmdline.strip()
if val[0] == '\'' or val[0] == '"': if val and (val[0] == '\'' or val[0] == '"'):
sp = val[0] sp = val[0]
val = val.strip(sp) val = val.strip(sp)
cmdline = val cmdline = val
@ -633,7 +752,7 @@ def updateGrub(restore=False):
# write out the updated target option # write out the updated target option
op.write('\n%s=%s%s%s\n' % (tgtopt, sp, cmdline, sp)) op.write('\n%s=%s%s%s\n' % (tgtopt, sp, cmdline, sp))
op.close() op.close()
res = call('update-grub') res = call(sysvals.blexec)
os.remove(grubfile) os.remove(grubfile)
except Exception, e: except Exception, e:
print 'Exception: %s' % str(e) print 'Exception: %s' % str(e)
@ -641,10 +760,18 @@ def updateGrub(restore=False):
# cleanup # cleanup
shutil.move(tempfile, grubfile) shutil.move(tempfile, grubfile)
if res != 0: if res != 0:
doError('update-grub failed') doError('update grub failed')
# Function: doError # Function: updateKernelParams
# Description: # 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 # generic error function for catastrphic failures
# Arguments: # Arguments:
# msg: the error message to print # msg: the error message to print
@ -660,7 +787,7 @@ def doError(msg, help=False):
# print out the help text # print out the help text
def printHelp(): def printHelp():
print('') print('')
print('%s v%.1f' % (sysvals.title, sysvals.version)) print('%s v%s' % (sysvals.title, sysvals.version))
print('Usage: bootgraph <options> <command>') print('Usage: bootgraph <options> <command>')
print('') print('')
print('Description:') print('Description:')
@ -669,13 +796,19 @@ def printHelp():
print(' the start of the init process.') print(' the start of the init process.')
print('') print('')
print(' If no specific command is given the tool reads the current dmesg') 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('')
print('Options:') print('Options:')
print(' -h Print this help text') print(' -h Print this help text')
print(' -v Print the current tool version') print(' -v Print the current tool version')
print(' -addlogs Add the dmesg log to the html output') 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(' [advanced]')
print(' -f Use ftrace to add function detail (default: disabled)') print(' -f Use ftrace to add function detail (default: disabled)')
print(' -callgraph Add callgraph detail, can be very large (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(' -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(' -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(' -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(' -func list Limit ftrace to comma-delimited list of functions (default: do_one_initcall)')
print(' [commands]') 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(' -reboot Reboot the machine automatically and generate a new timeline')
print(' -manual Show the requirements to generate a new timeline manually') print(' -manual Show the steps to generate a new timeline manually (used with -reboot)')
print(' -dmesg file Load a stored dmesg file (used with -ftrace)') print('')
print(' -ftrace file Load a stored ftrace file (used with -dmesg)') print('Other commands:')
print(' -flistall Print all functions capable of being captured in ftrace') 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('') print('')
return True return True
@ -698,14 +836,15 @@ def printHelp():
if __name__ == '__main__': if __name__ == '__main__':
# loop through the command line arguments # loop through the command line arguments
cmd = '' cmd = ''
simplecmds = ['-updategrub', '-flistall'] testrun = True
simplecmds = ['-sysinfo', '-kpupdate', '-flistall', '-checkbl']
args = iter(sys.argv[1:]) args = iter(sys.argv[1:])
for arg in args: for arg in args:
if(arg == '-h'): if(arg == '-h'):
printHelp() printHelp()
sys.exit() sys.exit()
elif(arg == '-v'): elif(arg == '-v'):
print("Version %.1f" % sysvals.version) print("Version %s" % sysvals.version)
sys.exit() sys.exit()
elif(arg in simplecmds): elif(arg in simplecmds):
cmd = arg[1:] cmd = arg[1:]
@ -716,16 +855,32 @@ if __name__ == '__main__':
sysvals.usecallgraph = True sysvals.usecallgraph = True
elif(arg == '-mincg'): elif(arg == '-mincg'):
sysvals.mincglen = aslib.getArgFloat('-mincg', args, 0.0, 10000.0) 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'): elif(arg == '-timeprec'):
sysvals.setPrecision(aslib.getArgInt('-timeprec', args, 0, 6)) sysvals.setPrecision(aslib.getArgInt('-timeprec', args, 0, 6))
elif(arg == '-maxdepth'): elif(arg == '-maxdepth'):
sysvals.max_graph_depth = aslib.getArgInt('-maxdepth', args, 0, 1000) sysvals.max_graph_depth = aslib.getArgInt('-maxdepth', args, 0, 1000)
elif(arg == '-filter'): elif(arg == '-func'):
try: try:
val = args.next() val = args.next()
except: except:
doError('No filter functions supplied', True) doError('No filter functions supplied', True)
aslib.rootCheck(True) sysvals.useftrace = True
sysvals.usecallgraph = True
sysvals.rootCheck(True)
sysvals.setGraphFilter(val) sysvals.setGraphFilter(val)
elif(arg == '-ftrace'): elif(arg == '-ftrace'):
try: try:
@ -734,9 +889,10 @@ if __name__ == '__main__':
doError('No ftrace file supplied', True) doError('No ftrace file supplied', True)
if(os.path.exists(val) == False): if(os.path.exists(val) == False):
doError('%s does not exist' % val) doError('%s does not exist' % val)
testrun = False
sysvals.ftracefile = val sysvals.ftracefile = val
elif(arg == '-addlogs'): elif(arg == '-addlogs'):
sysvals.addlogs = True sysvals.dmesglog = True
elif(arg == '-expandcg'): elif(arg == '-expandcg'):
sysvals.cgexp = True sysvals.cgexp = True
elif(arg == '-dmesg'): elif(arg == '-dmesg'):
@ -748,18 +904,15 @@ if __name__ == '__main__':
doError('%s does not exist' % val) doError('%s does not exist' % val)
if(sysvals.htmlfile == val or sysvals.outfile == val): if(sysvals.htmlfile == val or sysvals.outfile == val):
doError('Output filename collision') doError('Output filename collision')
testrun = False
sysvals.dmesgfile = val sysvals.dmesgfile = val
elif(arg == '-o'): elif(arg == '-o'):
try: try:
val = args.next() val = args.next()
except: except:
doError('No HTML filename supplied', True) doError('No subdirectory name supplied', True)
if(sysvals.dmesgfile == val or sysvals.ftracefile == val): sysvals.testdir = sysvals.setOutputFolder(val)
doError('Output filename collision')
sysvals.htmlfile = val
elif(arg == '-reboot'): elif(arg == '-reboot'):
if sysvals.iscronjob:
doError('-reboot and -cronjob are incompatible')
sysvals.reboot = True sysvals.reboot = True
elif(arg == '-manual'): elif(arg == '-manual'):
sysvals.reboot = True sysvals.reboot = True
@ -767,58 +920,93 @@ if __name__ == '__main__':
# remaining options are only for cron job use # remaining options are only for cron job use
elif(arg == '-cronjob'): elif(arg == '-cronjob'):
sysvals.iscronjob = True sysvals.iscronjob = True
if sysvals.reboot:
doError('-reboot and -cronjob are incompatible')
else: else:
doError('Invalid argument: '+arg, True) 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 != '':
if cmd == 'updategrub': if cmd == 'kpupdate':
updateGrub() updateKernelParams()
elif cmd == 'flistall': 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() sys.exit()
# update grub, setup a cronjob, and reboot # reboot: update grub, setup a cronjob, and reboot
if sysvals.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: if not sysvals.manual:
updateGrub() updateKernelParams()
updateCron() updateCron()
call('reboot') call('reboot')
else: else:
sysvals.manualRebootRequired() sysvals.manualRebootRequired()
sys.exit() sys.exit()
# disable the cronjob # cronjob: remove the cronjob, grub changes, and disable ftrace
if sysvals.iscronjob: if sysvals.iscronjob:
updateCron(True) updateCron(True)
updateGrub(True) updateKernelParams(True)
try:
sysvals.fsetVal('0', 'tracing_on')
except:
pass
data = loadKernelLog() # testrun: generate copies of the logs
if sysvals.useftrace: if testrun:
loadTraceLog(data) retrieveLogs()
if sysvals.iscronjob: else:
try: sysvals.setOutputFile()
sysvals.fsetVal('0', 'tracing_on')
except:
pass
if(sysvals.outfile and sysvals.phoronix): # process the log data
fp = open(sysvals.outfile, 'w') if sysvals.dmesgfile:
fp.write('pass %s initstart %.3f end %.3f boot %s\n' % data = parseKernelLog()
(data.valid, data.initstart*1000, data.end*1000, data.boottime)) if(not data.valid):
fp.close()
if(not data.valid):
if sysvals.dmesgfile:
doError('No initcall data found in %s' % sysvals.dmesgfile) doError('No initcall data found in %s' % sysvals.dmesgfile)
else: if sysvals.useftrace and sysvals.ftracefile:
doError('No initcall data found, is initcall_debug enabled?') parseTraceLog(data)
else:
doError('dmesg file required')
print(' Host: %s' % sysvals.hostname) print(' Host: %s' % sysvals.hostname)
print(' Test time: %s' % sysvals.testtime) print(' Test time: %s' % sysvals.testtime)
print(' Boot time: %s' % data.boottime) print(' Boot time: %s' % data.boottime)
print('Kernel Version: %s' % sysvals.kernel) print('Kernel Version: %s' % sysvals.kernel)
print(' Kernel start: %.3f' % (data.start * 1000)) 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)

View File

@ -68,10 +68,12 @@ from subprocess import call, Popen, PIPE
# store system values and test parameters # store system values and test parameters
class SystemValues: class SystemValues:
title = 'SleepGraph' title = 'SleepGraph'
version = '4.6' version = '4.7'
ansi = False ansi = False
verbose = False verbose = False
addlogs = False testlog = True
dmesglog = False
ftracelog = False
mindevlen = 0.0 mindevlen = 0.0
mincglen = 0.0 mincglen = 0.0
cgphase = '' cgphase = ''
@ -79,10 +81,11 @@ class SystemValues:
max_graph_depth = 0 max_graph_depth = 0
callloopmaxgap = 0.0001 callloopmaxgap = 0.0001
callloopmaxlen = 0.005 callloopmaxlen = 0.005
cpucount = 0
memtotal = 204800
srgap = 0 srgap = 0
cgexp = False cgexp = False
outdir = '' testdir = ''
testdir = '.'
tpath = '/sys/kernel/debug/tracing/' tpath = '/sys/kernel/debug/tracing/'
fpdtpath = '/sys/firmware/acpi/tables/FPDT' fpdtpath = '/sys/firmware/acpi/tables/FPDT'
epath = '/sys/kernel/debug/tracing/events/power/' epath = '/sys/kernel/debug/tracing/events/power/'
@ -95,14 +98,17 @@ class SystemValues:
testcommand = '' testcommand = ''
mempath = '/dev/mem' mempath = '/dev/mem'
powerfile = '/sys/power/state' powerfile = '/sys/power/state'
mempowerfile = '/sys/power/mem_sleep'
suspendmode = 'mem' suspendmode = 'mem'
memmode = ''
hostname = 'localhost' hostname = 'localhost'
prefix = 'test' prefix = 'test'
teststamp = '' teststamp = ''
sysstamp = ''
dmesgstart = 0.0 dmesgstart = 0.0
dmesgfile = '' dmesgfile = ''
ftracefile = '' ftracefile = ''
htmlfile = '' htmlfile = 'output.html'
embedded = False embedded = False
rtcwake = True rtcwake = True
rtcwaketime = 15 rtcwaketime = 15
@ -127,9 +133,6 @@ class SystemValues:
devpropfmt = '# Device Properties: .*' devpropfmt = '# Device Properties: .*'
tracertypefmt = '# tracer: (?P<t>.*)' tracertypefmt = '# tracer: (?P<t>.*)'
firmwarefmt = '# fwsuspend (?P<s>[0-9]*) fwresume (?P<r>[0-9]*)$' 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 = { tracefuncs = {
'sys_sync': dict(), 'sys_sync': dict(),
'pm_prepare_console': dict(), 'pm_prepare_console': dict(),
@ -218,7 +221,7 @@ class SystemValues:
# if this is a phoronix test run, set some default options # if this is a phoronix test run, set some default options
if('LOG_FILE' in os.environ and 'TEST_RESULTS_IDENTIFIER' in os.environ): if('LOG_FILE' in os.environ and 'TEST_RESULTS_IDENTIFIER' in os.environ):
self.embedded = True self.embedded = True
self.addlogs = True self.dmesglog = self.ftracelog = True
self.htmlfile = os.environ['LOG_FILE'] self.htmlfile = os.environ['LOG_FILE']
self.archargs = 'args_'+platform.machine() self.archargs = 'args_'+platform.machine()
self.hostname = platform.node() self.hostname = platform.node()
@ -233,6 +236,13 @@ class SystemValues:
self.rtcpath = rtc self.rtcpath = rtc
if (hasattr(sys.stdout, 'isatty') and sys.stdout.isatty()): if (hasattr(sys.stdout, 'isatty') and sys.stdout.isatty()):
self.ansi = True 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): def rootUser(self, fatal=False):
if 'USER' in os.environ and os.environ['USER'] == 'root': if 'USER' in os.environ and os.environ['USER'] == 'root':
return True return True
@ -249,30 +259,60 @@ class SystemValues:
args['date'] = n.strftime('%y%m%d') args['date'] = n.strftime('%y%m%d')
args['time'] = n.strftime('%H%M%S') args['time'] = n.strftime('%H%M%S')
args['hostname'] = self.hostname args['hostname'] = self.hostname
self.outdir = value.format(**args) return value.format(**args)
def setOutputFile(self): def setOutputFile(self):
if((self.htmlfile == '') and (self.dmesgfile != '')): if self.dmesgfile != '':
m = re.match('(?P<name>.*)_dmesg\.txt$', self.dmesgfile) m = re.match('(?P<name>.*)_dmesg\.txt$', self.dmesgfile)
if(m): if(m):
self.htmlfile = m.group('name')+'.html' self.htmlfile = m.group('name')+'.html'
if((self.htmlfile == '') and (self.ftracefile != '')): if self.ftracefile != '':
m = re.match('(?P<name>.*)_ftrace\.txt$', self.ftracefile) m = re.match('(?P<name>.*)_ftrace\.txt$', self.ftracefile)
if(m): if(m):
self.htmlfile = m.group('name')+'.html' self.htmlfile = m.group('name')+'.html'
if(self.htmlfile == ''): def systemInfo(self, info):
self.htmlfile = 'output.html' p = c = m = b = ''
def initTestOutput(self, subdir, testpath=''): 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 self.prefix = self.hostname
v = open('/proc/version', 'r').read().strip() v = open('/proc/version', 'r').read().strip()
kver = string.split(v)[2] kver = string.split(v)[2]
n = datetime.now() fmt = name+'-%m%d%y-%H%M%S'
testtime = n.strftime('suspend-%m%d%y-%H%M%S') testtime = datetime.now().strftime(fmt)
if not testpath:
testpath = n.strftime('suspend-%y%m%d-%H%M%S')
if(subdir != "."):
self.testdir = subdir+"/"+testpath
else:
self.testdir = testpath
self.teststamp = \ self.teststamp = \
'# '+testtime+' '+self.prefix+' '+self.suspendmode+' '+kver '# '+testtime+' '+self.prefix+' '+self.suspendmode+' '+kver
if(self.embedded): if(self.embedded):
@ -355,7 +395,7 @@ class SystemValues:
continue continue
self.tracefuncs[i] = dict() self.tracefuncs[i] = dict()
def getFtraceFilterFunctions(self, current): def getFtraceFilterFunctions(self, current):
rootCheck(True) self.rootCheck(True)
if not current: if not current:
call('cat '+self.tpath+'available_filter_functions', shell=True) call('cat '+self.tpath+'available_filter_functions', shell=True)
return return
@ -453,7 +493,7 @@ class SystemValues:
val += '\nr:%s_ret %s $retval\n' % (name, func) val += '\nr:%s_ret %s $retval\n' % (name, func)
return val return val
def addKprobes(self, output=False): def addKprobes(self, output=False):
if len(sysvals.kprobes) < 1: if len(self.kprobes) < 1:
return return
if output: if output:
print(' kprobe functions in this kernel:') print(' kprobe functions in this kernel:')
@ -525,7 +565,7 @@ class SystemValues:
fp.flush() fp.flush()
fp.close() fp.close()
except: except:
pass return False
return True return True
def fgetVal(self, path): def fgetVal(self, path):
file = self.tpath+path file = self.tpath+path
@ -566,9 +606,15 @@ class SystemValues:
self.cleanupFtrace() self.cleanupFtrace()
# set the trace clock to global # set the trace clock to global
self.fsetVal('global', 'trace_clock') self.fsetVal('global', 'trace_clock')
# set trace buffer to a huge value
self.fsetVal('nop', 'current_tracer') 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 # go no further if this is just a status check
if testing: if testing:
return return
@ -641,6 +687,15 @@ class SystemValues:
if not self.ansi: if not self.ansi:
return str return str
return '\x1B[%d;40m%s\x1B[m' % (color, 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() sysvals = SystemValues()
suspendmodename = { suspendmodename = {
@ -1008,6 +1063,12 @@ class Data:
else: else:
self.trimTime(self.tSuspended, \ self.trimTime(self.tSuspended, \
self.tResumed-self.tSuspended, False) 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): def setPhase(self, phase, ktime, isbegin):
if(isbegin): if(isbegin):
self.dmesg[phase]['start'] = ktime self.dmesg[phase]['start'] = ktime
@ -1517,7 +1578,7 @@ class FTraceCallGraph:
prelinedep += 1 prelinedep += 1
last = 0 last = 0
lasttime = line.time lasttime = line.time
virtualfname = 'execution_misalignment' virtualfname = 'missing_function_name'
if len(self.list) > 0: if len(self.list) > 0:
last = self.list[-1] last = self.list[-1]
lasttime = last.time 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_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_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_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}">&nbsp;{2}</div>\n'
def __init__(self, rowheight, scaleheight): def __init__(self, rowheight, scaleheight):
self.rowH = rowheight self.rowH = rowheight
self.scaleH = scaleheight self.scaleH = scaleheight
self.html = '' self.html = ''
def createHeader(self, sv, suppress=''): def createHeader(self, sv):
if(not sv.stamp['time']): if(not sv.stamp['time']):
return return
self.html += '<div class="version"><a href="https://01.org/suspendresume">%s v%s</a></div>' \ self.html += '<div class="version"><a href="https://01.org/suspendresume">%s v%s</a></div>' \
% (sv.title, sv.version) % (sv.title, sv.version)
if sv.logmsg and 'log' not in suppress: if sv.logmsg and sv.testlog:
self.html += '<button id="showtest" class="logbtn">log</button>' self.html += '<button id="showtest" class="logbtn btnfmt">log</button>'
if sv.addlogs and 'dmesg' not in suppress: if sv.dmesglog:
self.html += '<button id="showdmesg" class="logbtn">dmesg</button>' self.html += '<button id="showdmesg" class="logbtn btnfmt">dmesg</button>'
if sv.addlogs and sv.ftracefile and 'ftrace' not in suppress: if sv.ftracelog:
self.html += '<button id="showftrace" class="logbtn">ftrace</button>' self.html += '<button id="showftrace" class="logbtn btnfmt">ftrace</button>'
headline_stamp = '<div class="stamp">{0} {1} {2} {3}</div>\n' headline_stamp = '<div class="stamp">{0} {1} {2} {3}</div>\n'
self.html += headline_stamp.format(sv.stamp['host'], sv.stamp['kernel'], self.html += headline_stamp.format(sv.stamp['host'], sv.stamp['kernel'],
sv.stamp['mode'], sv.stamp['time']) 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 # Function: getDeviceRows
# Description: # Description:
# determine how may rows the device funcs will take # 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 # devlist: the list of devices/actions in a group of contiguous phases
# Output: # Output:
# The total number of rows needed to display this phase of the timeline # 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 # clear all rows and set them to undefined
remaining = len(devlist) remaining = len(devlist)
rowdata = dict() rowdata = dict()
@ -1852,8 +1919,12 @@ class Timeline:
if tp not in myphases: if tp not in myphases:
myphases.append(tp) myphases.append(tp)
dev['row'] = -1 dev['row'] = -1
# sort by length 1st, then name 2nd if sortby == 'start':
sortdict[item] = (float(dev['end']) - float(dev['start']), item.dev['name']) # 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: if 'src' in dev:
dev['devrows'] = self.getDeviceRows(dev['src']) dev['devrows'] = self.getDeviceRows(dev['src'])
# sort the devlist by length so that large items graph on top # 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 # A list of values describing the properties of these test runs
class TestProps: class TestProps:
stamp = '' stamp = ''
sysinfo = ''
S0i3 = False S0i3 = False
fwdata = [] 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 = \ ftrace_line_fmt_fg = \
'^ *(?P<time>[0-9\.]*) *\| *(?P<cpu>[0-9]*)\)'+\ '^ *(?P<time>[0-9\.]*) *\| *(?P<cpu>[0-9]*)\)'+\
' *(?P<proc>.*)-(?P<pid>[0-9]*) *\|'+\ ' *(?P<proc>.*)-(?P<pid>[0-9]*) *\|'+\
@ -2019,6 +2095,36 @@ class TestProps:
self.ftrace_line_fmt = self.ftrace_line_fmt_nop self.ftrace_line_fmt = self.ftrace_line_fmt_nop
else: else:
doError('Invalid tracer format: [%s]' % tracer) 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 # Class: TestRun
# Description: # Description:
@ -2090,35 +2196,6 @@ def vprint(msg):
if(sysvals.verbose): if(sysvals.verbose):
print(msg) 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 # Function: doesTraceLogHaveTraceEvents
# Description: # Description:
# Quickly determine if the ftrace log has some or all of the trace events # Quickly determine if the ftrace log has some or all of the trace events
@ -2136,11 +2213,6 @@ def doesTraceLogHaveTraceEvents():
sysvals.usekprobes = True sysvals.usekprobes = True
out = Popen(['head', '-1', sysvals.ftracefile], out = Popen(['head', '-1', sysvals.ftracefile],
stderr=PIPE, stdout=PIPE).stdout.read().replace('\n', '') 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 # figure out what level of trace events are supported
sysvals.usetraceeventsonly = True sysvals.usetraceeventsonly = True
sysvals.usetraceevents = False sysvals.usetraceevents = False
@ -2182,11 +2254,13 @@ def appendIncompleteTraceLog(testruns):
for line in tf: for line in tf:
# remove any latent carriage returns # remove any latent carriage returns
line = line.replace('\r\n', '') line = line.replace('\r\n', '')
# grab the time stamp # grab the stamp and sysinfo
m = re.match(sysvals.stampfmt, line) if re.match(tp.stampfmt, line):
if(m):
tp.stamp = line tp.stamp = line
continue continue
elif re.match(tp.sysinfofmt, line):
tp.sysinfo = line
continue
# determine the trace data type (required for further parsing) # determine the trace data type (required for further parsing)
m = re.match(sysvals.tracertypefmt, line) m = re.match(sysvals.tracertypefmt, line)
if(m): if(m):
@ -2219,7 +2293,7 @@ def appendIncompleteTraceLog(testruns):
# look for the suspend start marker # look for the suspend start marker
if(t.startMarker()): if(t.startMarker()):
data = testrun[testidx].data data = testrun[testidx].data
parseStamp(tp.stamp, data) tp.parseStamp(data, sysvals)
data.setStart(t.time) data.setStart(t.time)
continue continue
if(not data): if(not data):
@ -2389,11 +2463,13 @@ def parseTraceLog():
for line in tf: for line in tf:
# remove any latent carriage returns # remove any latent carriage returns
line = line.replace('\r\n', '') line = line.replace('\r\n', '')
# stamp line: each stamp means a new test run # stamp and sysinfo lines
m = re.match(sysvals.stampfmt, line) if re.match(tp.stampfmt, line):
if(m):
tp.stamp = line tp.stamp = line
continue continue
elif re.match(tp.sysinfofmt, line):
tp.sysinfo = line
continue
# firmware line: pull out any firmware data # firmware line: pull out any firmware data
m = re.match(sysvals.firmwarefmt, line) m = re.match(sysvals.firmwarefmt, line)
if(m): if(m):
@ -2439,7 +2515,7 @@ def parseTraceLog():
testdata.append(data) testdata.append(data)
testrun = TestRun(data) testrun = TestRun(data)
testruns.append(testrun) testruns.append(testrun)
parseStamp(tp.stamp, data) tp.parseStamp(data, sysvals)
data.setStart(t.time) data.setStart(t.time)
data.tKernSus = t.time data.tKernSus = t.time
continue continue
@ -2820,10 +2896,13 @@ def loadKernelLog(justtext=False):
idx = line.find('[') idx = line.find('[')
if idx > 1: if idx > 1:
line = line[idx:] line = line[idx:]
m = re.match(sysvals.stampfmt, line) # grab the stamp and sysinfo
if(m): if re.match(tp.stampfmt, line):
tp.stamp = line tp.stamp = line
continue continue
elif re.match(tp.sysinfofmt, line):
tp.sysinfo = line
continue
m = re.match(sysvals.firmwarefmt, line) m = re.match(sysvals.firmwarefmt, line)
if(m): if(m):
tp.fwdata.append((int(m.group('s')), int(m.group('r')))) tp.fwdata.append((int(m.group('s')), int(m.group('r'))))
@ -2839,7 +2918,7 @@ def loadKernelLog(justtext=False):
if(data): if(data):
testruns.append(data) testruns.append(data)
data = Data(len(testruns)) data = Data(len(testruns))
parseStamp(tp.stamp, data) tp.parseStamp(data, sysvals)
if len(tp.fwdata) > data.testnumber: if len(tp.fwdata) > data.testnumber:
data.fwSuspend, data.fwResume = tp.fwdata[data.testnumber] data.fwSuspend, data.fwResume = tp.fwdata[data.testnumber]
if(data.fwSuspend > 0 or data.fwResume > 0): if(data.fwSuspend > 0 or data.fwResume > 0):
@ -3170,6 +3249,8 @@ def addCallgraphs(sv, hf, data):
continue continue
list = data.dmesg[p]['list'] list = data.dmesg[p]['list']
for devname in data.sortedDevices(p): for devname in data.sortedDevices(p):
if len(sv.devicefilter) > 0 and devname not in sv.devicefilter:
continue
dev = list[devname] dev = list[devname]
color = 'white' color = 'white'
if 'color' in data.dmesg[p]: 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&rarr;</div>\n' html_error = '<div id="{1}" title="kernel error/warning" class="err" style="right:{0}%">ERROR&rarr;</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_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_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}">&nbsp;{2}</div>\n'
html_timetotal = '<table class="time1">\n<tr>'\ html_timetotal = '<table class="time1">\n<tr>'\
'<td class="green" title="{3}">{2} Suspend Time: <b>{0} ms</b></td>'\ '<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>'\ '<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 # Generate the header for this timeline
for data in testruns: for data in testruns:
tTotal = data.end - data.start tTotal = data.end - data.start
sktime = (data.dmesg['suspend_machine']['end'] - \ sktime, rktime = data.getTimeValues()
data.tKernSus) * 1000
rktime = (data.dmesg['resume_complete']['end'] - \
data.dmesg['resume_machine']['start']) * 1000
if(tTotal == 0): if(tTotal == 0):
print('ERROR: No timeline data') print('ERROR: No timeline data')
sys.exit() sys.exit()
@ -3581,7 +3658,7 @@ def createHTML(testruns):
id += tmp[1][0] id += tmp[1][0]
order = '%.2f' % ((data.dmesg[phase]['order'] * pdelta) + pmargin) order = '%.2f' % ((data.dmesg[phase]['order'] * pdelta) + pmargin)
name = string.replace(phase, '_', ' &nbsp;') name = string.replace(phase, '_', ' &nbsp;')
devtl.html += html_legend.format(order, \ devtl.html += devtl.html_legend.format(order, \
data.dmesg[phase]['color'], name, id) data.dmesg[phase]['color'], name, id)
devtl.html += '</div>\n' devtl.html += '</div>\n'
@ -3628,10 +3705,10 @@ def createHTML(testruns):
addCallgraphs(sysvals, hf, data) addCallgraphs(sysvals, hf, data)
# add the test log as a hidden div # 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') hf.write('<div id="testlog" style="display:none;">\n'+sysvals.logmsg+'</div>\n')
# add the dmesg log as a hidden div # 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') hf.write('<div id="dmesglog" style="display:none;">\n')
lf = open(sysvals.dmesgfile, 'r') lf = open(sysvals.dmesgfile, 'r')
for line in lf: for line in lf:
@ -3640,7 +3717,7 @@ def createHTML(testruns):
lf.close() lf.close()
hf.write('</div>\n') hf.write('</div>\n')
# add the ftrace log as a hidden div # 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') hf.write('<div id="ftracelog" style="display:none;">\n')
lf = open(sysvals.ftracefile, 'r') lf = open(sysvals.ftracefile, 'r')
for line in lf: for line in lf:
@ -3701,6 +3778,7 @@ def addCSS(hf, sv, testcount=1, kerror=False, extra=''):
<style type=\'text/css\'>\n\ <style type=\'text/css\'>\n\
body {overflow-y:scroll;}\n\ body {overflow-y:scroll;}\n\
.stamp {width:100%;text-align:center;background:gray;line-height:30px;color:white;font:25px Arial;}\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 {margin-top:30px;box-shadow:5px 5px 20px black;}\n\
.callgraph article * {padding-left:28px;}\n\ .callgraph article * {padding-left:28px;}\n\
h1 {color:black;font:bold 30px Times;}\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 {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\ .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\ 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\ .devlist {position:'+devlistpos+';width:190px;}\n\
a:link {color:white;text-decoration:none;}\n\ a:link {color:white;text-decoration:none;}\n\
a:visited {color:white;}\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.write(title+"<pre>"+log.innerHTML+"</pre>");\n'\
' win.document.close();\n'\ ' win.document.close();\n'\
' }\n'\ ' }\n'\
' function onClickPhase(e) {\n'\
' }\n'\
' function onMouseDown(e) {\n'\ ' function onMouseDown(e) {\n'\
' dragval[0] = e.clientX;\n'\ ' dragval[0] = e.clientX;\n'\
' dragval[1] = document.getElementById("dmesgzoombox").scrollLeft;\n'\ ' dragval[1] = document.getElementById("dmesgzoombox").scrollLeft;\n'\
@ -4120,9 +4196,6 @@ def addScriptCode(hf, testruns):
' document.getElementById("zoomin").onclick = zoomTimeline;\n'\ ' document.getElementById("zoomin").onclick = zoomTimeline;\n'\
' document.getElementById("zoomout").onclick = zoomTimeline;\n'\ ' document.getElementById("zoomout").onclick = zoomTimeline;\n'\
' document.getElementById("zoomdef").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'\ ' var list = document.getElementsByClassName("err");\n'\
' for (var i = 0; i < list.length; i++)\n'\ ' for (var i = 0; i < list.length; i++)\n'\
' list[i].onclick = errWindow;\n'\ ' list[i].onclick = errWindow;\n'\
@ -4193,8 +4266,14 @@ def executeSuspend():
if sysvals.testcommand != '': if sysvals.testcommand != '':
call(sysvals.testcommand+' 2>&1', shell=True); call(sysvals.testcommand+' 2>&1', shell=True);
else: 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 = open(sysvals.powerfile, 'w')
pf.write(sysvals.suspendmode) pf.write(mode)
# execution will pause here # execution will pause here
try: try:
pf.close() pf.close()
@ -4219,24 +4298,15 @@ def executeSuspend():
pm.stop() pm.stop()
sysvals.fsetVal('0', 'tracing_on') sysvals.fsetVal('0', 'tracing_on')
print('CAPTURING TRACE') print('CAPTURING TRACE')
writeDatafileHeader(sysvals.ftracefile, fwdata) sysvals.writeDatafileHeader(sysvals.ftracefile, fwdata)
call('cat '+tp+'trace >> '+sysvals.ftracefile, shell=True) call('cat '+tp+'trace >> '+sysvals.ftracefile, shell=True)
sysvals.fsetVal('', 'trace') sysvals.fsetVal('', 'trace')
devProps() devProps()
# grab a copy of the dmesg output # grab a copy of the dmesg output
print('CAPTURING DMESG') print('CAPTURING DMESG')
writeDatafileHeader(sysvals.dmesgfile, fwdata) sysvals.writeDatafileHeader(sysvals.dmesgfile, fwdata)
sysvals.getdmesg() 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 # Function: setUSBDevicesAuto
# Description: # Description:
# Set the autosuspend control parameter of all USB devices to auto # 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 # to always-on since the kernel cant determine if the device can
# properly autosuspend # properly autosuspend
def setUSBDevicesAuto(): def setUSBDevicesAuto():
rootCheck(True) sysvals.rootCheck(True)
for dirname, dirnames, filenames in os.walk('/sys/devices'): for dirname, dirnames, filenames in os.walk('/sys/devices'):
if(re.match('.*/usb[0-9]*.*', dirname) and if(re.match('.*/usb[0-9]*.*', dirname) and
'idVendor' in filenames and 'idProduct' in filenames): 'idVendor' in filenames and 'idProduct' in filenames):
@ -4467,13 +4537,146 @@ def devProps(data=0):
# Output: # Output:
# A string list of the available modes # A string list of the available modes
def getModes(): def getModes():
modes = '' modes = []
if(os.path.exists(sysvals.powerfile)): if(os.path.exists(sysvals.powerfile)):
fp = open(sysvals.powerfile, 'r') fp = open(sysvals.powerfile, 'r')
modes = string.split(fp.read()) modes = string.split(fp.read())
fp.close() 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 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 # Function: getFPDT
# Description: # Description:
# Read the acpi bios tables and pull out FPDT, the firmware data # 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[0] = 'Basic S3 Resume Performance Record'
prectype[1] = 'Basic S3 Suspend Performance Record' prectype[1] = 'Basic S3 Suspend Performance Record'
rootCheck(True) sysvals.rootCheck(True)
if(not os.path.exists(sysvals.fpdtpath)): if(not os.path.exists(sysvals.fpdtpath)):
if(output): if(output):
doError('file does not exist: %s' % sysvals.fpdtpath) doError('file does not exist: %s' % sysvals.fpdtpath)
@ -4617,7 +4820,7 @@ def statusCheck(probecheck=False):
# check we have root access # check we have root access
res = sysvals.colorText('NO (No features of this tool will work!)') res = sysvals.colorText('NO (No features of this tool will work!)')
if(rootCheck(False)): if(sysvals.rootCheck(False)):
res = 'YES' res = 'YES'
print(' have root access: %s' % res) print(' have root access: %s' % res)
if(res != 'YES'): if(res != 'YES'):
@ -4716,16 +4919,6 @@ def doError(msg, help=False):
print('ERROR: %s\n') % msg print('ERROR: %s\n') % msg
sys.exit() 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 # Function: getArgInt
# Description: # Description:
# pull out an integer argument from the command line with checks # 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)): if(sysvals.ftracefile and (sysvals.usecallgraph or sysvals.usetraceevents)):
appendIncompleteTraceLog(testruns) appendIncompleteTraceLog(testruns)
createHTML(testruns) createHTML(testruns)
return testruns
# Function: rerunTest # Function: rerunTest
# Description: # Description:
@ -4790,17 +4984,20 @@ def rerunTest():
doError('recreating this html output requires a dmesg file') doError('recreating this html output requires a dmesg file')
sysvals.setOutputFile() sysvals.setOutputFile()
vprint('Output file: %s' % sysvals.htmlfile) vprint('Output file: %s' % sysvals.htmlfile)
if(os.path.exists(sysvals.htmlfile) and not os.access(sysvals.htmlfile, os.W_OK)): if os.path.exists(sysvals.htmlfile):
doError('missing permission to write to %s' % sysvals.htmlfile) if not os.path.isfile(sysvals.htmlfile):
processData() 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 # Function: runTest
# Description: # Description:
# execute a suspend/resume, gather the logs, and generate the output # execute a suspend/resume, gather the logs, and generate the output
def runTest(subdir, testpath=''): def runTest():
# prepare for the test # prepare for the test
sysvals.initFtrace() sysvals.initFtrace()
sysvals.initTestOutput(subdir, testpath) sysvals.initTestOutput('suspend')
vprint('Output files:\n\t%s\n\t%s\n\t%s' % \ vprint('Output files:\n\t%s\n\t%s\n\t%s' % \
(sysvals.dmesgfile, sysvals.ftracefile, sysvals.htmlfile)) (sysvals.dmesgfile, sysvals.ftracefile, sysvals.htmlfile))
@ -4897,7 +5094,7 @@ def configFromFile(file):
if(opt.lower() == 'verbose'): if(opt.lower() == 'verbose'):
sysvals.verbose = checkArgBool(value) sysvals.verbose = checkArgBool(value)
elif(opt.lower() == 'addlogs'): elif(opt.lower() == 'addlogs'):
sysvals.addlogs = checkArgBool(value) sysvals.dmesglog = sysvals.ftracelog = checkArgBool(value)
elif(opt.lower() == 'dev'): elif(opt.lower() == 'dev'):
sysvals.usedevsrc = checkArgBool(value) sysvals.usedevsrc = checkArgBool(value)
elif(opt.lower() == 'proc'): elif(opt.lower() == 'proc'):
@ -4947,7 +5144,7 @@ def configFromFile(file):
elif(opt.lower() == 'mincg'): elif(opt.lower() == 'mincg'):
sysvals.mincglen = getArgFloat('-mincg', value, 0.0, 10000.0, False) sysvals.mincglen = getArgFloat('-mincg', value, 0.0, 10000.0, False)
elif(opt.lower() == 'output-dir'): elif(opt.lower() == 'output-dir'):
sysvals.setOutputFolder(value) sysvals.testdir = sysvals.setOutputFolder(value)
if sysvals.suspendmode == 'command' and not sysvals.testcommand: if sysvals.suspendmode == 'command' and not sysvals.testcommand:
doError('No command supplied for mode "command"') doError('No command supplied for mode "command"')
@ -5030,8 +5227,6 @@ def configFromFile(file):
# Description: # Description:
# print out the help text # print out the help text
def printHelp(): def printHelp():
modes = getModes()
print('') print('')
print('%s v%s' % (sysvals.title, sysvals.version)) print('%s v%s' % (sysvals.title, sysvals.version))
print('Usage: sudo sleepgraph <options> <commands>') 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(' 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(' a suspend/resume and capture the dmesg/ftrace output as an html timeline.')
print('') 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(' HTML output: <hostname>_<mode>.html')
print(' raw dmesg output: <hostname>_<mode>_dmesg.txt') print(' raw dmesg output: <hostname>_<mode>_dmesg.txt')
print(' raw ftrace output: <hostname>_<mode>_ftrace.txt') print(' raw ftrace output: <hostname>_<mode>_ftrace.txt')
@ -5058,8 +5253,9 @@ def printHelp():
print(' -v Print the current tool version') print(' -v Print the current tool version')
print(' -config fn Pull arguments and config options from file fn') print(' -config fn Pull arguments and config options from file fn')
print(' -verbose Print extra information during execution and analysis') print(' -verbose Print extra information during execution and analysis')
print(' -m mode Mode to initiate for suspend %s (default: %s)') % (modes, sysvals.suspendmode) print(' -m mode Mode to initiate for suspend (default: %s)') % (sysvals.suspendmode)
print(' -o subdir Override the output subdirectory') 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(' -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(' -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)') 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(' -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(' -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(' -timeprec N Number of significant digits in timestamps (0:S, [3:ms], 6:us)')
print(' [commands]') print('')
print(' -ftrace ftracefile Create HTML output using ftrace input (used with -dmesg)') print('Other commands:')
print(' -dmesg dmesgfile Create HTML output using dmesg (used with -ftrace)')
print(' -summary directory Create a summary of all test in this dir')
print(' -modes List available suspend modes') print(' -modes List available suspend modes')
print(' -status Test to see if the system is enabled to run this tool') 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(' -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(' -usbtopo Print out the current USB topology with power info')
print(' -usbauto Enable autosuspend for all connected USB devices') print(' -usbauto Enable autosuspend for all connected USB devices')
print(' -flist Print the list of functions currently being captured in ftrace') print(' -flist Print the list of functions currently being captured in ftrace')
print(' -flistall Print all functions capable of 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('') print('')
return True return True
@ -5102,9 +5301,9 @@ def printHelp():
# exec start (skipped if script is loaded as library) # exec start (skipped if script is loaded as library)
if __name__ == '__main__': if __name__ == '__main__':
cmd = '' cmd = ''
cmdarg = '' outdir = ''
multitest = {'run': False, 'count': 0, 'delay': 0} 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 # loop through the command line arguments
args = iter(sys.argv[1:]) args = iter(sys.argv[1:])
for arg in args: for arg in args:
@ -5135,7 +5334,7 @@ if __name__ == '__main__':
elif(arg == '-f'): elif(arg == '-f'):
sysvals.usecallgraph = True sysvals.usecallgraph = True
elif(arg == '-addlogs'): elif(arg == '-addlogs'):
sysvals.addlogs = True sysvals.dmesglog = sysvals.ftracelog = True
elif(arg == '-verbose'): elif(arg == '-verbose'):
sysvals.verbose = True sysvals.verbose = True
elif(arg == '-proc'): elif(arg == '-proc'):
@ -5195,7 +5394,7 @@ if __name__ == '__main__':
val = args.next() val = args.next()
except: except:
doError('No subdirectory name supplied', True) doError('No subdirectory name supplied', True)
sysvals.setOutputFolder(val) outdir = sysvals.setOutputFolder(val)
elif(arg == '-config'): elif(arg == '-config'):
try: try:
val = args.next() val = args.next()
@ -5236,7 +5435,7 @@ if __name__ == '__main__':
except: except:
doError('No directory supplied', True) doError('No directory supplied', True)
cmd = 'summary' cmd = 'summary'
cmdarg = val outdir = val
sysvals.notestrun = True sysvals.notestrun = True
if(os.path.isdir(val) == False): if(os.path.isdir(val) == False):
doError('%s is not accesible' % val) doError('%s is not accesible' % val)
@ -5260,11 +5459,14 @@ if __name__ == '__main__':
sysvals.mincglen = sysvals.mindevlen sysvals.mincglen = sysvals.mindevlen
# just run a utility command and exit # just run a utility command and exit
sysvals.cpuInfo()
if(cmd != ''): if(cmd != ''):
if(cmd == 'status'): if(cmd == 'status'):
statusCheck(True) statusCheck(True)
elif(cmd == 'fpdt'): elif(cmd == 'fpdt'):
getFPDT(True) getFPDT(True)
elif(cmd == 'sysinfo'):
sysvals.printSystemInfo()
elif(cmd == 'usbtopo'): elif(cmd == 'usbtopo'):
detectUSB() detectUSB()
elif(cmd == 'modes'): elif(cmd == 'modes'):
@ -5276,7 +5478,7 @@ if __name__ == '__main__':
elif(cmd == 'usbauto'): elif(cmd == 'usbauto'):
setUSBDevicesAuto() setUSBDevicesAuto()
elif(cmd == 'summary'): elif(cmd == 'summary'):
runSummary(cmdarg, True) runSummary(outdir, True)
sys.exit() sys.exit()
# if instructed, re-analyze existing data files # if instructed, re-analyze existing data files
@ -5289,21 +5491,43 @@ if __name__ == '__main__':
print('Check FAILED, aborting the test run!') print('Check FAILED, aborting the test run!')
sys.exit() 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']: if multitest['run']:
# run multiple tests in a separate subdirectory # run multiple tests in a separate subdirectory
s = 'x%d' % multitest['count'] if not outdir:
if not sysvals.outdir: s = 'suspend-x%d' % multitest['count']
sysvals.outdir = datetime.now().strftime('suspend-'+s+'-%m%d%y-%H%M%S') outdir = datetime.now().strftime(s+'-%y%m%d-%H%M%S')
if not os.path.isdir(sysvals.outdir): if not os.path.isdir(outdir):
os.mkdir(sysvals.outdir) os.mkdir(outdir)
for i in range(multitest['count']): for i in range(multitest['count']):
if(i != 0): if(i != 0):
print('Waiting %d seconds...' % (multitest['delay'])) print('Waiting %d seconds...' % (multitest['delay']))
time.sleep(multitest['delay']) time.sleep(multitest['delay'])
print('TEST (%d/%d) START' % (i+1, multitest['count'])) 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'])) print('TEST (%d/%d) COMPLETE' % (i+1, multitest['count']))
runSummary(sysvals.outdir, False) runSummary(outdir, False)
else: else:
if outdir:
sysvals.testdir = outdir
# run the test in the current directory # run the test in the current directory
runTest('.', sysvals.outdir) runTest()

View File

@ -8,14 +8,23 @@ bootgraph \- Kernel boot timing analysis
.RB [ COMMAND ] .RB [ COMMAND ]
.SH DESCRIPTION .SH DESCRIPTION
\fBbootgraph \fP reads the dmesg log from kernel boot and \fBbootgraph \fP reads the dmesg log from kernel boot and
creates an html representation of the initcall timeline up to the start creates an html representation of the initcall timeline. It graphs
of the init process. 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 .PP
If no specific command is given, the tool reads the current dmesg log and If no specific command is given, the tool reads the current dmesg log and
outputs bootgraph.html. outputs a new timeline.
.PP .PP
The tool can also augment the timeline with ftrace data on custom target The tool can also augment the timeline with ftrace data on custom target
functions as well as full trace callgraphs. 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 .SH OPTIONS
.TP .TP
\fB-h\fR \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 Add the dmesg log to the html output. It will be viewable by
clicking a button in the timeline. clicking a button in the timeline.
.TP .TP
\fB-o \fIfile\fR \fB-o \fIname\fR
Override the HTML output filename (default: bootgraph.html) Overrides the output subdirectory name when running a new test.
.SS "Ftrace Debug" Use {date}, {time}, {hostname} for current values.
.sp
e.g. boot-{hostname}-{date}-{time}
.SS "advanced"
.TP .TP
\fB-f\fR \fB-f\fR
Use ftrace to add function detail (default: disabled) Use ftrace to add function detail (default: disabled)
.TP .TP
\fB-callgraph\fR \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 is not used there will be one callgraph per initcall. This can produce
very large outputs, i.e. 10MB - 100MB. very large outputs, i.e. 10MB - 100MB.
.TP .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. which are barely visible in the timeline.
The value is a float: e.g. 0.001 represents 1 us. The value is a float: e.g. 0.001 represents 1 us.
.TP .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 \fB-timeprec \fIn\fR
Number of significant digits in timestamps (0:S, 3:ms, [6:us]) Number of significant digits in timestamps (0:S, 3:ms, [6:us])
.TP .TP
\fB-expandcg\fR \fB-expandcg\fR
pre-expand the callgraph data in the html output (default: disabled) pre-expand the callgraph data in the html output (default: disabled)
.TP .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) Instead of tracing each initcall, trace a custom list of functions (default: do_one_initcall)
.SH COMMANDS
.TP .TP
\fB-reboot\fR \fB-reboot\fR
Reboot the machine and generate a new timeline automatically. Works in 4 steps. 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. 1. append the string to the kernel command line via your native boot manager.
2. reboot the system 2. reboot the system
3. after startup, re-run the tool with the same arguments and no command 3. after startup, re-run the tool with the same arguments and no command
.SH COMMANDS
.SS "rebuild"
.TP .TP
\fB-dmesg \fIfile\fR \fB-dmesg \fIfile\fR
Create HTML output from an existing dmesg file. Create HTML output from an existing dmesg file.
.TP .TP
\fB-ftrace \fIfile\fR \fB-ftrace \fIfile\fR
Create HTML output from an existing ftrace file (used with -dmesg). Create HTML output from an existing ftrace file (used with -dmesg).
.SS "other"
.TP .TP
\fB-flistall\fR \fB-flistall\fR
Print all ftrace functions capable of being captured. These are all the 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 .SH EXAMPLES
Create a timeline using the current dmesg log. Create a timeline using the current dmesg log.
@ -93,13 +115,13 @@ Create a timeline using the current dmesg and ftrace log.
.IP .IP
\f(CW$ bootgraph -callgraph\fR \f(CW$ bootgraph -callgraph\fR
.PP .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 .IP
\f(CW$ bootgraph -addlogs -o myboot.html\fR \f(CW$ bootgraph -addlogs -o "myboot-{date}-{time}"\fR
.PP .PP
Capture a new boot timeline by automatically rebooting the machine. Capture a new boot timeline by automatically rebooting the machine.
.IP .IP
\f(CW$ sudo bootgraph -reboot -addlogs -o latestboot.html\fR \f(CW$ sudo bootgraph -reboot -addlogs -o "latest-{hostname)"\fR
.PP .PP
Capture a new boot timeline with function trace data. Capture a new boot timeline with function trace data.
.IP .IP
@ -111,7 +133,7 @@ Capture a new boot timeline with trace & callgraph data. Skip callgraphs smaller
.PP .PP
Capture a new boot timeline with callgraph data over custom functions. Capture a new boot timeline with callgraph data over custom functions.
.IP .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 .PP
Capture a brand new boot timeline with manual reboot. Capture a brand new boot timeline with manual reboot.
.IP .IP
@ -123,6 +145,15 @@ Capture a brand new boot timeline with manual reboot.
.IP .IP
\f(CW$ sudo bootgraph -callgraph # re-run the tool after restart\fR \f(CW$ sudo bootgraph -callgraph # re-run the tool after restart\fR
.PP .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" .SH "SEE ALSO"
dmesg(1), update-grub(8), crontab(1), reboot(8) dmesg(1), update-grub(8), crontab(1), reboot(8)

View File

@ -39,8 +39,9 @@ Pull arguments and config options from a file.
\fB-m \fImode\fR \fB-m \fImode\fR
Mode to initiate for suspend e.g. standby, freeze, mem (default: mem). Mode to initiate for suspend e.g. standby, freeze, mem (default: mem).
.TP .TP
\fB-o \fIsubdir\fR \fB-o \fIname\fR
Override the output subdirectory. Use {date}, {time}, {hostname} for current values. Overrides the output subdirectory name when running a new test.
Use {date}, {time}, {hostname} for current values.
.sp .sp
e.g. suspend-{hostname}-{date}-{time} e.g. suspend-{hostname}-{date}-{time}
.TP .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 Add the dmesg and ftrace logs to the html output. They will be viewable by
clicking buttons in the timeline. clicking buttons in the timeline.
.SS "Advanced" .SS "advanced"
.TP .TP
\fB-cmd \fIstr\fR \fB-cmd \fIstr\fR
Run the timeline over a custom suspend command, e.g. pm-suspend. By default 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 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}. be created in a new subdirectory with a summary page: suspend-xN-{date}-{time}.
.SS "Ftrace Debug" .SS "ftrace debug"
.TP .TP
\fB-f\fR \fB-f\fR
Use ftrace to create device callgraphs (default: disabled). This can produce 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 .SH COMMANDS
.TP .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 \fB-summary \fIindir\fR
Create a summary page of all tests in \fIindir\fR. Creates summary.html 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 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 \fB-fpdt\fR
Print out the contents of the ACPI Firmware Performance Data Table. Print out the contents of the ACPI Firmware Performance Data Table.
.TP .TP
\fB-sysinfo\fR
Print out system info extracted from BIOS. Reads /dev/mem directly instead of going through dmidecode.
.TP
\fB-usbtopo\fR \fB-usbtopo\fR
Print out the current USB topology with power info. Print out the current USB topology with power info.
.TP .TP
@ -162,9 +160,16 @@ with -fadd they will also be checked.
\fB-flistall\fR \fB-flistall\fR
Print all ftrace functions capable of being captured. These are all the Print all ftrace functions capable of being captured. These are all the
possible values you can add to trace via the -fadd argument. 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 .SH EXAMPLES
.SS "Simple Commands" .SS "simple commands"
Check which suspend modes are currently supported. Check which suspend modes are currently supported.
.IP .IP
\f(CW$ sleepgraph -modes\fR \f(CW$ sleepgraph -modes\fR
@ -185,12 +190,8 @@ Generate a summary of all timelines in a particular folder.
.IP .IP
\f(CW$ sleepgraph -summary ~/workspace/myresults/\fR \f(CW$ sleepgraph -summary ~/workspace/myresults/\fR
.PP .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. Execute a mem suspend with a 15 second wakeup. Include the logs in the html.
.IP .IP
\f(CW$ sudo sleepgraph -rtcwake 15 -addlogs\fR \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 \f(CW$ sudo sleepgraph -m freeze -rtcwake off -o "freeze-{hostname}-{date}-{time}"\fR
.PP .PP
.SS "Capturing Advanced Timelines" .SS "capturing advanced timelines"
Execute a suspend & include dev mode source calls, limit callbacks to 5ms or larger. Execute a suspend & include dev mode source calls, limit callbacks to 5ms or larger.
.IP .IP
\f(CW$ sudo sleepgraph -m mem -rtcwake 15 -dev -mindev 5\fR \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 \f(CW$ sudo sleepgraph -cmd "echo mem > /sys/power/state" -rtcwake 15\fR
.PP .PP
.SS "adding callgraph data"
.SS "Capturing Timelines with Callgraph Data"
Add device callgraphs. Limit the trace depth and only show callgraphs 10ms or larger. Add device callgraphs. Limit the trace depth and only show callgraphs 10ms or larger.
.IP .IP
\f(CW$ sudo sleepgraph -m mem -rtcwake 15 -f -maxdepth 5 -mincg 10\fR \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 \f(CW$ sleepgraph -dmesg host_mem_dmesg.txt -ftrace host_mem_ftrace.txt -f -cgphase resume
.PP .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" .SH "SEE ALSO"
dmesg(1) dmesg(1)
.PP .PP