[PATCH 0/2] scripts: show_delta: additional features

[PATCH 0/2] scripts: show_delta: additional features

[Erik Stromdahl]

This patch series adds two new features to the show_delta script:

- rounding
- delta time stamp only output

The purpose of the patches is to make it easier to diff show_delta-
processed kernel logs when debugging timing problems.
Rounding of the delta time stamps removes small (perhaps random)
differences in the time stamps which results in less irrelevant
differences detected by a diff tool. This can be useful when diffing
logs from different test runs in order to detect if there has been any
significant differences in timing.

Adding the possibility to print only delta time stamps (and not the
combination of absolute and delta time stamps which is the default
behavior of show_delta) also makes it easier to diff logs from
different test runs.

Erik Stromdahl (2):
  scripts: show_delta: add time stamp rounding option
  scripts: show_delta: add --delta-only option

 scripts/show_delta | 45 +++++++++++++++++++++++++++++++++++++++++----
 1 file changed, 41 insertions(+), 4 deletions(-)

-- 
2.7.4

[PATCH 1/2] scripts: show_delta: add time stamp rounding option

[Erik Stromdahl]

An additional feature for show_delta: -r <round_us>
With this option the delta time stamps are rounded to the
closest microsecond specified by the -r option.

Rationale: Make it easier to diff kernel logs when looking for
timing issues (less irrelevant diffs detected by a diff tool).

Signed-off-by: Erik Stromdahl <erik.stromdahl@gmail.com>
---
 scripts/show_delta | 36 +++++++++++++++++++++++++++++++++---
 1 file changed, 33 insertions(+), 3 deletions(-)

diff --git a/scripts/show_delta b/scripts/show_delta
index e386827..b85cf0f 100755
--- a/scripts/show_delta
+++ b/scripts/show_delta
@@ -20,7 +20,8 @@ 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.
+are relative to a single (base) point in time. The '-r' option is optional
+and can be used to round the calculated delta times.
 
 Options:
   -h            Show this usage help.
@@ -29,6 +30,10 @@ Options:
 		If it is a string, the first message line
 		which matches (at the beginning of the
 		line) is used as the time reference.
+  -r <round_us>	Specify a a rounding time (in us) for all
+		delta timestamps.
+		All delta timestamps will be rounded to the
+		nearest 'round_us' microsecond
 
 ex: $ dmesg >timefile
     $ show_delta -b NET4 timefile
@@ -52,13 +57,23 @@ def get_time(line):
 	#print "time=", time
 	return (time, rest)
 
+# Round delta to the nearest micro second specified by the rounding_time_us
+# argument
+def round_delta_ts(delta, rounding_time_us):
+	div_floor = (delta * 1E6) // rounding_time_us
+	delta_floor = rounding_time_us / 1E6 * div_floor
+	delta_modulo_us = (delta - delta_floor) * 1E6
+	if (delta_modulo_us - rounding_time_us / 2) < 0:
+		return delta_floor
+	else:
+		return delta_floor + rounding_time_us / 1E6
 
 # 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):
+def convert_line(line, base_time, rounding_time_us):
 	global last_time
 
 	try:
@@ -75,14 +90,20 @@ def convert_line(line, base_time):
 		delta = time - last_time
 		last_time = time
 
+	if rounding_time_us:
+		delta = round_delta_ts(delta, rounding_time_us)
+
 	return ("[%5.6f < %5.6f >]" % (time, delta)) + rest
 
 def main():
 	base_str = ""
+	rounding_str = ""
 	filein = ""
 	for arg in sys.argv[1:]:
 		if arg=="-b":
 			base_str = sys.argv[sys.argv.index("-b")+1]
+		elif arg=="-r":
+			rounding_str = sys.argv[sys.argv.index("-r")+1]
 		elif arg=="-h":
 			usage()
 		else:
@@ -122,7 +143,16 @@ def main():
 	else:
 		base_time = 0.0
 
+	if rounding_str:
+		try:
+			rounding_time_us = int(rounding_str)
+		except:
+			print ('Bad -r option: "%s"' % rounding_str)
+			sys.exit(1)
+	else:
+		rounding_time_us = 0
+
 	for line in lines:
-		print (convert_line(line, base_time),)
+		print (convert_line(line, base_time, rounding_time_us),)
 
 main()
-- 
2.7.4

[PATCH 2/2] scripts: show_delta: add --delta-only option

[Erik Stromdahl]

The --delta-only option makes show_delta print delta time stamps
only (and not the combination of absolute and delta time stamps
which is the default).

Rationale: Easier to diff kernel logs (with graphical diff tool)
when debugging timing issues. Having absolute time stamps
when diffing the output from two different test runs could
potentially (and likely) make the diff tool detect a lot of irrelevant
differences.

Signed-off-by: Erik Stromdahl <erik.stromdahl@gmail.com>
---
 scripts/show_delta | 13 ++++++++++---
 1 file changed, 10 insertions(+), 3 deletions(-)

diff --git a/scripts/show_delta b/scripts/show_delta
index b85cf0f..13b1f62 100755
--- a/scripts/show_delta
+++ b/scripts/show_delta
@@ -34,6 +34,7 @@ Options:
 		delta timestamps.
 		All delta timestamps will be rounded to the
 		nearest 'round_us' microsecond
+  --delta-only	Add only delta time stamps to the output.
 
 ex: $ dmesg >timefile
     $ show_delta -b NET4 timefile
@@ -73,7 +74,7 @@ def round_delta_ts(delta, rounding_time_us):
 # 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, rounding_time_us):
+def convert_line(line, base_time, rounding_time_us, delta_only):
 	global last_time
 
 	try:
@@ -93,17 +94,23 @@ def convert_line(line, base_time, rounding_time_us):
 	if rounding_time_us:
 		delta = round_delta_ts(delta, rounding_time_us)
 
-	return ("[%5.6f < %5.6f >]" % (time, delta)) + rest
+	if delta_only:
+		return ("[%5.6f]" % delta) + rest
+	else:
+		return ("[%5.6f < %5.6f >]" % (time, delta)) + rest
 
 def main():
 	base_str = ""
 	rounding_str = ""
+	delta_only = False
 	filein = ""
 	for arg in sys.argv[1:]:
 		if arg=="-b":
 			base_str = sys.argv[sys.argv.index("-b")+1]
 		elif arg=="-r":
 			rounding_str = sys.argv[sys.argv.index("-r")+1]
+		elif arg=="--delta-only":
+			delta_only = True
 		elif arg=="-h":
 			usage()
 		else:
@@ -153,6 +160,6 @@ def main():
 		rounding_time_us = 0
 
 	for line in lines:
-		print (convert_line(line, base_time, rounding_time_us),)
+		print (convert_line(line, base_time, rounding_time_us, delta_only),)
 
 main()
-- 
2.7.4