Change in coreboot[master]: boot_state: Reduce accuracy of reported times

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

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

Change subject: boot_state: Reduce accuracy of reported times
......................................................................

boot_state: Reduce accuracy of reported times

When diffing boot logs, lines reporting times spent in each
boot_state always get highlighed due the little fluctuation
in microsecond-scale. Recude the logged resolution to
milliseconds to avoid that.

Change-Id: I7a27d6c250d8432131f30e9a4869cb45ad75d9fd
Signed-off-by: Kyösti Mälkki 
---
M src/lib/hardwaremain.c
1 file changed, 7 insertions(+), 1 deletion(-)

git pull ssh://review.coreboot.org:29418/coreboot refs/changes/28/36528/1

diff --git a/src/lib/hardwaremain.c b/src/lib/hardwaremain.c
index 2ff2b8c..5967052 100644
--- a/src/lib/hardwaremain.c
+++ b/src/lib/hardwaremain.c
@@ -23,6 +23,7 @@
 #include <bootstate.h>
 #include <console/console.h>
 #include <console/post_codes.h>
+#include <commonlib/helpers.h>
 #include <cbmem.h>
 #include <version.h>
 #include <device/device.h>
@@ -256,7 +257,12 @@
    run_time = mono_time_diff_microseconds(&samples[1], &samples[2]);
    exit_time = mono_time_diff_microseconds(&samples[2], &samples[3]);

-	printk(BIOS_DEBUG, "BS: %s times (us): entry %ld run %ld exit %ld\n",
+	/* Report with millisecond accuracy to reduce log diffs. */
+	entry_time = DIV_ROUND_CLOSEST(entry_time, 1000);
+	run_time = DIV_ROUND_CLOSEST(run_time, 1000);
+	exit_time = DIV_ROUND_CLOSEST(exit_time, 1000);
+
+	printk(BIOS_DEBUG, "BS: %s times (ms): entry %ld run %ld exit %ld\n",
           state->name, entry_time, run_time, exit_time);
 }
 #else

[Arthur Heymans (Code Review)]

Arthur Heymans has posted comments on this change. ( https://review.coreboot.org/c/coreboot/+/36528 )

Change subject: boot_state: Reduce accuracy of reported times
......................................................................

Patch Set 1: Code-Review+2

Should timestamps also do that?

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

Kyösti Mälkki has posted comments on this change. ( https://review.coreboot.org/c/coreboot/+/36528 )

Change subject: boot_state: Reduce accuracy of reported times
......................................................................

Patch Set 1:
> Patch Set 1: Code-Review+2
>
> Should timestamps also do that?

I would leave it to util/cbmem to decide the accuracy of output. IMHO that utility should be improved to provide some capability of comparing timestamps-tables collected from different boots.

[Marshall Dawson (Code Review)]

Marshall Dawson has posted comments on this change. ( https://review.coreboot.org/c/coreboot/+/36528 )

Change subject: boot_state: Reduce accuracy of reported times
......................................................................

Patch Set 2:

(2 comments)

This seems like a reasonable change to me.  The times I've sought to improve boot times, the ones that get the most attention are typically in the 10s or 100s of ms, and I agree, <1000us tends to noise.

https://review.coreboot.org/c/coreboot/+/36528/2//COMMIT_MSG 
Commit Message:

https://review.coreboot.org/c/coreboot/+/36528/2//COMMIT_MSG@7 
PS2, Line 7: accuracy 
I would call this "precision" instead.  Reading "reduce accuracy ..." is pretty shocking.

https://review.coreboot.org/c/coreboot/+/36528/2//COMMIT_MSG@11 
PS2, Line 11: Recude 
Reduce

Change in coreboot[master]: boot_state: Reduce precision of reported times

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

Hello Arthur Heymans, build bot (Jenkins),

I'd like you to reexamine a change. Please visit

https://review.coreboot.org/c/coreboot/+/36528

to look at the new patch set (#3).

Change subject: boot_state: Reduce precision of reported times
......................................................................

boot_state: Reduce precision of reported times

When diffing boot logs, lines reporting times spent in each
boot_state always get highlighed due the little fluctuation
in microsecond-scale. Reduce the logged precision to
milliseconds to avoid that.

Change-Id: I7a27d6c250d8432131f30e9a4869cb45ad75d9fd
Signed-off-by: Kyösti Mälkki 
---
M src/lib/hardwaremain.c
1 file changed, 7 insertions(+), 1 deletion(-)

git pull ssh://review.coreboot.org:29418/coreboot refs/changes/28/36528/3

Change in coreboot[master]: boot_state: Reduce precision of reported times

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

Kyösti Mälkki has posted comments on this change. ( https://review.coreboot.org/c/coreboot/+/36528 )

Change subject: boot_state: Reduce precision of reported times
......................................................................

Patch Set 3:

(2 comments)

https://review.coreboot.org/c/coreboot/+/36528/2//COMMIT_MSG 
Commit Message:

https://review.coreboot.org/c/coreboot/+/36528/2//COMMIT_MSG@7 
PS2, Line 7: accuracy
> I would call this "precision" instead.  Reading "reduce accuracy ..." is pretty shocking.

Done

https://review.coreboot.org/c/coreboot/+/36528/2//COMMIT_MSG@11 
PS2, Line 11: Recude
> Reduce

Done

Change in coreboot[master]: boot_state: Reduce precision of reported times

[Aaron Durbin (Code Review)]

Aaron Durbin has posted comments on this change. ( https://review.coreboot.org/c/coreboot/+/36528 )

Change subject: boot_state: Reduce precision of reported times
......................................................................

Patch Set 3:

(1 comment)

https://review.coreboot.org/c/coreboot/+/36528/3/src/lib/hardwaremain.c 
File src/lib/hardwaremain.c:

https://review.coreboot.org/c/coreboot/+/36528/3/src/lib/hardwaremain.c@261 
PS3, Line 261: 1000
USECS_PER_MSEC

Change in coreboot[master]: boot_state: Reduce precision of reported times

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

Hello Arthur Heymans, build bot (Jenkins),

I'd like you to reexamine a change. Please visit

https://review.coreboot.org/c/coreboot/+/36528

to look at the new patch set (#4).

Change subject: boot_state: Reduce precision of reported times
......................................................................

boot_state: Reduce precision of reported times

When diffing boot logs, lines reporting times spent in each
boot_state always get highlighed due the little fluctuation
in microsecond-scale. Reduce the logged precision to
milliseconds to avoid that.

Change-Id: I7a27d6c250d8432131f30e9a4869cb45ad75d9fd
Signed-off-by: Kyösti Mälkki 
---
M src/lib/hardwaremain.c
1 file changed, 7 insertions(+), 1 deletion(-)

git pull ssh://review.coreboot.org:29418/coreboot refs/changes/28/36528/4

Change in coreboot[master]: boot_state: Reduce precision of reported times

[Aaron Durbin (Code Review)]

Aaron Durbin has posted comments on this change. ( https://review.coreboot.org/c/coreboot/+/36528 )

Change subject: boot_state: Reduce precision of reported times
......................................................................

Patch Set 4: Code-Review+2

Change in coreboot[master]: boot_state: Reduce precision of reported times

[Marshall Dawson (Code Review)]

Marshall Dawson has posted comments on this change. ( https://review.coreboot.org/c/coreboot/+/36528 )

Change subject: boot_state: Reduce precision of reported times
......................................................................

Patch Set 4: Code-Review+2

(1 comment)

https://review.coreboot.org/c/coreboot/+/36528/3/src/lib/hardwaremain.c 
File src/lib/hardwaremain.c:

https://review.coreboot.org/c/coreboot/+/36528/3/src/lib/hardwaremain.c@261 
PS3, Line 261: 1000
> USECS_PER_MSEC

Done

Change in coreboot[master]: boot_state: Reduce precision of reported times

[Angel Pons (Code Review)]

Angel Pons has posted comments on this change. ( https://review.coreboot.org/c/coreboot/+/36528 )

Change subject: boot_state: Reduce precision of reported times
......................................................................

Patch Set 4: Code-Review+2

Change in coreboot[master]: boot_state: Reduce precision of reported times

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

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

Change subject: boot_state: Reduce precision of reported times
......................................................................

boot_state: Reduce precision of reported times

When diffing boot logs, lines reporting times spent in each
boot_state always get highlighed due the little fluctuation
in microsecond-scale. Reduce the logged precision to
milliseconds to avoid that.

Change-Id: I7a27d6c250d8432131f30e9a4869cb45ad75d9fd
Signed-off-by: Kyösti Mälkki 
Reviewed-on: https://review.coreboot.org/c/coreboot/+/36528
Tested-by: build bot (Jenkins) 
Reviewed-by: Aaron Durbin 
Reviewed-by: Marshall Dawson 
Reviewed-by: Angel Pons 
---
M src/lib/hardwaremain.c
1 file changed, 7 insertions(+), 1 deletion(-)

Approvals:
  build bot (Jenkins): Verified
  Aaron Durbin: Looks good to me, approved
  Marshall Dawson: Looks good to me, approved
  Angel Pons: Looks good to me, approved

diff --git a/src/lib/hardwaremain.c b/src/lib/hardwaremain.c
index 2ff2b8c..51ff330 100644
--- a/src/lib/hardwaremain.c
+++ b/src/lib/hardwaremain.c
@@ -23,6 +23,7 @@
 #include <bootstate.h>
 #include <console/console.h>
 #include <console/post_codes.h>
+#include <commonlib/helpers.h>
 #include <cbmem.h>
 #include <version.h>
 #include <device/device.h>
@@ -256,7 +257,12 @@
    run_time = mono_time_diff_microseconds(&samples[1], &samples[2]);
    exit_time = mono_time_diff_microseconds(&samples[2], &samples[3]);

-	printk(BIOS_DEBUG, "BS: %s times (us): entry %ld run %ld exit %ld\n",
+	/* Report with millisecond precision to reduce log diffs. */
+	entry_time = DIV_ROUND_CLOSEST(entry_time, USECS_PER_MSEC);
+	run_time = DIV_ROUND_CLOSEST(run_time, USECS_PER_MSEC);
+	exit_time = DIV_ROUND_CLOSEST(exit_time, USECS_PER_MSEC);
+
+	printk(BIOS_DEBUG, "BS: %s times (ms): entry %ld run %ld exit %ld\n",
           state->name, entry_time, run_time, exit_time);
 }
 #else