From e81f20c36a1d2a29825ed60e543cfb427182ff7e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ky=C3=B6sti=20M=C3=A4lkki?= Date: Sun, 1 Dec 2019 08:38:11 +0200 Subject: [PATCH] Revert "console,boot_state: Exclude printk() from reported times" MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 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 Reviewed-on: https://review.coreboot.org/c/coreboot/+/37396 Tested-by: build bot (Jenkins) Reviewed-by: Angel Pons Reviewed-by: Werner Zeh Reviewed-by: Frans Hendriks --- src/arch/x86/postcar_loader.c | 2 -- src/console/printk.c | 46 ----------------------------------- src/include/console/console.h | 7 ------ src/lib/hardwaremain.c | 8 ------ src/lib/prog_loaders.c | 4 --- 5 files changed, 67 deletions(-) diff --git a/src/arch/x86/postcar_loader.c b/src/arch/x86/postcar_loader.c index b53cbf82af..868b770c18 100644 --- a/src/arch/x86/postcar_loader.c +++ b/src/arch/x86/postcar_loader.c @@ -228,8 +228,6 @@ void run_postcar_phase(struct postcar_frame *pcf) /* 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 4f9f547bc5..15c599dce0 100644 --- a/src/console/printk.c +++ b/src/console/printk.c @@ -21,56 +21,14 @@ #include #include #include -#include #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 @@ int do_vprintk(int msg_level, const char *fmt, va_list args) 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 @@ int do_vprintk(int msg_level, const char *fmt, va_list args) 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 607c96862e..1c2a276af0 100644 --- a/src/include/console/console.h +++ b/src/include/console/console.h @@ -64,11 +64,6 @@ asmlinkage void console_init(void); 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 int console_log_level(int msg_level) { return 0; } 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 3fcf8829f3..51ff330d84 100644 --- a/src/lib/hardwaremain.c +++ b/src/lib/hardwaremain.c @@ -63,7 +63,6 @@ static boot_state_t bs_payload_boot(void *arg); 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 @@ static void bs_sample_time(struct boot_state *state) { 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 @@ static void bs_report_time(struct boot_state *state) 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 57874967ec..7f320d9597 100644 --- a/src/lib/prog_loaders.c +++ b/src/lib/prog_loaders.c @@ -70,8 +70,6 @@ void run_romstage(void) timestamp_add_now(TS_END_COPYROM); - console_time_report(); - prog_run(&romstage); fail: @@ -155,8 +153,6 @@ void run_ramstage(void) timestamp_add_now(TS_END_COPYRAM); - console_time_report(); - /* This overrides the arg fetched from the relocatable module */ prog_set_arg(&ramstage, cbmem_top());