diff options
author | Todd Brandt <todd.e.brandt@linux.intel.com> | 2019-05-14 13:53:58 -0400 |
---|---|---|
committer | Rafael J. Wysocki <rafael.j.wysocki@intel.com> | 2019-05-27 05:17:07 -0400 |
commit | 45dd0a42b90bed6cb8c63e7f88f62bf5662c2413 (patch) | |
tree | 110aff5e35931638b43719945f9d00726df7d0c6 | |
parent | 7673896a40693506db49c1e9f9c3a4a8c7e357c5 (diff) |
Update to pm-graph 5.4
bootgraph:
- dmesg log format has changed, update parser in two places
- fix prints in preparation for upgrade to python3
sleepgraph:
- fix prints in preparation for upgrade to python3
- add new trace events and kprobes to cover freeze more completely
- add new -ftop callgraph trace over suspend_devices_and_enter
- add -wifi option to check if a wifi connection is active
- add -skipkprobe option to suppress unwanted kprobes in dev mode
- add kernel params and sysinfo to the log output
- don't crash if /dev/mem is throwing IO errors, ignore FPDT and DMI
- fix kprobe length calculation when calls are recursive
- add several new kernel issue definitions for USB, ACPI, ATA, etc
- enable turbostat output to be read from stdout instead of from file
- add BIOS call data to the timeline from acpi_ps_execute_method kprobe
Signed-off-by: Todd Brandt <todd.e.brandt@linux.intel.com>
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
-rwxr-xr-x | tools/power/pm-graph/bootgraph.py | 8 | ||||
-rwxr-xr-x | tools/power/pm-graph/sleepgraph.py | 491 |
2 files changed, 347 insertions, 152 deletions
diff --git a/tools/power/pm-graph/bootgraph.py b/tools/power/pm-graph/bootgraph.py index 6dae57041537..d7f4bd152bf1 100755 --- a/tools/power/pm-graph/bootgraph.py +++ b/tools/power/pm-graph/bootgraph.py | |||
@@ -333,9 +333,9 @@ def parseKernelLog(): | |||
333 | if(not sysvals.stamp['kernel']): | 333 | if(not sysvals.stamp['kernel']): |
334 | sysvals.stamp['kernel'] = sysvals.kernelVersion(msg) | 334 | sysvals.stamp['kernel'] = sysvals.kernelVersion(msg) |
335 | continue | 335 | continue |
336 | m = re.match('.* setting system clock to (?P<t>.*) UTC.*', msg) | 336 | m = re.match('.* setting system clock to (?P<d>[0-9\-]*)[ A-Z](?P<t>[0-9:]*) UTC.*', msg) |
337 | if(m): | 337 | if(m): |
338 | bt = datetime.strptime(m.group('t'), '%Y-%m-%d %H:%M:%S') | 338 | bt = datetime.strptime(m.group('d')+' '+m.group('t'), '%Y-%m-%d %H:%M:%S') |
339 | bt = bt - timedelta(seconds=int(ktime)) | 339 | bt = bt - timedelta(seconds=int(ktime)) |
340 | data.boottime = bt.strftime('%Y-%m-%d_%H:%M:%S') | 340 | data.boottime = bt.strftime('%Y-%m-%d_%H:%M:%S') |
341 | sysvals.stamp['time'] = bt.strftime('%B %d %Y, %I:%M:%S %p') | 341 | sysvals.stamp['time'] = bt.strftime('%B %d %Y, %I:%M:%S %p') |
@@ -356,7 +356,7 @@ def parseKernelLog(): | |||
356 | data.newAction(phase, f, pid, start, ktime, int(r), int(t)) | 356 | data.newAction(phase, f, pid, start, ktime, int(r), int(t)) |
357 | del devtemp[f] | 357 | del devtemp[f] |
358 | continue | 358 | continue |
359 | if(re.match('^Freeing unused kernel memory.*', msg)): | 359 | if(re.match('^Freeing unused kernel .*', msg)): |
360 | data.tUserMode = ktime | 360 | data.tUserMode = ktime |
361 | data.dmesg['kernel']['end'] = ktime | 361 | data.dmesg['kernel']['end'] = ktime |
362 | data.dmesg['user']['start'] = ktime | 362 | data.dmesg['user']['start'] = ktime |
@@ -1016,7 +1016,7 @@ if __name__ == '__main__': | |||
1016 | updateKernelParams() | 1016 | updateKernelParams() |
1017 | elif cmd == 'flistall': | 1017 | elif cmd == 'flistall': |
1018 | for f in sysvals.getBootFtraceFilterFunctions(): | 1018 | for f in sysvals.getBootFtraceFilterFunctions(): |
1019 | print f | 1019 | print(f) |
1020 | elif cmd == 'checkbl': | 1020 | elif cmd == 'checkbl': |
1021 | sysvals.getBootLoader() | 1021 | sysvals.getBootLoader() |
1022 | pprint('Boot Loader: %s\n%s' % (sysvals.bootloader, sysvals.blexec)) | 1022 | pprint('Boot Loader: %s\n%s' % (sysvals.bootloader, sysvals.blexec)) |
diff --git a/tools/power/pm-graph/sleepgraph.py b/tools/power/pm-graph/sleepgraph.py index 41d28d63e7c9..ccd0f3917c51 100755 --- a/tools/power/pm-graph/sleepgraph.py +++ b/tools/power/pm-graph/sleepgraph.py | |||
@@ -17,9 +17,9 @@ | |||
17 | # | 17 | # |
18 | # Links: | 18 | # Links: |
19 | # Home Page | 19 | # Home Page |
20 | # https://01.org/suspendresume | 20 | # https://01.org/pm-graph |
21 | # Source repo | 21 | # Source repo |
22 | # git@github.com:01org/pm-graph | 22 | # git@github.com:intel/pm-graph |
23 | # | 23 | # |
24 | # Description: | 24 | # Description: |
25 | # This tool is designed to assist kernel and OS developers in optimizing | 25 | # This tool is designed to assist kernel and OS developers in optimizing |
@@ -32,6 +32,7 @@ | |||
32 | # viewed in firefox or chrome. | 32 | # viewed in firefox or chrome. |
33 | # | 33 | # |
34 | # The following kernel build options are required: | 34 | # The following kernel build options are required: |
35 | # CONFIG_DEVMEM=y | ||
35 | # CONFIG_PM_DEBUG=y | 36 | # CONFIG_PM_DEBUG=y |
36 | # CONFIG_PM_SLEEP_DEBUG=y | 37 | # CONFIG_PM_SLEEP_DEBUG=y |
37 | # CONFIG_FTRACE=y | 38 | # CONFIG_FTRACE=y |
@@ -75,7 +76,7 @@ def pprint(msg): | |||
75 | # store system values and test parameters | 76 | # store system values and test parameters |
76 | class SystemValues: | 77 | class SystemValues: |
77 | title = 'SleepGraph' | 78 | title = 'SleepGraph' |
78 | version = '5.3' | 79 | version = '5.4' |
79 | ansi = False | 80 | ansi = False |
80 | rs = 0 | 81 | rs = 0 |
81 | display = '' | 82 | display = '' |
@@ -83,8 +84,9 @@ class SystemValues: | |||
83 | sync = False | 84 | sync = False |
84 | verbose = False | 85 | verbose = False |
85 | testlog = True | 86 | testlog = True |
86 | dmesglog = False | 87 | dmesglog = True |
87 | ftracelog = False | 88 | ftracelog = False |
89 | tstat = False | ||
88 | mindevlen = 0.0 | 90 | mindevlen = 0.0 |
89 | mincglen = 0.0 | 91 | mincglen = 0.0 |
90 | cgphase = '' | 92 | cgphase = '' |
@@ -108,6 +110,8 @@ class SystemValues: | |||
108 | pmdpath = '/sys/power/pm_debug_messages' | 110 | pmdpath = '/sys/power/pm_debug_messages' |
109 | traceevents = [ | 111 | traceevents = [ |
110 | 'suspend_resume', | 112 | 'suspend_resume', |
113 | 'wakeup_source_activate', | ||
114 | 'wakeup_source_deactivate', | ||
111 | 'device_pm_callback_end', | 115 | 'device_pm_callback_end', |
112 | 'device_pm_callback_start' | 116 | 'device_pm_callback_start' |
113 | ] | 117 | ] |
@@ -139,6 +143,8 @@ class SystemValues: | |||
139 | x2delay = 0 | 143 | x2delay = 0 |
140 | skiphtml = False | 144 | skiphtml = False |
141 | usecallgraph = False | 145 | usecallgraph = False |
146 | ftopfunc = 'suspend_devices_and_enter' | ||
147 | ftop = False | ||
142 | usetraceevents = False | 148 | usetraceevents = False |
143 | usetracemarkers = True | 149 | usetracemarkers = True |
144 | usekprobes = True | 150 | usekprobes = True |
@@ -167,6 +173,13 @@ class SystemValues: | |||
167 | 'acpi_hibernation_leave': {}, | 173 | 'acpi_hibernation_leave': {}, |
168 | 'acpi_pm_freeze': {}, | 174 | 'acpi_pm_freeze': {}, |
169 | 'acpi_pm_thaw': {}, | 175 | 'acpi_pm_thaw': {}, |
176 | 'acpi_s2idle_end': {}, | ||
177 | 'acpi_s2idle_sync': {}, | ||
178 | 'acpi_s2idle_begin': {}, | ||
179 | 'acpi_s2idle_prepare': {}, | ||
180 | 'acpi_s2idle_wake': {}, | ||
181 | 'acpi_s2idle_wakeup': {}, | ||
182 | 'acpi_s2idle_restore': {}, | ||
170 | 'hibernate_preallocate_memory': {}, | 183 | 'hibernate_preallocate_memory': {}, |
171 | 'create_basic_memory_bitmaps': {}, | 184 | 'create_basic_memory_bitmaps': {}, |
172 | 'swsusp_write': {}, | 185 | 'swsusp_write': {}, |
@@ -203,7 +216,11 @@ class SystemValues: | |||
203 | 'rt_mutex_slowlock': {'ub': 1}, | 216 | 'rt_mutex_slowlock': {'ub': 1}, |
204 | # ACPI | 217 | # ACPI |
205 | 'acpi_resume_power_resources': {}, | 218 | 'acpi_resume_power_resources': {}, |
206 | 'acpi_ps_parse_aml': {}, | 219 | 'acpi_ps_execute_method': { 'args_x86_64': { |
220 | 'fullpath':'+0(+40(%di)):string', | ||
221 | }}, | ||
222 | # mei_me | ||
223 | 'mei_reset': {}, | ||
207 | # filesystem | 224 | # filesystem |
208 | 'ext4_sync_fs': {}, | 225 | 'ext4_sync_fs': {}, |
209 | # 80211 | 226 | # 80211 |
@@ -252,6 +269,7 @@ class SystemValues: | |||
252 | timeformat = '%.3f' | 269 | timeformat = '%.3f' |
253 | cmdline = '%s %s' % \ | 270 | cmdline = '%s %s' % \ |
254 | (os.path.basename(sys.argv[0]), ' '.join(sys.argv[1:])) | 271 | (os.path.basename(sys.argv[0]), ' '.join(sys.argv[1:])) |
272 | kparams = '' | ||
255 | sudouser = '' | 273 | sudouser = '' |
256 | def __init__(self): | 274 | def __init__(self): |
257 | self.archargs = 'args_'+platform.machine() | 275 | self.archargs = 'args_'+platform.machine() |
@@ -330,6 +348,7 @@ class SystemValues: | |||
330 | args['date'] = n.strftime('%y%m%d') | 348 | args['date'] = n.strftime('%y%m%d') |
331 | args['time'] = n.strftime('%H%M%S') | 349 | args['time'] = n.strftime('%H%M%S') |
332 | args['hostname'] = args['host'] = self.hostname | 350 | args['hostname'] = args['host'] = self.hostname |
351 | args['mode'] = self.suspendmode | ||
333 | return value.format(**args) | 352 | return value.format(**args) |
334 | def setOutputFile(self): | 353 | def setOutputFile(self): |
335 | if self.dmesgfile != '': | 354 | if self.dmesgfile != '': |
@@ -341,7 +360,7 @@ class SystemValues: | |||
341 | if(m): | 360 | if(m): |
342 | self.htmlfile = m.group('name')+'.html' | 361 | self.htmlfile = m.group('name')+'.html' |
343 | def systemInfo(self, info): | 362 | def systemInfo(self, info): |
344 | p = c = m = b = '' | 363 | p = m = '' |
345 | if 'baseboard-manufacturer' in info: | 364 | if 'baseboard-manufacturer' in info: |
346 | m = info['baseboard-manufacturer'] | 365 | m = info['baseboard-manufacturer'] |
347 | elif 'system-manufacturer' in info: | 366 | elif 'system-manufacturer' in info: |
@@ -352,12 +371,17 @@ class SystemValues: | |||
352 | p = info['baseboard-product-name'] | 371 | p = info['baseboard-product-name'] |
353 | if m[:5].lower() == 'intel' and 'baseboard-product-name' in info: | 372 | if m[:5].lower() == 'intel' and 'baseboard-product-name' in info: |
354 | p = info['baseboard-product-name'] | 373 | p = info['baseboard-product-name'] |
355 | if 'processor-version' in info: | 374 | c = info['processor-version'] if 'processor-version' in info else '' |
356 | c = info['processor-version'] | 375 | b = info['bios-version'] if 'bios-version' in info else '' |
357 | if 'bios-version' in info: | 376 | r = info['bios-release-date'] if 'bios-release-date' in info else '' |
358 | b = info['bios-version'] | 377 | self.sysstamp = '# sysinfo | man:%s | plat:%s | cpu:%s | bios:%s | biosdate:%s | numcpu:%d | memsz:%d | memfr:%d' % \ |
359 | self.sysstamp = '# sysinfo | man:%s | plat:%s | cpu:%s | bios:%s | numcpu:%d | memsz:%d | memfr:%d' % \ | 378 | (m, p, c, b, r, self.cpucount, self.memtotal, self.memfree) |
360 | (m, p, c, b, self.cpucount, self.memtotal, self.memfree) | 379 | try: |
380 | kcmd = open('/proc/cmdline', 'r').read().strip() | ||
381 | except: | ||
382 | kcmd = '' | ||
383 | if kcmd: | ||
384 | self.sysstamp += '\n# kparams | %s' % kcmd | ||
361 | def printSystemInfo(self, fatal=False): | 385 | def printSystemInfo(self, fatal=False): |
362 | self.rootCheck(True) | 386 | self.rootCheck(True) |
363 | out = dmidecode(self.mempath, fatal) | 387 | out = dmidecode(self.mempath, fatal) |
@@ -365,10 +389,10 @@ class SystemValues: | |||
365 | return | 389 | return |
366 | fmt = '%-24s: %s' | 390 | fmt = '%-24s: %s' |
367 | for name in sorted(out): | 391 | for name in sorted(out): |
368 | print fmt % (name, out[name]) | 392 | print(fmt % (name, out[name])) |
369 | print fmt % ('cpucount', ('%d' % self.cpucount)) | 393 | print(fmt % ('cpucount', ('%d' % self.cpucount))) |
370 | print fmt % ('memtotal', ('%d kB' % self.memtotal)) | 394 | print(fmt % ('memtotal', ('%d kB' % self.memtotal))) |
371 | print fmt % ('memfree', ('%d kB' % self.memfree)) | 395 | print(fmt % ('memfree', ('%d kB' % self.memfree))) |
372 | def cpuInfo(self): | 396 | def cpuInfo(self): |
373 | self.cpucount = 0 | 397 | self.cpucount = 0 |
374 | fp = open('/proc/cpuinfo', 'r') | 398 | fp = open('/proc/cpuinfo', 'r') |
@@ -388,7 +412,7 @@ class SystemValues: | |||
388 | def initTestOutput(self, name): | 412 | def initTestOutput(self, name): |
389 | self.prefix = self.hostname | 413 | self.prefix = self.hostname |
390 | v = open('/proc/version', 'r').read().strip() | 414 | v = open('/proc/version', 'r').read().strip() |
391 | kver = string.split(v)[2] | 415 | kver = v.split()[2] |
392 | fmt = name+'-%m%d%y-%H%M%S' | 416 | fmt = name+'-%m%d%y-%H%M%S' |
393 | testtime = datetime.now().strftime(fmt) | 417 | testtime = datetime.now().strftime(fmt) |
394 | self.teststamp = \ | 418 | self.teststamp = \ |
@@ -403,7 +427,7 @@ class SystemValues: | |||
403 | self.htmlfile = \ | 427 | self.htmlfile = \ |
404 | self.testdir+'/'+self.prefix+'_'+self.suspendmode+'.html' | 428 | self.testdir+'/'+self.prefix+'_'+self.suspendmode+'.html' |
405 | if not os.path.isdir(self.testdir): | 429 | if not os.path.isdir(self.testdir): |
406 | os.mkdir(self.testdir) | 430 | os.makedirs(self.testdir) |
407 | def getValueList(self, value): | 431 | def getValueList(self, value): |
408 | out = [] | 432 | out = [] |
409 | for i in value.split(','): | 433 | for i in value.split(','): |
@@ -414,6 +438,12 @@ class SystemValues: | |||
414 | self.devicefilter = self.getValueList(value) | 438 | self.devicefilter = self.getValueList(value) |
415 | def setCallgraphFilter(self, value): | 439 | def setCallgraphFilter(self, value): |
416 | self.cgfilter = self.getValueList(value) | 440 | self.cgfilter = self.getValueList(value) |
441 | def skipKprobes(self, value): | ||
442 | for k in self.getValueList(value): | ||
443 | if k in self.tracefuncs: | ||
444 | del self.tracefuncs[k] | ||
445 | if k in self.dev_tracefuncs: | ||
446 | del self.dev_tracefuncs[k] | ||
417 | def setCallgraphBlacklist(self, file): | 447 | def setCallgraphBlacklist(self, file): |
418 | self.cgblacklist = self.listFromFile(file) | 448 | self.cgblacklist = self.listFromFile(file) |
419 | def rtcWakeAlarmOn(self): | 449 | def rtcWakeAlarmOn(self): |
@@ -483,9 +513,9 @@ class SystemValues: | |||
483 | if 'func' in self.tracefuncs[i]: | 513 | if 'func' in self.tracefuncs[i]: |
484 | i = self.tracefuncs[i]['func'] | 514 | i = self.tracefuncs[i]['func'] |
485 | if i in master: | 515 | if i in master: |
486 | print i | 516 | print(i) |
487 | else: | 517 | else: |
488 | print self.colorText(i) | 518 | print(self.colorText(i)) |
489 | def setFtraceFilterFunctions(self, list): | 519 | def setFtraceFilterFunctions(self, list): |
490 | master = self.listFromFile(self.tpath+'available_filter_functions') | 520 | master = self.listFromFile(self.tpath+'available_filter_functions') |
491 | flist = '' | 521 | flist = '' |
@@ -728,7 +758,10 @@ class SystemValues: | |||
728 | cf.append(self.tracefuncs[fn]['func']) | 758 | cf.append(self.tracefuncs[fn]['func']) |
729 | else: | 759 | else: |
730 | cf.append(fn) | 760 | cf.append(fn) |
731 | self.setFtraceFilterFunctions(cf) | 761 | if self.ftop: |
762 | self.setFtraceFilterFunctions([self.ftopfunc]) | ||
763 | else: | ||
764 | self.setFtraceFilterFunctions(cf) | ||
732 | # initialize the kprobe trace | 765 | # initialize the kprobe trace |
733 | elif self.usekprobes: | 766 | elif self.usekprobes: |
734 | for name in self.tracefuncs: | 767 | for name in self.tracefuncs: |
@@ -788,6 +821,14 @@ class SystemValues: | |||
788 | if 'bat' in test: | 821 | if 'bat' in test: |
789 | (a1, c1), (a2, c2) = test['bat'] | 822 | (a1, c1), (a2, c2) = test['bat'] |
790 | fp.write('# battery %s %d %s %d\n' % (a1, c1, a2, c2)) | 823 | fp.write('# battery %s %d %s %d\n' % (a1, c1, a2, c2)) |
824 | if 'wifi' in test: | ||
825 | wstr = [] | ||
826 | for wifi in test['wifi']: | ||
827 | tmp = [] | ||
828 | for key in sorted(wifi): | ||
829 | tmp.append('%s:%s' % (key, wifi[key])) | ||
830 | wstr.append('|'.join(tmp)) | ||
831 | fp.write('# wifi %s\n' % (','.join(wstr))) | ||
791 | if test['error'] or len(testdata) > 1: | 832 | if test['error'] or len(testdata) > 1: |
792 | fp.write('# enter_sleep_error %s\n' % test['error']) | 833 | fp.write('# enter_sleep_error %s\n' % test['error']) |
793 | return fp | 834 | return fp |
@@ -852,26 +893,22 @@ class SystemValues: | |||
852 | return '' | 893 | return '' |
853 | return base64.b64encode(out.encode('zlib')) | 894 | return base64.b64encode(out.encode('zlib')) |
854 | def haveTurbostat(self): | 895 | def haveTurbostat(self): |
896 | if not self.tstat: | ||
897 | return False | ||
855 | cmd = self.getExec('turbostat') | 898 | cmd = self.getExec('turbostat') |
856 | if not cmd: | 899 | if not cmd: |
857 | return False | 900 | return False |
858 | fp = Popen([cmd, '-v'], stdout=PIPE, stderr=PIPE).stderr | 901 | fp = Popen([cmd, '-v'], stdout=PIPE, stderr=PIPE).stderr |
859 | out = fp.read().strip() | 902 | out = fp.read().strip() |
860 | fp.close() | 903 | fp.close() |
861 | return re.match('turbostat version [0-8.]* .*', out) | 904 | return re.match('turbostat version [0-9\.]* .*', out) |
862 | def turbostat(self): | 905 | def turbostat(self): |
863 | cmd = self.getExec('turbostat') | 906 | cmd = self.getExec('turbostat') |
864 | if not cmd: | 907 | if not cmd: |
865 | return 'missing turbostat executable' | 908 | return 'missing turbostat executable' |
866 | outfile = '/tmp/pm-graph-turbostat.txt' | ||
867 | res = call('%s -o %s -q -S echo freeze > %s' % \ | ||
868 | (cmd, outfile, self.powerfile), shell=True) | ||
869 | if res != 0: | ||
870 | return 'turbosat returned %d' % res | ||
871 | if not os.path.exists(outfile): | ||
872 | return 'turbostat output missing' | ||
873 | fp = open(outfile, 'r') | ||
874 | text = [] | 909 | text = [] |
910 | fullcmd = '%s -q -S echo freeze > %s' % (cmd, self.powerfile) | ||
911 | fp = Popen(['sh', '-c', fullcmd], stdout=PIPE, stderr=PIPE).stderr | ||
875 | for line in fp: | 912 | for line in fp: |
876 | if re.match('[0-9.]* sec', line): | 913 | if re.match('[0-9.]* sec', line): |
877 | continue | 914 | continue |
@@ -888,6 +925,60 @@ class SystemValues: | |||
888 | values.append(line[idx]) | 925 | values.append(line[idx]) |
889 | out.append('%s=%s' % (key, ','.join(values))) | 926 | out.append('%s=%s' % (key, ','.join(values))) |
890 | return '|'.join(out) | 927 | return '|'.join(out) |
928 | def checkWifi(self): | ||
929 | out = dict() | ||
930 | iwcmd, ifcmd = self.getExec('iwconfig'), self.getExec('ifconfig') | ||
931 | if not iwcmd or not ifcmd: | ||
932 | return out | ||
933 | fp = Popen(iwcmd, stdout=PIPE, stderr=PIPE).stdout | ||
934 | for line in fp: | ||
935 | m = re.match('(?P<dev>\S*) .* ESSID:(?P<ess>\S*)', line) | ||
936 | if not m: | ||
937 | continue | ||
938 | out['device'] = m.group('dev') | ||
939 | if '"' in m.group('ess'): | ||
940 | out['essid'] = m.group('ess').strip('"') | ||
941 | break | ||
942 | fp.close() | ||
943 | if 'device' in out: | ||
944 | fp = Popen([ifcmd, out['device']], stdout=PIPE, stderr=PIPE).stdout | ||
945 | for line in fp: | ||
946 | m = re.match('.* inet (?P<ip>[0-9\.]*)', line) | ||
947 | if m: | ||
948 | out['ip'] = m.group('ip') | ||
949 | break | ||
950 | fp.close() | ||
951 | return out | ||
952 | def errorSummary(self, errinfo, msg): | ||
953 | found = False | ||
954 | for entry in errinfo: | ||
955 | if re.match(entry['match'], msg): | ||
956 | entry['count'] += 1 | ||
957 | if self.hostname not in entry['urls']: | ||
958 | entry['urls'][self.hostname] = [self.htmlfile] | ||
959 | elif self.htmlfile not in entry['urls'][self.hostname]: | ||
960 | entry['urls'][self.hostname].append(self.htmlfile) | ||
961 | found = True | ||
962 | break | ||
963 | if found: | ||
964 | return | ||
965 | arr = msg.split() | ||
966 | for j in range(len(arr)): | ||
967 | if re.match('^[0-9,\-\.]*$', arr[j]): | ||
968 | arr[j] = '[0-9,\-\.]*' | ||
969 | else: | ||
970 | arr[j] = arr[j]\ | ||
971 | .replace('\\', '\\\\').replace(']', '\]').replace('[', '\[')\ | ||
972 | .replace('.', '\.').replace('+', '\+').replace('*', '\*')\ | ||
973 | .replace('(', '\(').replace(')', '\)') | ||
974 | mstr = ' '.join(arr) | ||
975 | entry = { | ||
976 | 'line': msg, | ||
977 | 'match': mstr, | ||
978 | 'count': 1, | ||
979 | 'urls': {self.hostname: [self.htmlfile]} | ||
980 | } | ||
981 | errinfo.append(entry) | ||
891 | 982 | ||
892 | sysvals = SystemValues() | 983 | sysvals = SystemValues() |
893 | switchvalues = ['enable', 'disable', 'on', 'off', 'true', 'false', '1', '0'] | 984 | switchvalues = ['enable', 'disable', 'on', 'off', 'true', 'false', '1', '0'] |
@@ -982,7 +1073,14 @@ class Data: | |||
982 | 'ERROR' : '.*ERROR.*', | 1073 | 'ERROR' : '.*ERROR.*', |
983 | 'WARNING' : '.*WARNING.*', | 1074 | 'WARNING' : '.*WARNING.*', |
984 | 'IRQ' : '.*genirq: .*', | 1075 | 'IRQ' : '.*genirq: .*', |
985 | 'TASKFAIL': '.*Freezing of tasks failed.*', | 1076 | 'TASKFAIL': '.*Freezing of tasks *.*', |
1077 | 'ACPI' : '.*ACPI *(?P<b>[A-Za-z]*) *Error[: ].*', | ||
1078 | 'DEVFAIL' : '.* failed to (?P<b>[a-z]*) async: .*', | ||
1079 | 'DISKFULL': '.*No space left on device.*', | ||
1080 | 'USBERR' : '.*usb .*device .*, error [0-9-]*', | ||
1081 | 'ATAERR' : ' *ata[0-9\.]*: .*failed.*', | ||
1082 | 'MEIERR' : ' *mei.*: .*failed.*', | ||
1083 | 'TPMERR' : '(?i) *tpm *tpm[0-9]*: .*error.*', | ||
986 | } | 1084 | } |
987 | def __init__(self, num): | 1085 | def __init__(self, num): |
988 | idchar = 'abcdefghij' | 1086 | idchar = 'abcdefghij' |
@@ -1000,6 +1098,7 @@ class Data: | |||
1000 | self.outfile = '' | 1098 | self.outfile = '' |
1001 | self.kerror = False | 1099 | self.kerror = False |
1002 | self.battery = 0 | 1100 | self.battery = 0 |
1101 | self.wifi = 0 | ||
1003 | self.turbostat = 0 | 1102 | self.turbostat = 0 |
1004 | self.mcelog = 0 | 1103 | self.mcelog = 0 |
1005 | self.enterfail = '' | 1104 | self.enterfail = '' |
@@ -1036,35 +1135,21 @@ class Data: | |||
1036 | if len(plist) < 1: | 1135 | if len(plist) < 1: |
1037 | return '' | 1136 | return '' |
1038 | return plist[-1] | 1137 | return plist[-1] |
1039 | def errorSummary(self, errinfo, msg): | 1138 | def turbostatInfo(self): |
1040 | found = False | 1139 | tp = TestProps() |
1041 | for entry in errinfo: | 1140 | out = {'syslpi':'N/A','pkgpc10':'N/A'} |
1042 | if re.match(entry['match'], msg): | 1141 | for line in self.dmesgtext: |
1043 | entry['count'] += 1 | 1142 | m = re.match(tp.tstatfmt, line) |
1044 | if sysvals.hostname not in entry['urls']: | 1143 | if not m: |
1045 | entry['urls'][sysvals.hostname] = sysvals.htmlfile | 1144 | continue |
1046 | found = True | 1145 | for i in m.group('t').split('|'): |
1047 | break | 1146 | if 'SYS%LPI' in i: |
1048 | if found: | 1147 | out['syslpi'] = i.split('=')[-1]+'%' |
1049 | return | 1148 | elif 'pc10' in i: |
1050 | arr = msg.split() | 1149 | out['pkgpc10'] = i.split('=')[-1]+'%' |
1051 | for j in range(len(arr)): | 1150 | break |
1052 | if re.match('^[0-9\-\.]*$', arr[j]): | 1151 | return out |
1053 | arr[j] = '[0-9\-\.]*' | 1152 | def extractErrorInfo(self): |
1054 | else: | ||
1055 | arr[j] = arr[j]\ | ||
1056 | .replace(']', '\]').replace('[', '\[').replace('.', '\.')\ | ||
1057 | .replace('+', '\+').replace('*', '\*').replace('(', '\(')\ | ||
1058 | .replace(')', '\)') | ||
1059 | mstr = ' '.join(arr) | ||
1060 | entry = { | ||
1061 | 'line': msg, | ||
1062 | 'match': mstr, | ||
1063 | 'count': 1, | ||
1064 | 'urls': {sysvals.hostname: sysvals.htmlfile} | ||
1065 | } | ||
1066 | errinfo.append(entry) | ||
1067 | def extractErrorInfo(self, issues=0): | ||
1068 | lf = self.dmesgtext | 1153 | lf = self.dmesgtext |
1069 | if len(self.dmesgtext) < 1 and sysvals.dmesgfile: | 1154 | if len(self.dmesgtext) < 1 and sysvals.dmesgfile: |
1070 | lf = sysvals.openlog(sysvals.dmesgfile, 'r') | 1155 | lf = sysvals.openlog(sysvals.dmesgfile, 'r') |
@@ -1082,19 +1167,19 @@ class Data: | |||
1082 | msg = m.group('msg') | 1167 | msg = m.group('msg') |
1083 | for err in self.errlist: | 1168 | for err in self.errlist: |
1084 | if re.match(self.errlist[err], msg): | 1169 | if re.match(self.errlist[err], msg): |
1085 | list.append((err, dir, t, i, i)) | 1170 | list.append((msg, err, dir, t, i, i)) |
1086 | self.kerror = True | 1171 | self.kerror = True |
1087 | if not isinstance(issues, int): | ||
1088 | self.errorSummary(issues, msg) | ||
1089 | break | 1172 | break |
1090 | for e in list: | 1173 | msglist = [] |
1091 | type, dir, t, idx1, idx2 = e | 1174 | for msg, type, dir, t, idx1, idx2 in list: |
1175 | msglist.append(msg) | ||
1092 | sysvals.vprint('kernel %s found in %s at %f' % (type, dir, t)) | 1176 | sysvals.vprint('kernel %s found in %s at %f' % (type, dir, t)) |
1093 | self.errorinfo[dir].append((type, t, idx1, idx2)) | 1177 | self.errorinfo[dir].append((type, t, idx1, idx2)) |
1094 | if self.kerror: | 1178 | if self.kerror: |
1095 | sysvals.dmesglog = True | 1179 | sysvals.dmesglog = True |
1096 | if len(self.dmesgtext) < 1 and sysvals.dmesgfile: | 1180 | if len(self.dmesgtext) < 1 and sysvals.dmesgfile: |
1097 | lf.close() | 1181 | lf.close() |
1182 | return msglist | ||
1098 | def setStart(self, time): | 1183 | def setStart(self, time): |
1099 | self.start = time | 1184 | self.start = time |
1100 | def setEnd(self, time): | 1185 | def setEnd(self, time): |
@@ -2147,7 +2232,7 @@ class FTraceCallGraph: | |||
2147 | if(data.dmesg[p]['start'] <= self.start and | 2232 | if(data.dmesg[p]['start'] <= self.start and |
2148 | self.start <= data.dmesg[p]['end']): | 2233 | self.start <= data.dmesg[p]['end']): |
2149 | list = data.dmesg[p]['list'] | 2234 | list = data.dmesg[p]['list'] |
2150 | for devname in list: | 2235 | for devname in sorted(list, key=lambda k:list[k]['start']): |
2151 | dev = list[devname] | 2236 | dev = list[devname] |
2152 | if(pid == dev['pid'] and | 2237 | if(pid == dev['pid'] and |
2153 | self.start <= dev['start'] and | 2238 | self.start <= dev['start'] and |
@@ -2452,6 +2537,7 @@ class TestProps: | |||
2452 | '(?P<H>[0-9]{2})(?P<M>[0-9]{2})(?P<S>[0-9]{2})'+\ | 2537 | '(?P<H>[0-9]{2})(?P<M>[0-9]{2})(?P<S>[0-9]{2})'+\ |
2453 | ' (?P<host>.*) (?P<mode>.*) (?P<kernel>.*)$' | 2538 | ' (?P<host>.*) (?P<mode>.*) (?P<kernel>.*)$' |
2454 | batteryfmt = '^# battery (?P<a1>\w*) (?P<c1>\d*) (?P<a2>\w*) (?P<c2>\d*)' | 2539 | batteryfmt = '^# battery (?P<a1>\w*) (?P<c1>\d*) (?P<a2>\w*) (?P<c2>\d*)' |
2540 | wififmt = '^# wifi (?P<w>.*)' | ||
2455 | tstatfmt = '^# turbostat (?P<t>\S*)' | 2541 | tstatfmt = '^# turbostat (?P<t>\S*)' |
2456 | mcelogfmt = '^# mcelog (?P<m>\S*)' | 2542 | mcelogfmt = '^# mcelog (?P<m>\S*)' |
2457 | testerrfmt = '^# enter_sleep_error (?P<e>.*)' | 2543 | testerrfmt = '^# enter_sleep_error (?P<e>.*)' |
@@ -2479,6 +2565,7 @@ class TestProps: | |||
2479 | self.mcelog = [] | 2565 | self.mcelog = [] |
2480 | self.turbostat = [] | 2566 | self.turbostat = [] |
2481 | self.battery = [] | 2567 | self.battery = [] |
2568 | self.wifi = [] | ||
2482 | self.fwdata = [] | 2569 | self.fwdata = [] |
2483 | self.ftrace_line_fmt = self.ftrace_line_fmt_nop | 2570 | self.ftrace_line_fmt = self.ftrace_line_fmt_nop |
2484 | self.cgformat = False | 2571 | self.cgformat = False |
@@ -2505,6 +2592,9 @@ class TestProps: | |||
2505 | elif re.match(self.sysinfofmt, line): | 2592 | elif re.match(self.sysinfofmt, line): |
2506 | self.sysinfo = line | 2593 | self.sysinfo = line |
2507 | return True | 2594 | return True |
2595 | elif re.match(self.kparamsfmt, line): | ||
2596 | self.kparams = line | ||
2597 | return True | ||
2508 | elif re.match(self.cmdlinefmt, line): | 2598 | elif re.match(self.cmdlinefmt, line): |
2509 | self.cmdline = line | 2599 | self.cmdline = line |
2510 | return True | 2600 | return True |
@@ -2517,6 +2607,9 @@ class TestProps: | |||
2517 | elif re.match(self.batteryfmt, line): | 2607 | elif re.match(self.batteryfmt, line): |
2518 | self.battery.append(line) | 2608 | self.battery.append(line) |
2519 | return True | 2609 | return True |
2610 | elif re.match(self.wififmt, line): | ||
2611 | self.wifi.append(line) | ||
2612 | return True | ||
2520 | elif re.match(self.testerrfmt, line): | 2613 | elif re.match(self.testerrfmt, line): |
2521 | self.testerror.append(line) | 2614 | self.testerror.append(line) |
2522 | return True | 2615 | return True |
@@ -2586,6 +2679,11 @@ class TestProps: | |||
2586 | m = re.match(self.batteryfmt, self.battery[data.testnumber]) | 2679 | m = re.match(self.batteryfmt, self.battery[data.testnumber]) |
2587 | if m: | 2680 | if m: |
2588 | data.battery = m.groups() | 2681 | data.battery = m.groups() |
2682 | # wifi data | ||
2683 | if len(self.wifi) > data.testnumber: | ||
2684 | m = re.match(self.wififmt, self.wifi[data.testnumber]) | ||
2685 | if m: | ||
2686 | data.wifi = m.group('w') | ||
2589 | # sleep mode enter errors | 2687 | # sleep mode enter errors |
2590 | if len(self.testerror) > data.testnumber: | 2688 | if len(self.testerror) > data.testnumber: |
2591 | m = re.match(self.testerrfmt, self.testerror[data.testnumber]) | 2689 | m = re.match(self.testerrfmt, self.testerror[data.testnumber]) |
@@ -2655,9 +2753,9 @@ class ProcessMonitor: | |||
2655 | # Quickly determine if the ftrace log has all of the trace events, | 2753 | # Quickly determine if the ftrace log has all of the trace events, |
2656 | # markers, and/or kprobes required for primary parsing. | 2754 | # markers, and/or kprobes required for primary parsing. |
2657 | def doesTraceLogHaveTraceEvents(): | 2755 | def doesTraceLogHaveTraceEvents(): |
2658 | kpcheck = ['_cal: (', '_cpu_down()'] | 2756 | kpcheck = ['_cal: (', '_ret: ('] |
2659 | techeck = ['suspend_resume', 'device_pm_callback'] | 2757 | techeck = ['suspend_resume', 'device_pm_callback'] |
2660 | tmcheck = ['tracing_mark_write'] | 2758 | tmcheck = ['SUSPEND START', 'RESUME COMPLETE'] |
2661 | sysvals.usekprobes = False | 2759 | sysvals.usekprobes = False |
2662 | fp = sysvals.openlog(sysvals.ftracefile, 'r') | 2760 | fp = sysvals.openlog(sysvals.ftracefile, 'r') |
2663 | for line in fp: | 2761 | for line in fp: |
@@ -3042,7 +3140,7 @@ def parseTraceLog(live=False): | |||
3042 | tp.ktemp[key].append({ | 3140 | tp.ktemp[key].append({ |
3043 | 'pid': pid, | 3141 | 'pid': pid, |
3044 | 'begin': t.time, | 3142 | 'begin': t.time, |
3045 | 'end': t.time, | 3143 | 'end': -1, |
3046 | 'name': displayname, | 3144 | 'name': displayname, |
3047 | 'cdata': kprobedata, | 3145 | 'cdata': kprobedata, |
3048 | 'proc': m_proc, | 3146 | 'proc': m_proc, |
@@ -3053,12 +3151,11 @@ def parseTraceLog(live=False): | |||
3053 | elif(t.freturn): | 3151 | elif(t.freturn): |
3054 | if(key not in tp.ktemp) or len(tp.ktemp[key]) < 1: | 3152 | if(key not in tp.ktemp) or len(tp.ktemp[key]) < 1: |
3055 | continue | 3153 | continue |
3056 | e = tp.ktemp[key][-1] | 3154 | e = next((x for x in reversed(tp.ktemp[key]) if x['end'] < 0), 0) |
3057 | if e['begin'] < 0.0 or t.time - e['begin'] < 0.000001: | 3155 | if not e: |
3058 | tp.ktemp[key].pop() | 3156 | continue |
3059 | else: | 3157 | e['end'] = t.time |
3060 | e['end'] = t.time | 3158 | e['rdata'] = kprobedata |
3061 | e['rdata'] = kprobedata | ||
3062 | # end of kernel resume | 3159 | # end of kernel resume |
3063 | if(phase != 'suspend_prepare' and kprobename in krescalls): | 3160 | if(phase != 'suspend_prepare' and kprobename in krescalls): |
3064 | if phase in data.dmesg: | 3161 | if phase in data.dmesg: |
@@ -3080,8 +3177,10 @@ def parseTraceLog(live=False): | |||
3080 | if(res == -1): | 3177 | if(res == -1): |
3081 | testrun.ftemp[key][-1].addLine(t) | 3178 | testrun.ftemp[key][-1].addLine(t) |
3082 | tf.close() | 3179 | tf.close() |
3180 | if len(testdata) < 1: | ||
3181 | sysvals.vprint('WARNING: ftrace start marker is missing') | ||
3083 | if data and not data.devicegroups: | 3182 | if data and not data.devicegroups: |
3084 | sysvals.vprint('WARNING: end marker is missing') | 3183 | sysvals.vprint('WARNING: ftrace end marker is missing') |
3085 | data.handleEndMarker(t.time) | 3184 | data.handleEndMarker(t.time) |
3086 | 3185 | ||
3087 | if sysvals.suspendmode == 'command': | 3186 | if sysvals.suspendmode == 'command': |
@@ -3130,9 +3229,11 @@ def parseTraceLog(live=False): | |||
3130 | name, pid = key | 3229 | name, pid = key |
3131 | if name not in sysvals.tracefuncs: | 3230 | if name not in sysvals.tracefuncs: |
3132 | continue | 3231 | continue |
3232 | if pid not in data.devpids: | ||
3233 | data.devpids.append(pid) | ||
3133 | for e in tp.ktemp[key]: | 3234 | for e in tp.ktemp[key]: |
3134 | kb, ke = e['begin'], e['end'] | 3235 | kb, ke = e['begin'], e['end'] |
3135 | if kb == ke or tlb > kb or tle <= kb: | 3236 | if ke - kb < 0.000001 or tlb > kb or tle <= kb: |
3136 | continue | 3237 | continue |
3137 | color = sysvals.kprobeColor(name) | 3238 | color = sysvals.kprobeColor(name) |
3138 | data.newActionGlobal(e['name'], kb, ke, pid, color) | 3239 | data.newActionGlobal(e['name'], kb, ke, pid, color) |
@@ -3144,7 +3245,7 @@ def parseTraceLog(live=False): | |||
3144 | continue | 3245 | continue |
3145 | for e in tp.ktemp[key]: | 3246 | for e in tp.ktemp[key]: |
3146 | kb, ke = e['begin'], e['end'] | 3247 | kb, ke = e['begin'], e['end'] |
3147 | if kb == ke or tlb > kb or tle <= kb: | 3248 | if ke - kb < 0.000001 or tlb > kb or tle <= kb: |
3148 | continue | 3249 | continue |
3149 | data.addDeviceFunctionCall(e['name'], name, e['proc'], pid, kb, | 3250 | data.addDeviceFunctionCall(e['name'], name, e['proc'], pid, kb, |
3150 | ke, e['cdata'], e['rdata']) | 3251 | ke, e['cdata'], e['rdata']) |
@@ -3168,7 +3269,7 @@ def parseTraceLog(live=False): | |||
3168 | if not devname: | 3269 | if not devname: |
3169 | sortkey = '%f%f%d' % (cg.start, cg.end, pid) | 3270 | sortkey = '%f%f%d' % (cg.start, cg.end, pid) |
3170 | sortlist[sortkey] = cg | 3271 | sortlist[sortkey] = cg |
3171 | elif len(cg.list) > 1000000: | 3272 | elif len(cg.list) > 1000000 and cg.name != sysvals.ftopfunc: |
3172 | sysvals.vprint('WARNING: the callgraph for %s is massive (%d lines)' %\ | 3273 | sysvals.vprint('WARNING: the callgraph for %s is massive (%d lines)' %\ |
3173 | (devname, len(cg.list))) | 3274 | (devname, len(cg.list))) |
3174 | # create blocks for orphan cg data | 3275 | # create blocks for orphan cg data |
@@ -3275,7 +3376,7 @@ def loadKernelLog(): | |||
3275 | if data: | 3376 | if data: |
3276 | testruns.append(data) | 3377 | testruns.append(data) |
3277 | if len(testruns) < 1: | 3378 | if len(testruns) < 1: |
3278 | pprint('ERROR: dmesg log has no suspend/resume data: %s' \ | 3379 | doError('dmesg log has no suspend/resume data: %s' \ |
3279 | % sysvals.dmesgfile) | 3380 | % sysvals.dmesgfile) |
3280 | 3381 | ||
3281 | # fix lines with same timestamp/function with the call and return swapped | 3382 | # fix lines with same timestamp/function with the call and return swapped |
@@ -3614,6 +3715,8 @@ def addCallgraphs(sv, hf, data): | |||
3614 | name += ' '+p | 3715 | name += ' '+p |
3615 | if('ftrace' in dev): | 3716 | if('ftrace' in dev): |
3616 | cg = dev['ftrace'] | 3717 | cg = dev['ftrace'] |
3718 | if cg.name == sv.ftopfunc: | ||
3719 | name = 'top level suspend/resume call' | ||
3617 | num = callgraphHTML(sv, hf, num, cg, | 3720 | num = callgraphHTML(sv, hf, num, cg, |
3618 | name, color, dev['id']) | 3721 | name, color, dev['id']) |
3619 | if('ftraces' in dev): | 3722 | if('ftraces' in dev): |
@@ -3653,9 +3756,10 @@ def createHTMLSummarySimple(testruns, htmlfile, title): | |||
3653 | 3756 | ||
3654 | # extract the test data into list | 3757 | # extract the test data into list |
3655 | list = dict() | 3758 | list = dict() |
3656 | tAvg, tMin, tMax, tMed = [0.0, 0.0], [0.0, 0.0], [0.0, 0.0], [[], []] | 3759 | tAvg, tMin, tMax, tMed = [0.0, 0.0], [0.0, 0.0], [0.0, 0.0], [dict(), dict()] |
3657 | iMin, iMed, iMax = [0, 0], [0, 0], [0, 0] | 3760 | iMin, iMed, iMax = [0, 0], [0, 0], [0, 0] |
3658 | num = 0 | 3761 | num = 0 |
3762 | useturbo = False | ||
3659 | lastmode = '' | 3763 | lastmode = '' |
3660 | cnt = dict() | 3764 | cnt = dict() |
3661 | for data in sorted(testruns, key=lambda v:(v['mode'], v['host'], v['kernel'], v['time'])): | 3765 | for data in sorted(testruns, key=lambda v:(v['mode'], v['host'], v['kernel'], v['time'])): |
@@ -3666,20 +3770,25 @@ def createHTMLSummarySimple(testruns, htmlfile, title): | |||
3666 | for i in range(2): | 3770 | for i in range(2): |
3667 | s = sorted(tMed[i]) | 3771 | s = sorted(tMed[i]) |
3668 | list[lastmode]['med'][i] = s[int(len(s)/2)] | 3772 | list[lastmode]['med'][i] = s[int(len(s)/2)] |
3669 | iMed[i] = tMed[i].index(list[lastmode]['med'][i]) | 3773 | iMed[i] = tMed[i][list[lastmode]['med'][i]] |
3670 | list[lastmode]['avg'] = [tAvg[0] / num, tAvg[1] / num] | 3774 | list[lastmode]['avg'] = [tAvg[0] / num, tAvg[1] / num] |
3671 | list[lastmode]['min'] = tMin | 3775 | list[lastmode]['min'] = tMin |
3672 | list[lastmode]['max'] = tMax | 3776 | list[lastmode]['max'] = tMax |
3673 | list[lastmode]['idx'] = (iMin, iMed, iMax) | 3777 | list[lastmode]['idx'] = (iMin, iMed, iMax) |
3674 | tAvg, tMin, tMax, tMed = [0.0, 0.0], [0.0, 0.0], [0.0, 0.0], [[], []] | 3778 | tAvg, tMin, tMax, tMed = [0.0, 0.0], [0.0, 0.0], [0.0, 0.0], [dict(), dict()] |
3675 | iMin, iMed, iMax = [0, 0], [0, 0], [0, 0] | 3779 | iMin, iMed, iMax = [0, 0], [0, 0], [0, 0] |
3676 | num = 0 | 3780 | num = 0 |
3781 | pkgpc10 = syslpi = '' | ||
3782 | if 'pkgpc10' in data and 'syslpi' in data: | ||
3783 | pkgpc10 = data['pkgpc10'] | ||
3784 | syslpi = data['syslpi'] | ||
3785 | useturbo = True | ||
3677 | res = data['result'] | 3786 | res = data['result'] |
3678 | tVal = [float(data['suspend']), float(data['resume'])] | 3787 | tVal = [float(data['suspend']), float(data['resume'])] |
3679 | list[mode]['data'].append([data['host'], data['kernel'], | 3788 | list[mode]['data'].append([data['host'], data['kernel'], |
3680 | data['time'], tVal[0], tVal[1], data['url'], res, | 3789 | data['time'], tVal[0], tVal[1], data['url'], res, |
3681 | data['issues'], data['sus_worst'], data['sus_worsttime'], | 3790 | data['issues'], data['sus_worst'], data['sus_worsttime'], |
3682 | data['res_worst'], data['res_worsttime']]) | 3791 | data['res_worst'], data['res_worsttime'], pkgpc10, syslpi]) |
3683 | idx = len(list[mode]['data']) - 1 | 3792 | idx = len(list[mode]['data']) - 1 |
3684 | if res.startswith('fail in'): | 3793 | if res.startswith('fail in'): |
3685 | res = 'fail' | 3794 | res = 'fail' |
@@ -3689,7 +3798,7 @@ def createHTMLSummarySimple(testruns, htmlfile, title): | |||
3689 | cnt[res] += 1 | 3798 | cnt[res] += 1 |
3690 | if res == 'pass': | 3799 | if res == 'pass': |
3691 | for i in range(2): | 3800 | for i in range(2): |
3692 | tMed[i].append(tVal[i]) | 3801 | tMed[i][tVal[i]] = idx |
3693 | tAvg[i] += tVal[i] | 3802 | tAvg[i] += tVal[i] |
3694 | if tMin[i] == 0 or tVal[i] < tMin[i]: | 3803 | if tMin[i] == 0 or tVal[i] < tMin[i]: |
3695 | iMin[i] = idx | 3804 | iMin[i] = idx |
@@ -3703,7 +3812,7 @@ def createHTMLSummarySimple(testruns, htmlfile, title): | |||
3703 | for i in range(2): | 3812 | for i in range(2): |
3704 | s = sorted(tMed[i]) | 3813 | s = sorted(tMed[i]) |
3705 | list[lastmode]['med'][i] = s[int(len(s)/2)] | 3814 | list[lastmode]['med'][i] = s[int(len(s)/2)] |
3706 | iMed[i] = tMed[i].index(list[lastmode]['med'][i]) | 3815 | iMed[i] = tMed[i][list[lastmode]['med'][i]] |
3707 | list[lastmode]['avg'] = [tAvg[0] / num, tAvg[1] / num] | 3816 | list[lastmode]['avg'] = [tAvg[0] / num, tAvg[1] / num] |
3708 | list[lastmode]['min'] = tMin | 3817 | list[lastmode]['min'] = tMin |
3709 | list[lastmode]['max'] = tMax | 3818 | list[lastmode]['max'] = tMax |
@@ -3719,6 +3828,7 @@ def createHTMLSummarySimple(testruns, htmlfile, title): | |||
3719 | td = '\t<td>{0}</td>\n' | 3828 | td = '\t<td>{0}</td>\n' |
3720 | tdh = '\t<td{1}>{0}</td>\n' | 3829 | tdh = '\t<td{1}>{0}</td>\n' |
3721 | tdlink = '\t<td><a href="{0}">html</a></td>\n' | 3830 | tdlink = '\t<td><a href="{0}">html</a></td>\n' |
3831 | colspan = '14' if useturbo else '12' | ||
3722 | 3832 | ||
3723 | # table header | 3833 | # table header |
3724 | html += '<table>\n<tr>\n' + th.format('#') +\ | 3834 | html += '<table>\n<tr>\n' + th.format('#') +\ |
@@ -3726,12 +3836,13 @@ def createHTMLSummarySimple(testruns, htmlfile, title): | |||
3726 | th.format('Test Time') + th.format('Result') + th.format('Issues') +\ | 3836 | th.format('Test Time') + th.format('Result') + th.format('Issues') +\ |
3727 | th.format('Suspend') + th.format('Resume') +\ | 3837 | th.format('Suspend') + th.format('Resume') +\ |
3728 | th.format('Worst Suspend Device') + th.format('SD Time') +\ | 3838 | th.format('Worst Suspend Device') + th.format('SD Time') +\ |
3729 | th.format('Worst Resume Device') + th.format('RD Time') +\ | 3839 | th.format('Worst Resume Device') + th.format('RD Time') |
3730 | th.format('Detail') + '</tr>\n' | 3840 | if useturbo: |
3731 | 3841 | html += th.format('PkgPC10') + th.format('SysLPI') | |
3842 | html += th.format('Detail')+'</tr>\n' | ||
3732 | # export list into html | 3843 | # export list into html |
3733 | head = '<tr class="head"><td>{0}</td><td>{1}</td>'+\ | 3844 | head = '<tr class="head"><td>{0}</td><td>{1}</td>'+\ |
3734 | '<td colspan=12 class="sus">Suspend Avg={2} '+\ | 3845 | '<td colspan='+colspan+' class="sus">Suspend Avg={2} '+\ |
3735 | '<span class=minval><a href="#s{10}min">Min={3}</a></span> '+\ | 3846 | '<span class=minval><a href="#s{10}min">Min={3}</a></span> '+\ |
3736 | '<span class=medval><a href="#s{10}med">Med={4}</a></span> '+\ | 3847 | '<span class=medval><a href="#s{10}med">Med={4}</a></span> '+\ |
3737 | '<span class=maxval><a href="#s{10}max">Max={5}</a></span> '+\ | 3848 | '<span class=maxval><a href="#s{10}max">Max={5}</a></span> '+\ |
@@ -3740,7 +3851,8 @@ def createHTMLSummarySimple(testruns, htmlfile, title): | |||
3740 | '<span class=medval><a href="#r{10}med">Med={8}</a></span> '+\ | 3851 | '<span class=medval><a href="#r{10}med">Med={8}</a></span> '+\ |
3741 | '<span class=maxval><a href="#r{10}max">Max={9}</a></span></td>'+\ | 3852 | '<span class=maxval><a href="#r{10}max">Max={9}</a></span></td>'+\ |
3742 | '</tr>\n' | 3853 | '</tr>\n' |
3743 | headnone = '<tr class="head"><td>{0}</td><td>{1}</td><td colspan=12></td></tr>\n' | 3854 | headnone = '<tr class="head"><td>{0}</td><td>{1}</td><td colspan='+\ |
3855 | colspan+'></td></tr>\n' | ||
3744 | for mode in list: | 3856 | for mode in list: |
3745 | # header line for each suspend mode | 3857 | # header line for each suspend mode |
3746 | num = 0 | 3858 | num = 0 |
@@ -3787,6 +3899,9 @@ def createHTMLSummarySimple(testruns, htmlfile, title): | |||
3787 | html += td.format('%.3f ms' % d[9]) if d[9] else td.format('') # sus_worst time | 3899 | html += td.format('%.3f ms' % d[9]) if d[9] else td.format('') # sus_worst time |
3788 | html += td.format(d[10]) # res_worst | 3900 | html += td.format(d[10]) # res_worst |
3789 | html += td.format('%.3f ms' % d[11]) if d[11] else td.format('') # res_worst time | 3901 | html += td.format('%.3f ms' % d[11]) if d[11] else td.format('') # res_worst time |
3902 | if useturbo: | ||
3903 | html += td.format(d[12]) # pkg_pc10 | ||
3904 | html += td.format(d[13]) # syslpi | ||
3790 | html += tdlink.format(d[5]) if d[5] else td.format('') # url | 3905 | html += tdlink.format(d[5]) if d[5] else td.format('') # url |
3791 | html += '</tr>\n' | 3906 | html += '</tr>\n' |
3792 | num += 1 | 3907 | num += 1 |
@@ -3861,8 +3976,10 @@ def createHTMLDeviceSummary(testruns, htmlfile, title): | |||
3861 | hf.close() | 3976 | hf.close() |
3862 | return devall | 3977 | return devall |
3863 | 3978 | ||
3864 | def createHTMLIssuesSummary(issues, htmlfile, title): | 3979 | def createHTMLIssuesSummary(testruns, issues, htmlfile, title, extra=''): |
3980 | multihost = len([e for e in issues if len(e['urls']) > 1]) > 0 | ||
3865 | html = summaryCSS('Issues Summary - SleepGraph', False) | 3981 | html = summaryCSS('Issues Summary - SleepGraph', False) |
3982 | total = len(testruns) | ||
3866 | 3983 | ||
3867 | # generate the html | 3984 | # generate the html |
3868 | th = '\t<th>{0}</th>\n' | 3985 | th = '\t<th>{0}</th>\n' |
@@ -3870,27 +3987,36 @@ def createHTMLIssuesSummary(issues, htmlfile, title): | |||
3870 | tdlink = '<a href="{1}">{0}</a>' | 3987 | tdlink = '<a href="{1}">{0}</a>' |
3871 | subtitle = '%d issues' % len(issues) if len(issues) > 0 else 'no issues' | 3988 | subtitle = '%d issues' % len(issues) if len(issues) > 0 else 'no issues' |
3872 | html += '<div class="stamp">%s (%s)</div><table>\n' % (title, subtitle) | 3989 | html += '<div class="stamp">%s (%s)</div><table>\n' % (title, subtitle) |
3873 | html += '<tr>\n' + th.format('Count') + th.format('Issue') +\ | 3990 | html += '<tr>\n' + th.format('Issue') + th.format('Count') |
3874 | th.format('Hosts') + th.format('First Instance') + '</tr>\n' | 3991 | if multihost: |
3992 | html += th.format('Hosts') | ||
3993 | html += th.format('Tests') + th.format('Fail Rate') +\ | ||
3994 | th.format('First Instance') + '</tr>\n' | ||
3875 | 3995 | ||
3876 | num = 0 | 3996 | num = 0 |
3877 | for e in sorted(issues, key=lambda v:v['count'], reverse=True): | 3997 | for e in sorted(issues, key=lambda v:v['count'], reverse=True): |
3998 | testtotal = 0 | ||
3878 | links = [] | 3999 | links = [] |
3879 | for host in sorted(e['urls']): | 4000 | for host in sorted(e['urls']): |
3880 | links.append(tdlink.format(host, e['urls'][host])) | 4001 | links.append(tdlink.format(host, e['urls'][host][0])) |
4002 | testtotal += len(e['urls'][host]) | ||
4003 | rate = '%d/%d (%.2f%%)' % (testtotal, total, 100*float(testtotal)/float(total)) | ||
3881 | # row classes - alternate row color | 4004 | # row classes - alternate row color |
3882 | rcls = ['alt'] if num % 2 == 1 else [] | 4005 | rcls = ['alt'] if num % 2 == 1 else [] |
3883 | html += '<tr class="'+(' '.join(rcls))+'">\n' if len(rcls) > 0 else '<tr>\n' | 4006 | html += '<tr class="'+(' '.join(rcls))+'">\n' if len(rcls) > 0 else '<tr>\n' |
3884 | html += td.format('center', e['count']) # count | ||
3885 | html += td.format('left', e['line']) # issue | 4007 | html += td.format('left', e['line']) # issue |
3886 | html += td.format('center', len(e['urls'])) # hosts | 4008 | html += td.format('center', e['count']) # count |
4009 | if multihost: | ||
4010 | html += td.format('center', len(e['urls'])) # hosts | ||
4011 | html += td.format('center', testtotal) # test count | ||
4012 | html += td.format('center', rate) # test rate | ||
3887 | html += td.format('center nowrap', '<br>'.join(links)) # links | 4013 | html += td.format('center nowrap', '<br>'.join(links)) # links |
3888 | html += '</tr>\n' | 4014 | html += '</tr>\n' |
3889 | num += 1 | 4015 | num += 1 |
3890 | 4016 | ||
3891 | # flush the data to file | 4017 | # flush the data to file |
3892 | hf = open(htmlfile, 'w') | 4018 | hf = open(htmlfile, 'w') |
3893 | hf.write(html+'</table>\n</body>\n</html>\n') | 4019 | hf.write(html+'</table>\n'+extra+'</body>\n</html>\n') |
3894 | hf.close() | 4020 | hf.close() |
3895 | return issues | 4021 | return issues |
3896 | 4022 | ||
@@ -4195,7 +4321,7 @@ def createHTML(testruns, testfail): | |||
4195 | for word in phase.split('_'): | 4321 | for word in phase.split('_'): |
4196 | id += word[0] | 4322 | id += word[0] |
4197 | order = '%.2f' % ((p['order'] * pdelta) + pmargin) | 4323 | order = '%.2f' % ((p['order'] * pdelta) + pmargin) |
4198 | name = string.replace(phase, '_', ' ') | 4324 | name = phase.replace('_', ' ') |
4199 | devtl.html += devtl.html_legend.format(order, p['color'], name, id) | 4325 | devtl.html += devtl.html_legend.format(order, p['color'], name, id) |
4200 | devtl.html += '</div>\n' | 4326 | devtl.html += '</div>\n' |
4201 | 4327 | ||
@@ -4784,6 +4910,7 @@ def setRuntimeSuspend(before=True): | |||
4784 | def executeSuspend(): | 4910 | def executeSuspend(): |
4785 | pm = ProcessMonitor() | 4911 | pm = ProcessMonitor() |
4786 | tp = sysvals.tpath | 4912 | tp = sysvals.tpath |
4913 | wifi = sysvals.checkWifi() | ||
4787 | testdata = [] | 4914 | testdata = [] |
4788 | battery = True if getBattery() else False | 4915 | battery = True if getBattery() else False |
4789 | # run these commands to prepare the system for suspend | 4916 | # run these commands to prepare the system for suspend |
@@ -4857,6 +4984,8 @@ def executeSuspend(): | |||
4857 | else: | 4984 | else: |
4858 | tdata['error'] = turbo | 4985 | tdata['error'] = turbo |
4859 | else: | 4986 | else: |
4987 | if sysvals.haveTurbostat(): | ||
4988 | sysvals.vprint('WARNING: ignoring turbostat in mode "%s"' % mode) | ||
4860 | pf = open(sysvals.powerfile, 'w') | 4989 | pf = open(sysvals.powerfile, 'w') |
4861 | pf.write(mode) | 4990 | pf.write(mode) |
4862 | # execution will pause here | 4991 | # execution will pause here |
@@ -4883,6 +5012,8 @@ def executeSuspend(): | |||
4883 | bat2 = getBattery() if battery else False | 5012 | bat2 = getBattery() if battery else False |
4884 | if battery and bat1 and bat2: | 5013 | if battery and bat1 and bat2: |
4885 | tdata['bat'] = (bat1, bat2) | 5014 | tdata['bat'] = (bat1, bat2) |
5015 | if 'device' in wifi and 'ip' in wifi: | ||
5016 | tdata['wifi'] = (wifi, sysvals.checkWifi()) | ||
4886 | testdata.append(tdata) | 5017 | testdata.append(tdata) |
4887 | # stop ftrace | 5018 | # stop ftrace |
4888 | if(sysvals.usecallgraph or sysvals.usetraceevents): | 5019 | if(sysvals.usecallgraph or sysvals.usetraceevents): |
@@ -4989,7 +5120,7 @@ def deviceInfo(output=''): | |||
4989 | ms2nice(power['runtime_active_time']), \ | 5120 | ms2nice(power['runtime_active_time']), \ |
4990 | ms2nice(power['runtime_suspended_time'])) | 5121 | ms2nice(power['runtime_suspended_time'])) |
4991 | for i in sorted(lines): | 5122 | for i in sorted(lines): |
4992 | print lines[i] | 5123 | print(lines[i]) |
4993 | return res | 5124 | return res |
4994 | 5125 | ||
4995 | # Function: devProps | 5126 | # Function: devProps |
@@ -5122,12 +5253,12 @@ def getModes(): | |||
5122 | modes = [] | 5253 | modes = [] |
5123 | if(os.path.exists(sysvals.powerfile)): | 5254 | if(os.path.exists(sysvals.powerfile)): |
5124 | fp = open(sysvals.powerfile, 'r') | 5255 | fp = open(sysvals.powerfile, 'r') |
5125 | modes = string.split(fp.read()) | 5256 | modes = fp.read().split() |
5126 | fp.close() | 5257 | fp.close() |
5127 | if(os.path.exists(sysvals.mempowerfile)): | 5258 | if(os.path.exists(sysvals.mempowerfile)): |
5128 | deep = False | 5259 | deep = False |
5129 | fp = open(sysvals.mempowerfile, 'r') | 5260 | fp = open(sysvals.mempowerfile, 'r') |
5130 | for m in string.split(fp.read()): | 5261 | for m in fp.read().split(): |
5131 | memmode = m.strip('[]') | 5262 | memmode = m.strip('[]') |
5132 | if memmode == 'deep': | 5263 | if memmode == 'deep': |
5133 | deep = True | 5264 | deep = True |
@@ -5138,7 +5269,7 @@ def getModes(): | |||
5138 | modes.remove('mem') | 5269 | modes.remove('mem') |
5139 | if('disk' in modes and os.path.exists(sysvals.diskpowerfile)): | 5270 | if('disk' in modes and os.path.exists(sysvals.diskpowerfile)): |
5140 | fp = open(sysvals.diskpowerfile, 'r') | 5271 | fp = open(sysvals.diskpowerfile, 'r') |
5141 | for m in string.split(fp.read()): | 5272 | for m in fp.read().split(): |
5142 | modes.append('disk-%s' % m.strip('[]')) | 5273 | modes.append('disk-%s' % m.strip('[]')) |
5143 | fp.close() | 5274 | fp.close() |
5144 | return modes | 5275 | return modes |
@@ -5201,14 +5332,15 @@ def dmidecode(mempath, fatal=False): | |||
5201 | continue | 5332 | continue |
5202 | 5333 | ||
5203 | # read in the memory for scanning | 5334 | # read in the memory for scanning |
5204 | fp = open(mempath, 'rb') | ||
5205 | try: | 5335 | try: |
5336 | fp = open(mempath, 'rb') | ||
5206 | fp.seek(memaddr) | 5337 | fp.seek(memaddr) |
5207 | buf = fp.read(memsize) | 5338 | buf = fp.read(memsize) |
5208 | except: | 5339 | except: |
5209 | if(fatal): | 5340 | if(fatal): |
5210 | doError('DMI table is unreachable, sorry') | 5341 | doError('DMI table is unreachable, sorry') |
5211 | else: | 5342 | else: |
5343 | pprint('WARNING: /dev/mem is not readable, ignoring DMI data') | ||
5212 | return out | 5344 | return out |
5213 | fp.close() | 5345 | fp.close() |
5214 | 5346 | ||
@@ -5231,14 +5363,15 @@ def dmidecode(mempath, fatal=False): | |||
5231 | return out | 5363 | return out |
5232 | 5364 | ||
5233 | # read in the SM or DMI table | 5365 | # read in the SM or DMI table |
5234 | fp = open(mempath, 'rb') | ||
5235 | try: | 5366 | try: |
5367 | fp = open(mempath, 'rb') | ||
5236 | fp.seek(base) | 5368 | fp.seek(base) |
5237 | buf = fp.read(length) | 5369 | buf = fp.read(length) |
5238 | except: | 5370 | except: |
5239 | if(fatal): | 5371 | if(fatal): |
5240 | doError('DMI table is unreachable, sorry') | 5372 | doError('DMI table is unreachable, sorry') |
5241 | else: | 5373 | else: |
5374 | pprint('WARNING: /dev/mem is not readable, ignoring DMI data') | ||
5242 | return out | 5375 | return out |
5243 | fp.close() | 5376 | fp.close() |
5244 | 5377 | ||
@@ -5382,7 +5515,11 @@ def getFPDT(output): | |||
5382 | i = 0 | 5515 | i = 0 |
5383 | fwData = [0, 0] | 5516 | fwData = [0, 0] |
5384 | records = buf[36:] | 5517 | records = buf[36:] |
5385 | fp = open(sysvals.mempath, 'rb') | 5518 | try: |
5519 | fp = open(sysvals.mempath, 'rb') | ||
5520 | except: | ||
5521 | pprint('WARNING: /dev/mem is not readable, ignoring the FPDT data') | ||
5522 | return False | ||
5386 | while(i < len(records)): | 5523 | while(i < len(records)): |
5387 | header = struct.unpack('HBB', records[i:i+4]) | 5524 | header = struct.unpack('HBB', records[i:i+4]) |
5388 | if(header[0] not in rectype): | 5525 | if(header[0] not in rectype): |
@@ -5499,13 +5636,14 @@ def statusCheck(probecheck=False): | |||
5499 | pprint(' is ftrace supported: %s' % res) | 5636 | pprint(' is ftrace supported: %s' % res) |
5500 | 5637 | ||
5501 | # check if kprobes are available | 5638 | # check if kprobes are available |
5502 | res = sysvals.colorText('NO') | 5639 | if sysvals.usekprobes: |
5503 | sysvals.usekprobes = sysvals.verifyKprobes() | 5640 | res = sysvals.colorText('NO') |
5504 | if(sysvals.usekprobes): | 5641 | sysvals.usekprobes = sysvals.verifyKprobes() |
5505 | res = 'YES' | 5642 | if(sysvals.usekprobes): |
5506 | else: | 5643 | res = 'YES' |
5507 | sysvals.usedevsrc = False | 5644 | else: |
5508 | pprint(' are kprobes supported: %s' % res) | 5645 | sysvals.usedevsrc = False |
5646 | pprint(' are kprobes supported: %s' % res) | ||
5509 | 5647 | ||
5510 | # what data source are we using | 5648 | # what data source are we using |
5511 | res = 'DMESG' | 5649 | res = 'DMESG' |
@@ -5593,6 +5731,8 @@ def getArgFloat(name, args, min, max, main=True): | |||
5593 | 5731 | ||
5594 | def processData(live=False): | 5732 | def processData(live=False): |
5595 | pprint('PROCESSING DATA') | 5733 | pprint('PROCESSING DATA') |
5734 | sysvals.vprint('usetraceevents=%s, usetracemarkers=%s, usekprobes=%s' % \ | ||
5735 | (sysvals.usetraceevents, sysvals.usetracemarkers, sysvals.usekprobes)) | ||
5596 | error = '' | 5736 | error = '' |
5597 | if(sysvals.usetraceevents): | 5737 | if(sysvals.usetraceevents): |
5598 | testruns, error = parseTraceLog(live) | 5738 | testruns, error = parseTraceLog(live) |
@@ -5605,6 +5745,11 @@ def processData(live=False): | |||
5605 | parseKernelLog(data) | 5745 | parseKernelLog(data) |
5606 | if(sysvals.ftracefile and (sysvals.usecallgraph or sysvals.usetraceevents)): | 5746 | if(sysvals.ftracefile and (sysvals.usecallgraph or sysvals.usetraceevents)): |
5607 | appendIncompleteTraceLog(testruns) | 5747 | appendIncompleteTraceLog(testruns) |
5748 | sysvals.vprint('System Info:') | ||
5749 | for key in sorted(sysvals.stamp): | ||
5750 | sysvals.vprint(' %-8s : %s' % (key.upper(), sysvals.stamp[key])) | ||
5751 | if sysvals.kparams: | ||
5752 | sysvals.vprint('Kparams:\n %s' % sysvals.kparams) | ||
5608 | sysvals.vprint('Command:\n %s' % sysvals.cmdline) | 5753 | sysvals.vprint('Command:\n %s' % sysvals.cmdline) |
5609 | for data in testruns: | 5754 | for data in testruns: |
5610 | if data.mcelog: | 5755 | if data.mcelog: |
@@ -5612,12 +5757,24 @@ def processData(live=False): | |||
5612 | for line in data.mcelog.split('\n'): | 5757 | for line in data.mcelog.split('\n'): |
5613 | sysvals.vprint(' %s' % line) | 5758 | sysvals.vprint(' %s' % line) |
5614 | if data.turbostat: | 5759 | if data.turbostat: |
5615 | sysvals.vprint('Turbostat:\n %s' % data.turbostat.replace('|', ' ')) | 5760 | idx, s = 0, 'Turbostat:\n ' |
5761 | for val in data.turbostat.split('|'): | ||
5762 | idx += len(val) + 1 | ||
5763 | if idx >= 80: | ||
5764 | idx = 0 | ||
5765 | s += '\n ' | ||
5766 | s += val + ' ' | ||
5767 | sysvals.vprint(s) | ||
5616 | if data.battery: | 5768 | if data.battery: |
5617 | a1, c1, a2, c2 = data.battery | 5769 | a1, c1, a2, c2 = data.battery |
5618 | s = 'Battery:\n Before - AC: %s, Charge: %d\n After - AC: %s, Charge: %d' % \ | 5770 | s = 'Battery:\n Before - AC: %s, Charge: %d\n After - AC: %s, Charge: %d' % \ |
5619 | (a1, int(c1), a2, int(c2)) | 5771 | (a1, int(c1), a2, int(c2)) |
5620 | sysvals.vprint(s) | 5772 | sysvals.vprint(s) |
5773 | if data.wifi: | ||
5774 | w = data.wifi.replace('|', ' ').split(',') | ||
5775 | s = 'Wifi:\n Before %s\n After %s' % \ | ||
5776 | (w[0], w[1]) | ||
5777 | sysvals.vprint(s) | ||
5621 | data.printDetails() | 5778 | data.printDetails() |
5622 | if sysvals.cgdump: | 5779 | if sysvals.cgdump: |
5623 | for data in testruns: | 5780 | for data in testruns: |
@@ -5641,13 +5798,13 @@ def processData(live=False): | |||
5641 | # Function: rerunTest | 5798 | # Function: rerunTest |
5642 | # Description: | 5799 | # Description: |
5643 | # generate an output from an existing set of ftrace/dmesg logs | 5800 | # generate an output from an existing set of ftrace/dmesg logs |
5644 | def rerunTest(): | 5801 | def rerunTest(htmlfile=''): |
5645 | if sysvals.ftracefile: | 5802 | if sysvals.ftracefile: |
5646 | doesTraceLogHaveTraceEvents() | 5803 | doesTraceLogHaveTraceEvents() |
5647 | if not sysvals.dmesgfile and not sysvals.usetraceevents: | 5804 | if not sysvals.dmesgfile and not sysvals.usetraceevents: |
5648 | doError('recreating this html output requires a dmesg file') | 5805 | doError('recreating this html output requires a dmesg file') |
5649 | if sysvals.outdir: | 5806 | if htmlfile: |
5650 | sysvals.htmlfile = sysvals.outdir | 5807 | sysvals.htmlfile = htmlfile |
5651 | else: | 5808 | else: |
5652 | sysvals.setOutputFile() | 5809 | sysvals.setOutputFile() |
5653 | if os.path.exists(sysvals.htmlfile): | 5810 | if os.path.exists(sysvals.htmlfile): |
@@ -5673,7 +5830,7 @@ def runTest(n=0): | |||
5673 | if sysvals.skiphtml: | 5830 | if sysvals.skiphtml: |
5674 | sysvals.sudoUserchown(sysvals.testdir) | 5831 | sysvals.sudoUserchown(sysvals.testdir) |
5675 | return | 5832 | return |
5676 | if len(testdata) > 0 and not testdata[0]['error']: | 5833 | if not testdata[0]['error']: |
5677 | testruns, stamp = processData(True) | 5834 | testruns, stamp = processData(True) |
5678 | for data in testruns: | 5835 | for data in testruns: |
5679 | del data | 5836 | del data |
@@ -5709,15 +5866,13 @@ def find_in_html(html, start, end, firstonly=True): | |||
5709 | return '' | 5866 | return '' |
5710 | return out | 5867 | return out |
5711 | 5868 | ||
5712 | def data_from_html(file, outpath, issues): | 5869 | def data_from_html(file, outpath, issues, fulldetail=False): |
5713 | if '<html>' not in file: | 5870 | html = open(file, 'r').read() |
5714 | html = open(file, 'r').read() | 5871 | sysvals.htmlfile = os.path.relpath(file, outpath) |
5715 | sysvals.htmlfile = os.path.relpath(file, outpath) | ||
5716 | else: | ||
5717 | html = file | ||
5718 | # extract general info | 5872 | # extract general info |
5719 | suspend = find_in_html(html, 'Kernel Suspend', 'ms') | 5873 | suspend = find_in_html(html, 'Kernel Suspend', 'ms') |
5720 | resume = find_in_html(html, 'Kernel Resume', 'ms') | 5874 | resume = find_in_html(html, 'Kernel Resume', 'ms') |
5875 | sysinfo = find_in_html(html, '<div class="stamp sysinfo">', '</div>') | ||
5721 | line = find_in_html(html, '<div class="stamp">', '</div>') | 5876 | line = find_in_html(html, '<div class="stamp">', '</div>') |
5722 | stmp = line.split() | 5877 | stmp = line.split() |
5723 | if not suspend or not resume or len(stmp) != 8: | 5878 | if not suspend or not resume or len(stmp) != 8: |
@@ -5739,13 +5894,18 @@ def data_from_html(file, outpath, issues): | |||
5739 | result = 'pass' | 5894 | result = 'pass' |
5740 | # extract error info | 5895 | # extract error info |
5741 | ilist = [] | 5896 | ilist = [] |
5897 | extra = dict() | ||
5742 | log = find_in_html(html, '<div id="dmesglog" style="display:none;">', | 5898 | log = find_in_html(html, '<div id="dmesglog" style="display:none;">', |
5743 | '</div>').strip() | 5899 | '</div>').strip() |
5744 | if log: | 5900 | if log: |
5745 | d = Data(0) | 5901 | d = Data(0) |
5746 | d.end = 999999999 | 5902 | d.end = 999999999 |
5747 | d.dmesgtext = log.split('\n') | 5903 | d.dmesgtext = log.split('\n') |
5748 | d.extractErrorInfo(issues) | 5904 | msglist = d.extractErrorInfo() |
5905 | for msg in msglist: | ||
5906 | sysvals.errorSummary(issues, msg) | ||
5907 | if stmp[2] == 'freeze': | ||
5908 | extra = d.turbostatInfo() | ||
5749 | elist = dict() | 5909 | elist = dict() |
5750 | for dir in d.errorinfo: | 5910 | for dir in d.errorinfo: |
5751 | for err in d.errorinfo[dir]: | 5911 | for err in d.errorinfo[dir]: |
@@ -5761,14 +5921,15 @@ def data_from_html(file, outpath, issues): | |||
5761 | if len(match) > 0: | 5921 | if len(match) > 0: |
5762 | match[0]['count'] += 1 | 5922 | match[0]['count'] += 1 |
5763 | if sysvals.hostname not in match[0]['urls']: | 5923 | if sysvals.hostname not in match[0]['urls']: |
5764 | match[0]['urls'][sysvals.hostname] = sysvals.htmlfile | 5924 | match[0]['urls'][sysvals.hostname] = [sysvals.htmlfile] |
5925 | elif sysvals.htmlfile not in match[0]['urls'][sysvals.hostname]: | ||
5926 | match[0]['urls'][sysvals.hostname].append(sysvals.htmlfile) | ||
5765 | else: | 5927 | else: |
5766 | issues.append({ | 5928 | issues.append({ |
5767 | 'match': issue, 'count': 1, 'line': issue, | 5929 | 'match': issue, 'count': 1, 'line': issue, |
5768 | 'urls': {sysvals.hostname: sysvals.htmlfile}, | 5930 | 'urls': {sysvals.hostname: [sysvals.htmlfile]}, |
5769 | }) | 5931 | }) |
5770 | ilist.append(issue) | 5932 | ilist.append(issue) |
5771 | |||
5772 | # extract device info | 5933 | # extract device info |
5773 | devices = dict() | 5934 | devices = dict() |
5774 | for line in html.split('\n'): | 5935 | for line in html.split('\n'): |
@@ -5804,6 +5965,7 @@ def data_from_html(file, outpath, issues): | |||
5804 | 'mode': stmp[2], | 5965 | 'mode': stmp[2], |
5805 | 'host': stmp[0], | 5966 | 'host': stmp[0], |
5806 | 'kernel': stmp[1], | 5967 | 'kernel': stmp[1], |
5968 | 'sysinfo': sysinfo, | ||
5807 | 'time': tstr, | 5969 | 'time': tstr, |
5808 | 'result': result, | 5970 | 'result': result, |
5809 | 'issues': ' '.join(ilist), | 5971 | 'issues': ' '.join(ilist), |
@@ -5816,8 +5978,28 @@ def data_from_html(file, outpath, issues): | |||
5816 | 'res_worsttime': worst['resume']['time'], | 5978 | 'res_worsttime': worst['resume']['time'], |
5817 | 'url': sysvals.htmlfile, | 5979 | 'url': sysvals.htmlfile, |
5818 | } | 5980 | } |
5981 | for key in extra: | ||
5982 | data[key] = extra[key] | ||
5983 | if fulldetail: | ||
5984 | data['funclist'] = find_in_html(html, '<div title="', '" class="traceevent"', False) | ||
5819 | return data | 5985 | return data |
5820 | 5986 | ||
5987 | def genHtml(subdir): | ||
5988 | for dirname, dirnames, filenames in os.walk(subdir): | ||
5989 | sysvals.dmesgfile = sysvals.ftracefile = sysvals.htmlfile = '' | ||
5990 | for filename in filenames: | ||
5991 | if(re.match('.*_dmesg.txt', filename)): | ||
5992 | sysvals.dmesgfile = os.path.join(dirname, filename) | ||
5993 | elif(re.match('.*_ftrace.txt', filename)): | ||
5994 | sysvals.ftracefile = os.path.join(dirname, filename) | ||
5995 | sysvals.setOutputFile() | ||
5996 | if sysvals.ftracefile and sysvals.htmlfile and \ | ||
5997 | not os.path.exists(sysvals.htmlfile): | ||
5998 | pprint('FTRACE: %s' % sysvals.ftracefile) | ||
5999 | if sysvals.dmesgfile: | ||
6000 | pprint('DMESG : %s' % sysvals.dmesgfile) | ||
6001 | rerunTest() | ||
6002 | |||
5821 | # Function: runSummary | 6003 | # Function: runSummary |
5822 | # Description: | 6004 | # Description: |
5823 | # create a summary of tests in a sub-directory | 6005 | # create a summary of tests in a sub-directory |
@@ -5826,20 +6008,7 @@ def runSummary(subdir, local=True, genhtml=False): | |||
5826 | outpath = os.path.abspath('.') if local else inpath | 6008 | outpath = os.path.abspath('.') if local else inpath |
5827 | pprint('Generating a summary of folder:\n %s' % inpath) | 6009 | pprint('Generating a summary of folder:\n %s' % inpath) |
5828 | if genhtml: | 6010 | if genhtml: |
5829 | for dirname, dirnames, filenames in os.walk(subdir): | 6011 | genHtml(subdir) |
5830 | sysvals.dmesgfile = sysvals.ftracefile = sysvals.htmlfile = '' | ||
5831 | for filename in filenames: | ||
5832 | if(re.match('.*_dmesg.txt', filename)): | ||
5833 | sysvals.dmesgfile = os.path.join(dirname, filename) | ||
5834 | elif(re.match('.*_ftrace.txt', filename)): | ||
5835 | sysvals.ftracefile = os.path.join(dirname, filename) | ||
5836 | sysvals.setOutputFile() | ||
5837 | if sysvals.ftracefile and sysvals.htmlfile and \ | ||
5838 | not os.path.exists(sysvals.htmlfile): | ||
5839 | pprint('FTRACE: %s' % sysvals.ftracefile) | ||
5840 | if sysvals.dmesgfile: | ||
5841 | pprint('DMESG : %s' % sysvals.dmesgfile) | ||
5842 | rerunTest() | ||
5843 | issues = [] | 6012 | issues = [] |
5844 | testruns = [] | 6013 | testruns = [] |
5845 | desc = {'host':[],'mode':[],'kernel':[]} | 6014 | desc = {'host':[],'mode':[],'kernel':[]} |
@@ -5863,7 +6032,7 @@ def runSummary(subdir, local=True, genhtml=False): | |||
5863 | pprint(' summary.html - tabular list of test data found') | 6032 | pprint(' summary.html - tabular list of test data found') |
5864 | createHTMLDeviceSummary(testruns, os.path.join(outpath, 'summary-devices.html'), title) | 6033 | createHTMLDeviceSummary(testruns, os.path.join(outpath, 'summary-devices.html'), title) |
5865 | pprint(' summary-devices.html - kernel device list sorted by total execution time') | 6034 | pprint(' summary-devices.html - kernel device list sorted by total execution time') |
5866 | createHTMLIssuesSummary(issues, os.path.join(outpath, 'summary-issues.html'), title) | 6035 | createHTMLIssuesSummary(testruns, issues, os.path.join(outpath, 'summary-issues.html'), title) |
5867 | pprint(' summary-issues.html - kernel issues found sorted by frequency') | 6036 | pprint(' summary-issues.html - kernel issues found sorted by frequency') |
5868 | 6037 | ||
5869 | # Function: checkArgBool | 6038 | # Function: checkArgBool |
@@ -6109,6 +6278,7 @@ def printHelp(): | |||
6109 | ' default: suspend-{date}-{time}\n'\ | 6278 | ' default: suspend-{date}-{time}\n'\ |
6110 | ' -rtcwake t Wakeup t seconds after suspend, set t to "off" to disable (default: 15)\n'\ | 6279 | ' -rtcwake t Wakeup t seconds after suspend, set t to "off" to disable (default: 15)\n'\ |
6111 | ' -addlogs Add the dmesg and ftrace logs to the html output\n'\ | 6280 | ' -addlogs Add the dmesg and ftrace logs to the html output\n'\ |
6281 | ' -turbostat Use turbostat to execute the command in freeze mode (default: disabled)\n'\ | ||
6112 | ' -srgap Add a visible gap in the timeline between sus/res (default: disabled)\n'\ | 6282 | ' -srgap Add a visible gap in the timeline between sus/res (default: disabled)\n'\ |
6113 | ' -skiphtml Run the test and capture the trace logs, but skip the timeline (default: disabled)\n'\ | 6283 | ' -skiphtml Run the test and capture the trace logs, but skip the timeline (default: disabled)\n'\ |
6114 | ' -result fn Export a results table to a text file for parsing.\n'\ | 6284 | ' -result fn Export a results table to a text file for parsing.\n'\ |
@@ -6130,6 +6300,7 @@ def printHelp(): | |||
6130 | ' be created in a new subdirectory with a summary page.\n'\ | 6300 | ' be created in a new subdirectory with a summary page.\n'\ |
6131 | ' [debug]\n'\ | 6301 | ' [debug]\n'\ |
6132 | ' -f Use ftrace to create device callgraphs (default: disabled)\n'\ | 6302 | ' -f Use ftrace to create device callgraphs (default: disabled)\n'\ |
6303 | ' -ftop Use ftrace on the top level call: "%s" (default: disabled)\n'\ | ||
6133 | ' -maxdepth N limit the callgraph data to N call levels (default: 0=all)\n'\ | 6304 | ' -maxdepth N limit the callgraph data to N call levels (default: 0=all)\n'\ |
6134 | ' -expandcg pre-expand the callgraph data in the html output (default: disabled)\n'\ | 6305 | ' -expandcg pre-expand the callgraph data in the html output (default: disabled)\n'\ |
6135 | ' -fadd file Add functions to be graphed in the timeline from a list in a text file\n'\ | 6306 | ' -fadd file Add functions to be graphed in the timeline from a list in a text file\n'\ |
@@ -6149,6 +6320,7 @@ def printHelp(): | |||
6149 | ' -status Test to see if the system is enabled to run this tool\n'\ | 6320 | ' -status Test to see if the system is enabled to run this tool\n'\ |
6150 | ' -fpdt Print out the contents of the ACPI Firmware Performance Data Table\n'\ | 6321 | ' -fpdt Print out the contents of the ACPI Firmware Performance Data Table\n'\ |
6151 | ' -battery Print out battery info (if available)\n'\ | 6322 | ' -battery Print out battery info (if available)\n'\ |
6323 | ' -wifi Print out wifi connection info (if wireless-tools and device exists)\n'\ | ||
6152 | ' -x<mode> Test xset by toggling the given mode (on/off/standby/suspend)\n'\ | 6324 | ' -x<mode> Test xset by toggling the given mode (on/off/standby/suspend)\n'\ |
6153 | ' -sysinfo Print out system info extracted from BIOS\n'\ | 6325 | ' -sysinfo Print out system info extracted from BIOS\n'\ |
6154 | ' -devinfo Print out the pm settings of all devices which support runtime suspend\n'\ | 6326 | ' -devinfo Print out the pm settings of all devices which support runtime suspend\n'\ |
@@ -6158,7 +6330,7 @@ def printHelp(): | |||
6158 | ' [redo]\n'\ | 6330 | ' [redo]\n'\ |
6159 | ' -ftrace ftracefile Create HTML output using ftrace input (used with -dmesg)\n'\ | 6331 | ' -ftrace ftracefile Create HTML output using ftrace input (used with -dmesg)\n'\ |
6160 | ' -dmesg dmesgfile Create HTML output using dmesg (used with -ftrace)\n'\ | 6332 | ' -dmesg dmesgfile Create HTML output using dmesg (used with -ftrace)\n'\ |
6161 | '' % (sysvals.title, sysvals.version, sysvals.suspendmode)) | 6333 | '' % (sysvals.title, sysvals.version, sysvals.suspendmode, sysvals.ftopfunc)) |
6162 | return True | 6334 | return True |
6163 | 6335 | ||
6164 | # ----------------- MAIN -------------------- | 6336 | # ----------------- MAIN -------------------- |
@@ -6168,7 +6340,7 @@ if __name__ == '__main__': | |||
6168 | cmd = '' | 6340 | cmd = '' |
6169 | simplecmds = ['-sysinfo', '-modes', '-fpdt', '-flist', '-flistall', | 6341 | simplecmds = ['-sysinfo', '-modes', '-fpdt', '-flist', '-flistall', |
6170 | '-devinfo', '-status', '-battery', '-xon', '-xoff', '-xstandby', | 6342 | '-devinfo', '-status', '-battery', '-xon', '-xoff', '-xstandby', |
6171 | '-xsuspend', '-xinit', '-xreset', '-xstat'] | 6343 | '-xsuspend', '-xinit', '-xreset', '-xstat', '-wifi'] |
6172 | if '-f' in sys.argv: | 6344 | if '-f' in sys.argv: |
6173 | sysvals.cgskip = sysvals.configFile('cgskip.txt') | 6345 | sysvals.cgskip = sysvals.configFile('cgskip.txt') |
6174 | # loop through the command line arguments | 6346 | # loop through the command line arguments |
@@ -6200,6 +6372,10 @@ if __name__ == '__main__': | |||
6200 | sysvals.postdelay = getArgInt('-postdelay', args, 0, 60000) | 6372 | sysvals.postdelay = getArgInt('-postdelay', args, 0, 60000) |
6201 | elif(arg == '-f'): | 6373 | elif(arg == '-f'): |
6202 | sysvals.usecallgraph = True | 6374 | sysvals.usecallgraph = True |
6375 | elif(arg == '-ftop'): | ||
6376 | sysvals.usecallgraph = True | ||
6377 | sysvals.ftop = True | ||
6378 | sysvals.usekprobes = False | ||
6203 | elif(arg == '-skiphtml'): | 6379 | elif(arg == '-skiphtml'): |
6204 | sysvals.skiphtml = True | 6380 | sysvals.skiphtml = True |
6205 | elif(arg == '-cgdump'): | 6381 | elif(arg == '-cgdump'): |
@@ -6210,10 +6386,16 @@ if __name__ == '__main__': | |||
6210 | genhtml = True | 6386 | genhtml = True |
6211 | elif(arg == '-addlogs'): | 6387 | elif(arg == '-addlogs'): |
6212 | sysvals.dmesglog = sysvals.ftracelog = True | 6388 | sysvals.dmesglog = sysvals.ftracelog = True |
6389 | elif(arg == '-nologs'): | ||
6390 | sysvals.dmesglog = sysvals.ftracelog = False | ||
6213 | elif(arg == '-addlogdmesg'): | 6391 | elif(arg == '-addlogdmesg'): |
6214 | sysvals.dmesglog = True | 6392 | sysvals.dmesglog = True |
6215 | elif(arg == '-addlogftrace'): | 6393 | elif(arg == '-addlogftrace'): |
6216 | sysvals.ftracelog = True | 6394 | sysvals.ftracelog = True |
6395 | elif(arg == '-turbostat'): | ||
6396 | sysvals.tstat = True | ||
6397 | if not sysvals.haveTurbostat(): | ||
6398 | doError('Turbostat command not found') | ||
6217 | elif(arg == '-verbose'): | 6399 | elif(arg == '-verbose'): |
6218 | sysvals.verbose = True | 6400 | sysvals.verbose = True |
6219 | elif(arg == '-proc'): | 6401 | elif(arg == '-proc'): |
@@ -6283,6 +6465,12 @@ if __name__ == '__main__': | |||
6283 | except: | 6465 | except: |
6284 | doError('No callgraph functions supplied', True) | 6466 | doError('No callgraph functions supplied', True) |
6285 | sysvals.setCallgraphFilter(val) | 6467 | sysvals.setCallgraphFilter(val) |
6468 | elif(arg == '-skipkprobe'): | ||
6469 | try: | ||
6470 | val = args.next() | ||
6471 | except: | ||
6472 | doError('No kprobe functions supplied', True) | ||
6473 | sysvals.skipKprobes(val) | ||
6286 | elif(arg == '-cgskip'): | 6474 | elif(arg == '-cgskip'): |
6287 | try: | 6475 | try: |
6288 | val = args.next() | 6476 | val = args.next() |
@@ -6421,7 +6609,7 @@ if __name__ == '__main__': | |||
6421 | elif(cmd == 'devinfo'): | 6609 | elif(cmd == 'devinfo'): |
6422 | deviceInfo() | 6610 | deviceInfo() |
6423 | elif(cmd == 'modes'): | 6611 | elif(cmd == 'modes'): |
6424 | print getModes() | 6612 | pprint(getModes()) |
6425 | elif(cmd == 'flist'): | 6613 | elif(cmd == 'flist'): |
6426 | sysvals.getFtraceFilterFunctions(True) | 6614 | sysvals.getFtraceFilterFunctions(True) |
6427 | elif(cmd == 'flistall'): | 6615 | elif(cmd == 'flistall'): |
@@ -6433,11 +6621,18 @@ if __name__ == '__main__': | |||
6433 | ret = displayControl(cmd[1:]) | 6621 | ret = displayControl(cmd[1:]) |
6434 | elif(cmd == 'xstat'): | 6622 | elif(cmd == 'xstat'): |
6435 | pprint('Display Status: %s' % displayControl('stat').upper()) | 6623 | pprint('Display Status: %s' % displayControl('stat').upper()) |
6624 | elif(cmd == 'wifi'): | ||
6625 | out = sysvals.checkWifi() | ||
6626 | if 'device' not in out: | ||
6627 | pprint('WIFI interface not found') | ||
6628 | else: | ||
6629 | for key in sorted(out): | ||
6630 | pprint('%6s: %s' % (key.upper(), out[key])) | ||
6436 | sys.exit(ret) | 6631 | sys.exit(ret) |
6437 | 6632 | ||
6438 | # if instructed, re-analyze existing data files | 6633 | # if instructed, re-analyze existing data files |
6439 | if(sysvals.notestrun): | 6634 | if(sysvals.notestrun): |
6440 | stamp = rerunTest() | 6635 | stamp = rerunTest(sysvals.outdir) |
6441 | sysvals.outputResult(stamp) | 6636 | sysvals.outputResult(stamp) |
6442 | sys.exit(0) | 6637 | sys.exit(0) |
6443 | 6638 | ||
@@ -6474,7 +6669,7 @@ if __name__ == '__main__': | |||
6474 | s = 'suspend-x%d' % sysvals.multitest['count'] | 6669 | s = 'suspend-x%d' % sysvals.multitest['count'] |
6475 | sysvals.outdir = datetime.now().strftime(s+'-%y%m%d-%H%M%S') | 6670 | sysvals.outdir = datetime.now().strftime(s+'-%y%m%d-%H%M%S') |
6476 | if not os.path.isdir(sysvals.outdir): | 6671 | if not os.path.isdir(sysvals.outdir): |
6477 | os.mkdir(sysvals.outdir) | 6672 | os.makedirs(sysvals.outdir) |
6478 | for i in range(sysvals.multitest['count']): | 6673 | for i in range(sysvals.multitest['count']): |
6479 | if(i != 0): | 6674 | if(i != 0): |
6480 | pprint('Waiting %d seconds...' % (sysvals.multitest['delay'])) | 6675 | pprint('Waiting %d seconds...' % (sysvals.multitest['delay'])) |