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

[Nico Huber (Code Review)]

Nico Huber has submitted this change. ( 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.

Change-Id: Ibea43124a1937f404a6e71fd9431086b2b72290a
Signed-off-by: Kyösti Mälkki 
Reviewed-on: https://review.coreboot.org/c/coreboot/+/37425
Tested-by: build bot (Jenkins) 
Reviewed-by: Nico Huber 
---
M src/device/device.c
1 file changed, 16 insertions(+), 13 deletions(-)

Approvals:
  build bot (Jenkins): Verified
  Nico Huber: Looks good to me, approved

diff --git a/src/device/device.c b/src/device/device.c
index 5d9938f..236b768 100644
--- a/src/device/device.c
+++ b/src/device/device.c
@@ -903,16 +903,17 @@
 {
    int do_scan_bus;
    struct stopwatch sw;
-
-	stopwatch_init(&sw);
+	long scan_time;

if (!busdev->enabled)
    	return;

-	printk(BIOS_SPEW, "%s scanning...\n", dev_path(busdev));
+	printk(BIOS_DEBUG, "%s scanning...\n", dev_path(busdev));

post_log_path(busdev);

+	stopwatch_init(&sw);
+
    do_scan_bus = 1;
    while (do_scan_bus) {
    	struct bus *link;
@@ -928,8 +929,9 @@
    	}
    }

-	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);
+	printk(BIOS_DEBUG, "%s: bus %s finished in %ld msecs\n", __func__,
+	       dev_path(busdev), scan_time);
 }

void scan_bridges(struct bus *bus)
@@ -1116,22 +1118,23 @@
    	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);
+		printk(BIOS_DEBUG, "%s init finished in %ld msecs\n", dev_path(dev),
+		       init_time);
    }
 }