From e3d9d67e9977ac5387eae057bc709b29ec6fe03f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ky=C3=B6sti=20M=C3=A4lkki?= Date: Sun, 1 Dec 2019 12:27:44 +0200 Subject: [PATCH] device: Log times with millisecond resolution MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 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 --- src/device/device.c | 29 ++++++++++++++++------------- 1 file changed, 16 insertions(+), 13 deletions(-) diff --git a/src/device/device.c b/src/device/device.c index 5d9938ff0e..236b7684d7 100644 --- a/src/device/device.c +++ b/src/device/device.c @@ -903,16 +903,17 @@ static void scan_bus(struct device *busdev) { 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 @@ static void scan_bus(struct device *busdev) } } - 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 @@ static void init_dev(struct device *dev) 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); } }