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>
This commit is contained in:
parent
c3a8d63788
commit
e81f20c36a
|
@ -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);
|
||||
|
|
|
@ -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 @@ 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());
|
||||
|
|
|
@ -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, ...)
|
||||
|
|
|
@ -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);
|
||||
|
|
|
@ -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());
|
||||
|
||||
|
|
Loading…
Reference in New Issue