Kyösti Mälkki has uploaded this change for review.

View Change

device: Log times with millisecond resolution

To print times with 1 us resolution just adds unnecessary noise
when comparing logs across different boots. Furthermore, just
the printk itself is 1 ms if some slow console is enabled.

If bus scan or device init takes less than 2 ms it's not really
worth printing the time at all.

Change-Id: Ibea43124a1937f404a6e71fd9431086b2b72290a
Signed-off-by: Kyösti Mälkki <kyosti.malkki@gmail.com>
---
M src/device/device.c
1 file changed, 21 insertions(+), 12 deletions(-)

git pull ssh://review.coreboot.org:29418/coreboot refs/changes/25/37425/1

diff --git a/src/device/device.c b/src/device/device.c
index 5d9938f..511e09b 100644
--- a/src/device/device.c
+++ b/src/device/device.c
@@ -903,8 +903,7 @@
 {
 	int do_scan_bus;
 	struct stopwatch sw;
-
-	stopwatch_init(&sw);
+	long scan_time;
 
 	if (!busdev->enabled)
 		return;
@@ -913,6 +912,8 @@
 
 	post_log_path(busdev);
 
+	stopwatch_init(&sw);
+
 	do_scan_bus = 1;
 	while (do_scan_bus) {
 		struct bus *link;
@@ -928,8 +929,13 @@
 		}
 	}
 
-	printk(BIOS_DEBUG, "%s: scanning of bus %s took %ld usecs\n",
-		__func__, dev_path(busdev), stopwatch_duration_usecs(&sw));
+	scan_time = stopwatch_duration_msecs(&sw);
+	if (scan_time >= 2) {
+		printk(BIOS_DEBUG, "%s: bus %s finished in %ld msecs\n", __func__,
+		       dev_path(busdev), scan_time);
+	} else {
+		printk(BIOS_DEBUG, "%s: bus %s done\n", __func__, dev_path(busdev));
+	}
 }
 
 void scan_bridges(struct bus *bus)
@@ -1116,22 +1122,25 @@
 		return;
 
 	if (!dev->initialized && dev->ops && dev->ops->init) {
-#if CONFIG(HAVE_MONOTONIC_TIMER)
 		struct stopwatch sw;
-		stopwatch_init(&sw);
-#endif
+		long init_time;
+
 		if (dev->path.type == DEVICE_PATH_I2C) {
 			printk(BIOS_DEBUG, "smbus: %s[%d]->",
 			       dev_path(dev->bus->dev), dev->bus->link_num);
 		}
 
-		printk(BIOS_DEBUG, "%s init ...\n", dev_path(dev));
+		printk(BIOS_DEBUG, "%s init\n", dev_path(dev));
+
+		stopwatch_init(&sw);
 		dev->initialized = 1;
 		dev->ops->init(dev);
-#if CONFIG(HAVE_MONOTONIC_TIMER)
-		printk(BIOS_DEBUG, "%s init finished in %ld usecs\n", dev_path(dev),
-			stopwatch_duration_usecs(&sw));
-#endif
+
+		init_time = stopwatch_duration_msecs(&sw);
+		if (init_time >= 2) {
+			printk(BIOS_DEBUG, "%s init finished in %ld msecs\n", dev_path(dev),
+			       init_time);
+		}
 	}
 }
 

To view, visit change 37425. To unsubscribe, or for help writing mail filters, visit settings.