[coreboot-gerrit] Change in coreboot[master]: device: Log times with millisecond resolution

[Kyösti Mälkki (Code Review)]

Kyösti Mälkki has uploaded this change for review. ( https://review.coreboot.org/c/coreboot/+/37425 )

Change subject: device: Log times with millisecond resolution
......................................................................

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 
---
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);
+		}
    }
 }