show_delta 2.99 KB
Newer Older
1
#!/usr/bin/python
Linus Torvalds's avatar
Linus Torvalds committed
2 3 4 5 6 7 8 9 10 11 12 13 14 15
#
# show_deltas: Read list of printk messages instrumented with
# time data, and format with time deltas.
#
# Also, you can show the times relative to a fixed point.
#
# Copyright 2003 Sony Corporation
#
# GPL 2.0 applies.

import sys
import string

def usage():
16
	print ("""usage: show_delta [<options>] <filename>
Linus Torvalds's avatar
Linus Torvalds committed
17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37

This program parses the output from a set of printk message lines which
have time data prefixed because the CONFIG_PRINTK_TIME option is set, or
the kernel command line option "time" is specified. When run with no
options, the time information is converted to show the time delta between
each printk line and the next.  When run with the '-b' option, all times
are relative to a single (base) point in time.

Options:
  -h            Show this usage help.
  -b <base>	Specify a base for time references.
		<base> can be a number or a string.
		If it is a string, the first message line
		which matches (at the beginning of the
		line) is used as the time reference.

ex: $ dmesg >timefile
    $ show_delta -b NET4 timefile

will show times relative to the line in the kernel output
starting with "NET4".
38
""")
Linus Torvalds's avatar
Linus Torvalds committed
39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96
	sys.exit(1)

# returns a tuple containing the seconds and text for each message line
# seconds is returned as a float
# raise an exception if no timing data was found
def get_time(line):
	if line[0]!="[":
		raise ValueError

	# split on closing bracket
	(time_str, rest) = string.split(line[1:],']',1)
	time = string.atof(time_str)

	#print "time=", time
	return (time, rest)


# average line looks like:
# [    0.084282] VFS: Mounted root (romfs filesystem) readonly
# time data is expressed in seconds.useconds,
# convert_line adds a delta for each line
last_time = 0.0
def convert_line(line, base_time):
	global last_time

	try:
		(time, rest) = get_time(line)
	except:
		# if any problem parsing time, don't convert anything
		return line

	if base_time:
		# show time from base
		delta = time - base_time
	else:
		# just show time from last line
		delta = time - last_time
		last_time = time

	return ("[%5.6f < %5.6f >]" % (time, delta)) + rest

def main():
	base_str = ""
	filein = ""
	for arg in sys.argv[1:]:
		if arg=="-b":
			base_str = sys.argv[sys.argv.index("-b")+1]
		elif arg=="-h":
			usage()
		else:
			filein = arg

	if not filein:
		usage()

	try:
		lines = open(filein,"r").readlines()
	except:
97
		print ("Problem opening file: %s" % filein)
Linus Torvalds's avatar
Linus Torvalds committed
98 99 100
		sys.exit(1)

	if base_str:
101
		print ('base= "%s"' % base_str)
Linus Torvalds's avatar
Linus Torvalds committed
102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119
		# assume a numeric base.  If that fails, try searching
		# for a matching line.
		try:
			base_time = float(base_str)
		except:
			# search for line matching <base> string
			found = 0
			for line in lines:
				try:
					(time, rest) = get_time(line)
				except:
					continue
				if string.find(rest, base_str)==1:
					base_time = time
					found = 1
					# stop at first match
					break
			if not found:
120
				print ('Couldn\'t find line matching base pattern "%s"' % base_str)
Linus Torvalds's avatar
Linus Torvalds committed
121 122 123 124 125
				sys.exit(1)
	else:
		base_time = 0.0

	for line in lines:
126
		print (convert_line(line, base_time),)
Linus Torvalds's avatar
Linus Torvalds committed
127 128

main()