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