[coreboot-gerrit] Change in coreboot[master]: [WIP] boot state: Exclude printk() from reported times

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

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

Change subject: [WIP] boot_state: Exclude printk() from reported times
......................................................................

[WIP] boot_state: Exclude printk() from reported times

Change-Id: Id3998bab553ff803a93257a3f2c7bfea44c31729
Signed-off-by: Kyösti Mälkki 
---
M src/console/printk.c
M src/include/console/console.h
M src/lib/hardwaremain.c
3 files changed, 33 insertions(+), 0 deletions(-)

git pull ssh://review.coreboot.org:29418/coreboot refs/changes/74/36574/1

diff --git a/src/console/printk.c b/src/console/printk.c
index 15c599d..e398c37 100644
--- a/src/console/printk.c
+++ b/src/console/printk.c
@@ -21,6 +21,7 @@
 #include <smp/node.h>
 #include <stddef.h>
 #include <trace.h>
+#include <timer.h>

#if (!defined(__PRE_RAM__) && CONFIG(HAVE_ROMSTAGE_CONSOLE_SPINLOCK)) || !CONFIG(HAVE_ROMSTAGE_CONSOLE_SPINLOCK)
 DECLARE_SPIN_LOCK(console_lock)
@@ -44,6 +45,7 @@
 int do_vprintk(int msg_level, const char *fmt, va_list args)
 {
    int i, log_this;
+	struct mono_time mt_start, mt_stop;

if (CONFIG(SQUELCH_EARLY_SMP) && ENV_ROMSTAGE_OR_BEFORE && !boot_cpu())
    	return 0;
@@ -61,6 +63,9 @@
    spin_lock(&console_lock);
 #endif

+	if (CONFIG(HAVE_MONOTONIC_TIMER))
+		timer_monotonic_get(&mt_start);
+
    if (log_this == CONSOLE_LOG_FAST) {
    	i = vtxprintf(wrap_putchar_cbmemc, fmt, args, NULL);
    } else {
@@ -68,6 +73,12 @@
    	console_tx_flush();
    }

+	if (CONFIG(HAVE_MONOTONIC_TIMER)) {
+		timer_monotonic_get(&mt_stop);
+		if (ENV_RAMSTAGE)
+			console_accumulate_time(&mt_start, &mt_stop);
+	}
+
 #ifdef __PRE_RAM__
 #if CONFIG(HAVE_ROMSTAGE_CONSOLE_SPINLOCK)
    spin_unlock(romstage_console_lock());
diff --git a/src/include/console/console.h b/src/include/console/console.h
index 1c2a276..11e16c9 100644
--- a/src/include/console/console.h
+++ b/src/include/console/console.h
@@ -53,6 +53,10 @@
  */
 void die_notify(void);

+struct mono_time;
+void console_accumulate_time(const struct mono_time *start,
+			     const struct mono_time *stop);
+
 #define __CONSOLE_ENABLE__ \
    ((ENV_BOOTBLOCK && CONFIG(BOOTBLOCK_CONSOLE)) || \
    (ENV_POSTCAR && CONFIG(POSTCAR_CONSOLE)) || \
diff --git a/src/lib/hardwaremain.c b/src/lib/hardwaremain.c
index 51ff330..98a0c12 100644
--- a/src/lib/hardwaremain.c
+++ b/src/lib/hardwaremain.c
@@ -63,6 +63,7 @@
 struct boot_state_times {
    int num_samples;
    struct mono_time samples[MAX_TIME_SAMPLES];
+	long console_usecs[MAX_TIME_SAMPLES];
 };

/* The prologue (BS_ON_ENTRY) and epilogue (BS_ON_EXIT) of a state can be
@@ -237,15 +238,28 @@
 }

#if CONFIG(HAVE_MONOTONIC_TIMER)
+
+static long *console_usecs;
+
 static void bs_sample_time(struct boot_state *state)
 {
    struct mono_time *mt;

+	console_usecs = &state->times.console_usecs[state->times.num_samples];
+	*console_usecs = 0;
+
    mt = &state->times.samples[state->times.num_samples];
    timer_monotonic_get(mt);
    state->times.num_samples++;
 }

+void console_accumulate_time(const struct mono_time *start,
+			     const struct mono_time *stop)
+{
+	if (console_usecs)
+		*console_usecs += mono_time_diff_microseconds(start, stop);
+}
+
 static void bs_report_time(struct boot_state *state)
 {
    long entry_time;
@@ -257,6 +271,10 @@
    run_time = mono_time_diff_microseconds(&samples[1], &samples[2]);
    exit_time = mono_time_diff_microseconds(&samples[2], &samples[3]);

+	entry_time -= state->times.console_usecs[0];
+	run_time -= state->times.console_usecs[1];
+	exit_time -= state->times.console_usecs[2];
+
    /* 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);