Kyösti Mälkki has submitted this change. ( https://review.coreboot.org/c/coreboot/+/37396 )
Change subject: Revert "console,boot_state: Exclude printk() from reported times" ......................................................................
Revert "console,boot_state: Exclude printk() from reported times"
The code in cpu/x86/lapic/apic_timer.c for timer_monotonic_get() is not SMP safe as LAPIC timers do not run as synchronised as TSCs. So the reported times with LAPIC_MONOTONIC_TIMER=y at least were incorrect.
Since the approach for this improved times reporting was not completed wrt. the output format either, revert it from 4.11_branch.
Change-Id: Ie7edae572cf4fee0b9d2497f7690145c2699a809 Signed-off-by: Kyösti Mälkki kyosti.malkki@gmail.com Reviewed-on: https://review.coreboot.org/c/coreboot/+/37396 Tested-by: build bot (Jenkins) no-reply@coreboot.org Reviewed-by: Angel Pons th3fanbus@gmail.com Reviewed-by: Werner Zeh werner.zeh@siemens.com Reviewed-by: Frans Hendriks fhendriks@eltan.com --- M src/arch/x86/postcar_loader.c M src/console/printk.c M src/include/console/console.h M src/lib/hardwaremain.c M src/lib/prog_loaders.c 5 files changed, 0 insertions(+), 67 deletions(-)
Approvals: build bot (Jenkins): Verified Werner Zeh: Looks good to me, approved Frans Hendriks: Looks good to me, but someone else must approve Angel Pons: Looks good to me, approved
diff --git a/src/arch/x86/postcar_loader.c b/src/arch/x86/postcar_loader.c index b53cbf8..868b770 100644 --- a/src/arch/x86/postcar_loader.c +++ b/src/arch/x86/postcar_loader.c @@ -228,8 +228,6 @@ /* As postcar exist, it's end of romstage here */ timestamp_add_now(TS_END_ROMSTAGE);
- console_time_report(); - prog_set_arg(&prog, cbmem_top());
prog_run(&prog); diff --git a/src/console/printk.c b/src/console/printk.c index 4f9f547..15c599d 100644 --- a/src/console/printk.c +++ b/src/console/printk.c @@ -21,56 +21,14 @@ #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) #endif
-#define TRACK_CONSOLE_TIME (CONFIG(HAVE_MONOTONIC_TIMER) && \ - (ENV_RAMSTAGE || !CONFIG(CAR_GLOBAL_MIGRATION))) - -static struct mono_time mt_start, mt_stop; -static long console_usecs; - -static void console_time_run(void) -{ - if (TRACK_CONSOLE_TIME) - timer_monotonic_get(&mt_start); -} - -static void console_time_stop(void) -{ - if (TRACK_CONSOLE_TIME) { - timer_monotonic_get(&mt_stop); - console_usecs += mono_time_diff_microseconds(&mt_start, &mt_stop); - } -} - -void console_time_report(void) -{ - if (!TRACK_CONSOLE_TIME) - return; - - printk(BIOS_DEBUG, "Accumulated console time in " ENV_STRING " %ld ms\n", - DIV_ROUND_CLOSEST(console_usecs, USECS_PER_MSEC)); -} - -long console_time_get_and_reset(void) -{ - if (!TRACK_CONSOLE_TIME) - return 0; - - long elapsed = console_usecs; - console_usecs = 0; - return elapsed; -} - void do_putchar(unsigned char byte) { - console_time_run(); console_tx_byte(byte); - console_time_stop(); }
static void wrap_putchar(unsigned char byte, void *data) @@ -103,8 +61,6 @@ spin_lock(&console_lock); #endif
- console_time_run(); - if (log_this == CONSOLE_LOG_FAST) { i = vtxprintf(wrap_putchar_cbmemc, fmt, args, NULL); } else { @@ -112,8 +68,6 @@ console_tx_flush(); }
- console_time_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 607c968..1c2a276 100644 --- a/src/include/console/console.h +++ b/src/include/console/console.h @@ -64,11 +64,6 @@ int console_log_level(int msg_level); void do_putchar(unsigned char byte);
-/* Return number of microseconds elapsed from start of stage or the previous - get_and_reset() call. */ -long console_time_get_and_reset(void); -void console_time_report(void); - #define printk(LEVEL, fmt, args...) do_printk(LEVEL, fmt, ##args) #define vprintk(LEVEL, fmt, args) do_vprintk(LEVEL, fmt, args)
@@ -92,8 +87,6 @@ static inline void printk(int LEVEL, const char *fmt, ...) {} static inline void vprintk(int LEVEL, const char *fmt, va_list args) {} static inline void do_putchar(unsigned char byte) {} -static inline long console_time_get_and_reset(void) { return 0; } -static inline void console_time_report(void) {} #endif
int do_printk(int msg_level, const char *fmt, ...) diff --git a/src/lib/hardwaremain.c b/src/lib/hardwaremain.c index 3fcf882..51ff330 100644 --- a/src/lib/hardwaremain.c +++ b/src/lib/hardwaremain.c @@ -63,7 +63,6 @@ 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 @@ -242,9 +241,6 @@ { struct mono_time *mt;
- long console_usecs = console_time_get_and_reset(); - state->times.console_usecs[state->times.num_samples] = console_usecs; - mt = &state->times.samples[state->times.num_samples]; timer_monotonic_get(mt); state->times.num_samples++; @@ -261,10 +257,6 @@ 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[1]; - run_time -= state->times.console_usecs[2]; - exit_time -= state->times.console_usecs[3]; - /* 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); diff --git a/src/lib/prog_loaders.c b/src/lib/prog_loaders.c index 5787496..7f320d9 100644 --- a/src/lib/prog_loaders.c +++ b/src/lib/prog_loaders.c @@ -70,8 +70,6 @@
timestamp_add_now(TS_END_COPYROM);
- console_time_report(); - prog_run(&romstage);
fail: @@ -155,8 +153,6 @@
timestamp_add_now(TS_END_COPYRAM);
- console_time_report(); - /* This overrides the arg fetched from the relocatable module */ prog_set_arg(&ramstage, cbmem_top());