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