lib/hardwaremain: Print individual boot state callback durations

This is useful when trying to find which callbacks are taking the
longest time.

BUG=b:179092979
TEST=See bootstate durations in logs
BS: callback (0xcb79d4d8) @ src/security/vboot/bootmode.c:53 (0 ms).
BS: callback (0xcb79cf20) @ src/vendorcode/google/chromeos/ramoops.c:30 (0 ms).
BS: callback (0xcb79cef0) @ src/vendorcode/google/chromeos/cr50_enable_update.c:160 (18 ms).

Signed-off-by: Raul E Rangel <rrangel@chromium.org>
Change-Id: Ifb145fea32ad4e0b694bdb7cdcdd43dce4cc0d27
Reviewed-on: https://review.coreboot.org/c/coreboot/+/55374
Reviewed-by: Angel Pons <th3fanbus@gmail.com>
Reviewed-by: Julius Werner <jwerner@chromium.org>
Tested-by: build bot (Jenkins) <no-reply@coreboot.org>
This commit is contained in:
Raul E Rangel 2021-06-09 16:49:53 -06:00 committed by Werner Zeh
parent 83156682d6
commit cb42874231
1 changed files with 9 additions and 0 deletions

View File

@ -264,6 +264,7 @@ static void bs_call_callbacks(struct boot_state *state,
boot_state_sequence_t seq)
{
struct boot_phase *phase = &state->phases[seq];
struct mono_time mt_start, mt_stop;
while (1) {
if (phase->callbacks != NULL) {
@ -277,8 +278,16 @@ static void bs_call_callbacks(struct boot_state *state,
if (CONFIG(DEBUG_BOOT_STATE)) {
printk(BIOS_DEBUG, "BS: callback (%p) @ %s.\n",
bscb, bscb_location(bscb));
timer_monotonic_get(&mt_start);
}
bscb->callback(bscb->arg);
if (CONFIG(DEBUG_BOOT_STATE)) {
timer_monotonic_get(&mt_stop);
printk(BIOS_DEBUG, "BS: callback (%p) @ %s (%ld ms).\n", bscb,
bscb_location(bscb),
mono_time_diff_microseconds(&mt_start, &mt_stop)
/ USECS_PER_MSEC);
}
continue;
}