.. | .. |
---|
1 | | -#!/usr/bin/python2 |
---|
| 1 | +#!/usr/bin/env python3 |
---|
| 2 | +# SPDX-License-Identifier: GPL-2.0-only |
---|
2 | 3 | # |
---|
3 | 4 | # Tool for analyzing boot timing |
---|
4 | 5 | # Copyright (c) 2013, Intel Corporation. |
---|
.. | .. |
---|
33 | 34 | from datetime import datetime, timedelta |
---|
34 | 35 | from subprocess import call, Popen, PIPE |
---|
35 | 36 | import sleepgraph as aslib |
---|
| 37 | + |
---|
| 38 | +def pprint(msg): |
---|
| 39 | + print(msg) |
---|
| 40 | + sys.stdout.flush() |
---|
36 | 41 | |
---|
37 | 42 | # ----------------- CLASSES -------------------- |
---|
38 | 43 | |
---|
.. | .. |
---|
85 | 90 | cmdline = 'initcall_debug log_buf_len=32M' |
---|
86 | 91 | if self.useftrace: |
---|
87 | 92 | if self.cpucount > 0: |
---|
88 | | - bs = min(self.memtotal / 2, 2*1024*1024) / self.cpucount |
---|
| 93 | + bs = min(self.memtotal // 2, 2*1024*1024) // self.cpucount |
---|
89 | 94 | else: |
---|
90 | 95 | bs = 131072 |
---|
91 | 96 | cmdline += ' trace_buf_size=%dK trace_clock=global '\ |
---|
.. | .. |
---|
141 | 146 | if arg in ['-h', '-v', '-cronjob', '-reboot', '-verbose']: |
---|
142 | 147 | continue |
---|
143 | 148 | elif arg in ['-o', '-dmesg', '-ftrace', '-func']: |
---|
144 | | - args.next() |
---|
| 149 | + next(args) |
---|
145 | 150 | continue |
---|
146 | 151 | elif arg == '-result': |
---|
147 | | - cmdline += ' %s "%s"' % (arg, os.path.abspath(args.next())) |
---|
| 152 | + cmdline += ' %s "%s"' % (arg, os.path.abspath(next(args))) |
---|
148 | 153 | continue |
---|
149 | 154 | elif arg == '-cgskip': |
---|
150 | | - file = self.configFile(args.next()) |
---|
| 155 | + file = self.configFile(next(args)) |
---|
151 | 156 | cmdline += ' %s "%s"' % (arg, os.path.abspath(file)) |
---|
152 | 157 | continue |
---|
153 | 158 | cmdline += ' '+arg |
---|
.. | .. |
---|
157 | 162 | return cmdline |
---|
158 | 163 | def manualRebootRequired(self): |
---|
159 | 164 | cmdline = self.kernelParams() |
---|
160 | | - print 'To generate a new timeline manually, follow these steps:\n' |
---|
161 | | - print '1. Add the CMDLINE string to your kernel command line.' |
---|
162 | | - print '2. Reboot the system.' |
---|
163 | | - print '3. After reboot, re-run this tool with the same arguments but no command (w/o -reboot or -manual).\n' |
---|
164 | | - print 'CMDLINE="%s"' % cmdline |
---|
| 165 | + pprint('To generate a new timeline manually, follow these steps:\n\n'\ |
---|
| 166 | + '1. Add the CMDLINE string to your kernel command line.\n'\ |
---|
| 167 | + '2. Reboot the system.\n'\ |
---|
| 168 | + '3. After reboot, re-run this tool with the same arguments but no command (w/o -reboot or -manual).\n\n'\ |
---|
| 169 | + 'CMDLINE="%s"' % cmdline) |
---|
165 | 170 | sys.exit() |
---|
166 | 171 | def blGrub(self): |
---|
167 | 172 | blcmd = '' |
---|
.. | .. |
---|
296 | 301 | tp = aslib.TestProps() |
---|
297 | 302 | devtemp = dict() |
---|
298 | 303 | if(sysvals.dmesgfile): |
---|
299 | | - lf = open(sysvals.dmesgfile, 'r') |
---|
| 304 | + lf = open(sysvals.dmesgfile, 'rb') |
---|
300 | 305 | else: |
---|
301 | 306 | lf = Popen('dmesg', stdout=PIPE).stdout |
---|
302 | 307 | for line in lf: |
---|
303 | | - line = line.replace('\r\n', '') |
---|
| 308 | + line = aslib.ascii(line).replace('\r\n', '') |
---|
304 | 309 | # grab the stamp and sysinfo |
---|
305 | 310 | if re.match(tp.stampfmt, line): |
---|
306 | 311 | tp.stamp = line |
---|
.. | .. |
---|
329 | 334 | if(not sysvals.stamp['kernel']): |
---|
330 | 335 | sysvals.stamp['kernel'] = sysvals.kernelVersion(msg) |
---|
331 | 336 | continue |
---|
332 | | - m = re.match('.* setting system clock to (?P<t>.*) UTC.*', msg) |
---|
| 337 | + m = re.match('.* setting system clock to (?P<d>[0-9\-]*)[ A-Z](?P<t>[0-9:]*) UTC.*', msg) |
---|
333 | 338 | if(m): |
---|
334 | | - bt = datetime.strptime(m.group('t'), '%Y-%m-%d %H:%M:%S') |
---|
| 339 | + bt = datetime.strptime(m.group('d')+' '+m.group('t'), '%Y-%m-%d %H:%M:%S') |
---|
335 | 340 | bt = bt - timedelta(seconds=int(ktime)) |
---|
336 | 341 | data.boottime = bt.strftime('%Y-%m-%d_%H:%M:%S') |
---|
337 | 342 | sysvals.stamp['time'] = bt.strftime('%B %d %Y, %I:%M:%S %p') |
---|
.. | .. |
---|
352 | 357 | data.newAction(phase, f, pid, start, ktime, int(r), int(t)) |
---|
353 | 358 | del devtemp[f] |
---|
354 | 359 | continue |
---|
355 | | - if(re.match('^Freeing unused kernel memory.*', msg)): |
---|
| 360 | + if(re.match('^Freeing unused kernel .*', msg)): |
---|
356 | 361 | data.tUserMode = ktime |
---|
357 | 362 | data.dmesg['kernel']['end'] = ktime |
---|
358 | 363 | data.dmesg['user']['start'] = ktime |
---|
.. | .. |
---|
431 | 436 | if len(cg.list) < 1 or cg.invalid or (cg.end - cg.start == 0): |
---|
432 | 437 | continue |
---|
433 | 438 | if(not cg.postProcess()): |
---|
434 | | - print('Sanity check failed for %s-%d' % (proc, pid)) |
---|
| 439 | + pprint('Sanity check failed for %s-%d' % (proc, pid)) |
---|
435 | 440 | continue |
---|
436 | 441 | # match cg data to devices |
---|
437 | 442 | devname = data.deviceMatch(pid, cg) |
---|
.. | .. |
---|
442 | 447 | sysvals.vprint('%s callgraph found for %s %s-%d [%f - %f]' %\ |
---|
443 | 448 | (kind, cg.name, proc, pid, cg.start, cg.end)) |
---|
444 | 449 | elif len(cg.list) > 1000000: |
---|
445 | | - print 'WARNING: the callgraph found for %s is massive! (%d lines)' %\ |
---|
446 | | - (devname, len(cg.list)) |
---|
| 450 | + pprint('WARNING: the callgraph found for %s is massive! (%d lines)' %\ |
---|
| 451 | + (devname, len(cg.list))) |
---|
447 | 452 | |
---|
448 | 453 | # Function: retrieveLogs |
---|
449 | 454 | # Description: |
---|
.. | .. |
---|
528 | 533 | tMax = data.end |
---|
529 | 534 | tTotal = tMax - t0 |
---|
530 | 535 | if(tTotal == 0): |
---|
531 | | - print('ERROR: No timeline data') |
---|
| 536 | + pprint('ERROR: No timeline data') |
---|
532 | 537 | return False |
---|
533 | 538 | user_mode = '%.0f'%(data.tUserMode*1000) |
---|
534 | 539 | last_init = '%.0f'%(tTotal*1000) |
---|
.. | .. |
---|
653 | 658 | statinfo += '\t"%s": [\n\t\t"%s",\n' % (n, devstats[n]['info']) |
---|
654 | 659 | if 'fstat' in devstats[n]: |
---|
655 | 660 | funcs = devstats[n]['fstat'] |
---|
656 | | - for f in sorted(funcs, key=funcs.get, reverse=True): |
---|
| 661 | + for f in sorted(funcs, key=lambda k:(funcs[k], k), reverse=True): |
---|
657 | 662 | if funcs[f][0] < 0.01 and len(funcs) > 10: |
---|
658 | 663 | break |
---|
659 | 664 | statinfo += '\t\t"%f|%s|%d",\n' % (funcs[f][0], f, funcs[f][1]) |
---|
.. | .. |
---|
733 | 738 | op.write('@reboot python %s\n' % sysvals.cronjobCmdString()) |
---|
734 | 739 | op.close() |
---|
735 | 740 | res = call([cmd, cronfile]) |
---|
736 | | - except Exception, e: |
---|
737 | | - print 'Exception: %s' % str(e) |
---|
| 741 | + except Exception as e: |
---|
| 742 | + pprint('Exception: %s' % str(e)) |
---|
738 | 743 | shutil.move(backfile, cronfile) |
---|
739 | 744 | res = -1 |
---|
740 | 745 | if res != 0: |
---|
.. | .. |
---|
749 | 754 | try: |
---|
750 | 755 | call(sysvals.blexec, stderr=PIPE, stdout=PIPE, |
---|
751 | 756 | env={'PATH': '.:/sbin:/usr/sbin:/usr/bin:/sbin:/bin'}) |
---|
752 | | - except Exception, e: |
---|
753 | | - print 'Exception: %s\n' % str(e) |
---|
| 757 | + except Exception as e: |
---|
| 758 | + pprint('Exception: %s\n' % str(e)) |
---|
754 | 759 | return |
---|
755 | 760 | # extract the option and create a grub config without it |
---|
756 | 761 | sysvals.rootUser(True) |
---|
.. | .. |
---|
796 | 801 | op.close() |
---|
797 | 802 | res = call(sysvals.blexec) |
---|
798 | 803 | os.remove(grubfile) |
---|
799 | | - except Exception, e: |
---|
800 | | - print 'Exception: %s' % str(e) |
---|
| 804 | + except Exception as e: |
---|
| 805 | + pprint('Exception: %s' % str(e)) |
---|
801 | 806 | res = -1 |
---|
802 | 807 | # cleanup |
---|
803 | 808 | shutil.move(tempfile, grubfile) |
---|
.. | .. |
---|
821 | 826 | def doError(msg, help=False): |
---|
822 | 827 | if help == True: |
---|
823 | 828 | printHelp() |
---|
824 | | - print 'ERROR: %s\n' % msg |
---|
| 829 | + pprint('ERROR: %s\n' % msg) |
---|
825 | 830 | sysvals.outputResult({'error':msg}) |
---|
826 | 831 | sys.exit() |
---|
827 | 832 | |
---|
.. | .. |
---|
829 | 834 | # Description: |
---|
830 | 835 | # print out the help text |
---|
831 | 836 | def printHelp(): |
---|
832 | | - print('') |
---|
833 | | - print('%s v%s' % (sysvals.title, sysvals.version)) |
---|
834 | | - print('Usage: bootgraph <options> <command>') |
---|
835 | | - print('') |
---|
836 | | - print('Description:') |
---|
837 | | - print(' This tool reads in a dmesg log of linux kernel boot and') |
---|
838 | | - print(' creates an html representation of the boot timeline up to') |
---|
839 | | - print(' the start of the init process.') |
---|
840 | | - print('') |
---|
841 | | - print(' If no specific command is given the tool reads the current dmesg') |
---|
842 | | - print(' and/or ftrace log and creates a timeline') |
---|
843 | | - print('') |
---|
844 | | - print(' Generates output files in subdirectory: boot-yymmdd-HHMMSS') |
---|
845 | | - print(' HTML output: <hostname>_boot.html') |
---|
846 | | - print(' raw dmesg output: <hostname>_boot_dmesg.txt') |
---|
847 | | - print(' raw ftrace output: <hostname>_boot_ftrace.txt') |
---|
848 | | - print('') |
---|
849 | | - print('Options:') |
---|
850 | | - print(' -h Print this help text') |
---|
851 | | - print(' -v Print the current tool version') |
---|
852 | | - print(' -verbose Print extra information during execution and analysis') |
---|
853 | | - print(' -addlogs Add the dmesg log to the html output') |
---|
854 | | - print(' -result fn Export a results table to a text file for parsing.') |
---|
855 | | - print(' -o name Overrides the output subdirectory name when running a new test') |
---|
856 | | - print(' default: boot-{date}-{time}') |
---|
857 | | - print(' [advanced]') |
---|
858 | | - print(' -fstat Use ftrace to add function detail and statistics (default: disabled)') |
---|
859 | | - print(' -f/-callgraph Add callgraph detail, can be very large (default: disabled)') |
---|
860 | | - print(' -maxdepth N limit the callgraph data to N call levels (default: 2)') |
---|
861 | | - print(' -mincg ms Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)') |
---|
862 | | - print(' -timeprec N Number of significant digits in timestamps (0:S, 3:ms, [6:us])') |
---|
863 | | - print(' -expandcg pre-expand the callgraph data in the html output (default: disabled)') |
---|
864 | | - print(' -func list Limit ftrace to comma-delimited list of functions (default: do_one_initcall)') |
---|
865 | | - print(' -cgfilter S Filter the callgraph output in the timeline') |
---|
866 | | - print(' -cgskip file Callgraph functions to skip, off to disable (default: cgskip.txt)') |
---|
867 | | - print(' -bl name Use the following boot loader for kernel params (default: grub)') |
---|
868 | | - print(' -reboot Reboot the machine automatically and generate a new timeline') |
---|
869 | | - print(' -manual Show the steps to generate a new timeline manually (used with -reboot)') |
---|
870 | | - print('') |
---|
871 | | - print('Other commands:') |
---|
872 | | - print(' -flistall Print all functions capable of being captured in ftrace') |
---|
873 | | - print(' -sysinfo Print out system info extracted from BIOS') |
---|
874 | | - print(' [redo]') |
---|
875 | | - print(' -dmesg file Create HTML output using dmesg input (used with -ftrace)') |
---|
876 | | - print(' -ftrace file Create HTML output using ftrace input (used with -dmesg)') |
---|
877 | | - print('') |
---|
| 837 | + pprint('\n%s v%s\n'\ |
---|
| 838 | + 'Usage: bootgraph <options> <command>\n'\ |
---|
| 839 | + '\n'\ |
---|
| 840 | + 'Description:\n'\ |
---|
| 841 | + ' This tool reads in a dmesg log of linux kernel boot and\n'\ |
---|
| 842 | + ' creates an html representation of the boot timeline up to\n'\ |
---|
| 843 | + ' the start of the init process.\n'\ |
---|
| 844 | + '\n'\ |
---|
| 845 | + ' If no specific command is given the tool reads the current dmesg\n'\ |
---|
| 846 | + ' and/or ftrace log and creates a timeline\n'\ |
---|
| 847 | + '\n'\ |
---|
| 848 | + ' Generates output files in subdirectory: boot-yymmdd-HHMMSS\n'\ |
---|
| 849 | + ' HTML output: <hostname>_boot.html\n'\ |
---|
| 850 | + ' raw dmesg output: <hostname>_boot_dmesg.txt\n'\ |
---|
| 851 | + ' raw ftrace output: <hostname>_boot_ftrace.txt\n'\ |
---|
| 852 | + '\n'\ |
---|
| 853 | + 'Options:\n'\ |
---|
| 854 | + ' -h Print this help text\n'\ |
---|
| 855 | + ' -v Print the current tool version\n'\ |
---|
| 856 | + ' -verbose Print extra information during execution and analysis\n'\ |
---|
| 857 | + ' -addlogs Add the dmesg log to the html output\n'\ |
---|
| 858 | + ' -result fn Export a results table to a text file for parsing.\n'\ |
---|
| 859 | + ' -o name Overrides the output subdirectory name when running a new test\n'\ |
---|
| 860 | + ' default: boot-{date}-{time}\n'\ |
---|
| 861 | + ' [advanced]\n'\ |
---|
| 862 | + ' -fstat Use ftrace to add function detail and statistics (default: disabled)\n'\ |
---|
| 863 | + ' -f/-callgraph Add callgraph detail, can be very large (default: disabled)\n'\ |
---|
| 864 | + ' -maxdepth N limit the callgraph data to N call levels (default: 2)\n'\ |
---|
| 865 | + ' -mincg ms Discard all callgraphs shorter than ms milliseconds (e.g. 0.001 for us)\n'\ |
---|
| 866 | + ' -timeprec N Number of significant digits in timestamps (0:S, 3:ms, [6:us])\n'\ |
---|
| 867 | + ' -expandcg pre-expand the callgraph data in the html output (default: disabled)\n'\ |
---|
| 868 | + ' -func list Limit ftrace to comma-delimited list of functions (default: do_one_initcall)\n'\ |
---|
| 869 | + ' -cgfilter S Filter the callgraph output in the timeline\n'\ |
---|
| 870 | + ' -cgskip file Callgraph functions to skip, off to disable (default: cgskip.txt)\n'\ |
---|
| 871 | + ' -bl name Use the following boot loader for kernel params (default: grub)\n'\ |
---|
| 872 | + ' -reboot Reboot the machine automatically and generate a new timeline\n'\ |
---|
| 873 | + ' -manual Show the steps to generate a new timeline manually (used with -reboot)\n'\ |
---|
| 874 | + '\n'\ |
---|
| 875 | + 'Other commands:\n'\ |
---|
| 876 | + ' -flistall Print all functions capable of being captured in ftrace\n'\ |
---|
| 877 | + ' -sysinfo Print out system info extracted from BIOS\n'\ |
---|
| 878 | + ' -which exec Print an executable path, should function even without PATH\n'\ |
---|
| 879 | + ' [redo]\n'\ |
---|
| 880 | + ' -dmesg file Create HTML output using dmesg input (used with -ftrace)\n'\ |
---|
| 881 | + ' -ftrace file Create HTML output using ftrace input (used with -dmesg)\n'\ |
---|
| 882 | + '' % (sysvals.title, sysvals.version)) |
---|
878 | 883 | return True |
---|
879 | 884 | |
---|
880 | 885 | # ----------------- MAIN -------------------- |
---|
.. | .. |
---|
895 | 900 | printHelp() |
---|
896 | 901 | sys.exit() |
---|
897 | 902 | elif(arg == '-v'): |
---|
898 | | - print("Version %s" % sysvals.version) |
---|
| 903 | + pprint("Version %s" % sysvals.version) |
---|
899 | 904 | sys.exit() |
---|
900 | 905 | elif(arg == '-verbose'): |
---|
901 | 906 | sysvals.verbose = True |
---|
.. | .. |
---|
912 | 917 | sysvals.mincglen = aslib.getArgFloat('-mincg', args, 0.0, 10000.0) |
---|
913 | 918 | elif(arg == '-cgfilter'): |
---|
914 | 919 | try: |
---|
915 | | - val = args.next() |
---|
| 920 | + val = next(args) |
---|
916 | 921 | except: |
---|
917 | 922 | doError('No callgraph functions supplied', True) |
---|
918 | 923 | sysvals.setCallgraphFilter(val) |
---|
919 | 924 | elif(arg == '-cgskip'): |
---|
920 | 925 | try: |
---|
921 | | - val = args.next() |
---|
| 926 | + val = next(args) |
---|
922 | 927 | except: |
---|
923 | 928 | doError('No file supplied', True) |
---|
924 | 929 | if val.lower() in switchoff: |
---|
.. | .. |
---|
929 | 934 | doError('%s does not exist' % cgskip) |
---|
930 | 935 | elif(arg == '-bl'): |
---|
931 | 936 | try: |
---|
932 | | - val = args.next() |
---|
| 937 | + val = next(args) |
---|
933 | 938 | except: |
---|
934 | 939 | doError('No boot loader name supplied', True) |
---|
935 | 940 | if val.lower() not in ['grub']: |
---|
.. | .. |
---|
942 | 947 | sysvals.max_graph_depth = aslib.getArgInt('-maxdepth', args, 0, 1000) |
---|
943 | 948 | elif(arg == '-func'): |
---|
944 | 949 | try: |
---|
945 | | - val = args.next() |
---|
| 950 | + val = next(args) |
---|
946 | 951 | except: |
---|
947 | 952 | doError('No filter functions supplied', True) |
---|
948 | 953 | sysvals.useftrace = True |
---|
.. | .. |
---|
951 | 956 | sysvals.setGraphFilter(val) |
---|
952 | 957 | elif(arg == '-ftrace'): |
---|
953 | 958 | try: |
---|
954 | | - val = args.next() |
---|
| 959 | + val = next(args) |
---|
955 | 960 | except: |
---|
956 | 961 | doError('No ftrace file supplied', True) |
---|
957 | 962 | if(os.path.exists(val) == False): |
---|
.. | .. |
---|
964 | 969 | sysvals.cgexp = True |
---|
965 | 970 | elif(arg == '-dmesg'): |
---|
966 | 971 | try: |
---|
967 | | - val = args.next() |
---|
| 972 | + val = next(args) |
---|
968 | 973 | except: |
---|
969 | 974 | doError('No dmesg file supplied', True) |
---|
970 | 975 | if(os.path.exists(val) == False): |
---|
.. | .. |
---|
973 | 978 | sysvals.dmesgfile = val |
---|
974 | 979 | elif(arg == '-o'): |
---|
975 | 980 | try: |
---|
976 | | - val = args.next() |
---|
| 981 | + val = next(args) |
---|
977 | 982 | except: |
---|
978 | 983 | doError('No subdirectory name supplied', True) |
---|
979 | 984 | sysvals.testdir = sysvals.setOutputFolder(val) |
---|
980 | 985 | elif(arg == '-result'): |
---|
981 | 986 | try: |
---|
982 | | - val = args.next() |
---|
| 987 | + val = next(args) |
---|
983 | 988 | except: |
---|
984 | 989 | doError('No result file supplied', True) |
---|
985 | 990 | sysvals.result = val |
---|
.. | .. |
---|
991 | 996 | # remaining options are only for cron job use |
---|
992 | 997 | elif(arg == '-cronjob'): |
---|
993 | 998 | sysvals.iscronjob = True |
---|
| 999 | + elif(arg == '-which'): |
---|
| 1000 | + try: |
---|
| 1001 | + val = next(args) |
---|
| 1002 | + except: |
---|
| 1003 | + doError('No executable supplied', True) |
---|
| 1004 | + out = sysvals.getExec(val) |
---|
| 1005 | + if not out: |
---|
| 1006 | + print('%s not found' % val) |
---|
| 1007 | + sys.exit(1) |
---|
| 1008 | + print(out) |
---|
| 1009 | + sys.exit(0) |
---|
994 | 1010 | else: |
---|
995 | 1011 | doError('Invalid argument: '+arg, True) |
---|
996 | 1012 | |
---|
.. | .. |
---|
1013 | 1029 | updateKernelParams() |
---|
1014 | 1030 | elif cmd == 'flistall': |
---|
1015 | 1031 | for f in sysvals.getBootFtraceFilterFunctions(): |
---|
1016 | | - print f |
---|
| 1032 | + print(f) |
---|
1017 | 1033 | elif cmd == 'checkbl': |
---|
1018 | 1034 | sysvals.getBootLoader() |
---|
1019 | | - print 'Boot Loader: %s\n%s' % (sysvals.bootloader, sysvals.blexec) |
---|
| 1035 | + pprint('Boot Loader: %s\n%s' % (sysvals.bootloader, sysvals.blexec)) |
---|
1020 | 1036 | elif(cmd == 'sysinfo'): |
---|
1021 | 1037 | sysvals.printSystemInfo(True) |
---|
1022 | 1038 | sys.exit() |
---|