c25ce589dca10 (Finn Behrens 2020-11-23 15:15:33 +0100 1) #!/usr/bin/env python
acf147074cb2a (Thomas Gleixner 2019-06-01 10:08:52 +0200 2) # SPDX-License-Identifier: GPL-2.0-only
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 3) #
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 4) # show_deltas: Read list of printk messages instrumented with
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 5) # time data, and format with time deltas.
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 6) #
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 7) # Also, you can show the times relative to a fixed point.
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 8) #
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 9) # Copyright 2003 Sony Corporation
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 10) #
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 11)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 12) import sys
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 13) import string
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 14)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 15) def usage():
f29b5f3e6fc0a (Mike Pagano 2013-10-09 10:36:42 -0400 16) print ("""usage: show_delta [<options>] <filename>
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 17)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 18) This program parses the output from a set of printk message lines which
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 19) have time data prefixed because the CONFIG_PRINTK_TIME option is set, or
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 20) the kernel command line option "time" is specified. When run with no
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 21) options, the time information is converted to show the time delta between
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 22) each printk line and the next. When run with the '-b' option, all times
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 23) are relative to a single (base) point in time.
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 24)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 25) Options:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 26) -h Show this usage help.
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 27) -b <base> Specify a base for time references.
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 28) <base> can be a number or a string.
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 29) If it is a string, the first message line
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 30) which matches (at the beginning of the
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 31) line) is used as the time reference.
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 32)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 33) ex: $ dmesg >timefile
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 34) $ show_delta -b NET4 timefile
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 35)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 36) will show times relative to the line in the kernel output
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 37) starting with "NET4".
f29b5f3e6fc0a (Mike Pagano 2013-10-09 10:36:42 -0400 38) """)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 39) sys.exit(1)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 40)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 41) # returns a tuple containing the seconds and text for each message line
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 42) # seconds is returned as a float
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 43) # raise an exception if no timing data was found
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 44) def get_time(line):
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 45) if line[0]!="[":
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 46) raise ValueError
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 47)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 48) # split on closing bracket
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 49) (time_str, rest) = string.split(line[1:],']',1)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 50) time = string.atof(time_str)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 51)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 52) #print "time=", time
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 53) return (time, rest)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 54)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 55)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 56) # average line looks like:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 57) # [ 0.084282] VFS: Mounted root (romfs filesystem) readonly
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 58) # time data is expressed in seconds.useconds,
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 59) # convert_line adds a delta for each line
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 60) last_time = 0.0
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 61) def convert_line(line, base_time):
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 62) global last_time
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 63)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 64) try:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 65) (time, rest) = get_time(line)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 66) except:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 67) # if any problem parsing time, don't convert anything
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 68) return line
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 69)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 70) if base_time:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 71) # show time from base
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 72) delta = time - base_time
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 73) else:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 74) # just show time from last line
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 75) delta = time - last_time
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 76) last_time = time
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 77)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 78) return ("[%5.6f < %5.6f >]" % (time, delta)) + rest
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 79)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 80) def main():
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 81) base_str = ""
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 82) filein = ""
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 83) for arg in sys.argv[1:]:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 84) if arg=="-b":
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 85) base_str = sys.argv[sys.argv.index("-b")+1]
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 86) elif arg=="-h":
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 87) usage()
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 88) else:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 89) filein = arg
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 90)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 91) if not filein:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 92) usage()
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 93)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 94) try:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 95) lines = open(filein,"r").readlines()
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 96) except:
f29b5f3e6fc0a (Mike Pagano 2013-10-09 10:36:42 -0400 97) print ("Problem opening file: %s" % filein)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 98) sys.exit(1)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 99)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 100) if base_str:
f29b5f3e6fc0a (Mike Pagano 2013-10-09 10:36:42 -0400 101) print ('base= "%s"' % base_str)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 102) # assume a numeric base. If that fails, try searching
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 103) # for a matching line.
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 104) try:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 105) base_time = float(base_str)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 106) except:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 107) # search for line matching <base> string
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 108) found = 0
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 109) for line in lines:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 110) try:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 111) (time, rest) = get_time(line)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 112) except:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 113) continue
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 114) if string.find(rest, base_str)==1:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 115) base_time = time
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 116) found = 1
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 117) # stop at first match
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 118) break
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 119) if not found:
f29b5f3e6fc0a (Mike Pagano 2013-10-09 10:36:42 -0400 120) print ('Couldn\'t find line matching base pattern "%s"' % base_str)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 121) sys.exit(1)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 122) else:
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 123) base_time = 0.0
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 124)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 125) for line in lines:
f29b5f3e6fc0a (Mike Pagano 2013-10-09 10:36:42 -0400 126) print (convert_line(line, base_time),)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 127)
^1da177e4c3f4 (Linus Torvalds 2005-04-16 15:20:36 -0700 128) main()