From a7d924412a4300e91b3bd6eb3581b954b02f8d37 Mon Sep 17 00:00:00 2001 From: Julius Werner Date: Tue, 2 Dec 2014 20:51:19 -0800 Subject: timestamps: You can never have enough of them! Now that we have timestamps in pre-RAM stages, let's actually make use of them. This patch adds several timestamps to both the bootblock and especially the verstage to allow more fine-grained boot time tracking. Some of the introduced timestamps can appear more than once per boot. This doesn't seem to be a problem for both coreboot and the cbmem utility, and the context makes it clear which operation was timestamped at what point. Also simplifies cbmem's timestamp printing routine a bit, fixing a display bug when a timestamp had a section of exactly ",000," in it (e.g. 1,000,185). BRANCH=None BUG=None TEST=Booted Pinky, Blaze and Falco, confirmed that all timestamps show up and contained sane values. Booted Storm (no timestamps here since it doesn't support pre-RAM timestamps yet). Change-Id: I7f4d6aba3ebe3db0d003c7bcb2954431b74961b3 Signed-off-by: Patrick Georgi Original-Commit-Id: 7a2ce81722aba85beefcc6c81f9908422b8da8fa Original-Change-Id: I5979bfa9445a9e0aba98ffdf8006c21096743456 Original-Signed-off-by: Julius Werner Original-Reviewed-on: https://chromium-review.googlesource.com/234063 Original-Reviewed-by: Aaron Durbin Reviewed-on: http://review.coreboot.org/9608 Tested-by: build bot (Jenkins) Reviewed-by: Stefan Reinauer --- .../google/chromeos/vboot2/vboot_handoff.c | 6 +++- src/vendorcode/google/chromeos/vboot2/verstage.c | 36 +++++++++++++++++++--- src/vendorcode/google/chromeos/vboot2/verstub.c | 26 +++++++++------- 3 files changed, 52 insertions(+), 16 deletions(-) (limited to 'src/vendorcode/google/chromeos') diff --git a/src/vendorcode/google/chromeos/vboot2/vboot_handoff.c b/src/vendorcode/google/chromeos/vboot2/vboot_handoff.c index 7e91432029..a5c7de617c 100644 --- a/src/vendorcode/google/chromeos/vboot2/vboot_handoff.c +++ b/src/vendorcode/google/chromeos/vboot2/vboot_handoff.c @@ -40,6 +40,7 @@ static void *load_ramstage(struct vboot_handoff *vboot_handoff, struct vboot_region *fw_main) { struct vboot_components *fw_info; + void *ret; int i; fw_info = vboot_locate_components(fw_main); @@ -53,7 +54,10 @@ static void *load_ramstage(struct vboot_handoff *vboot_handoff, vboot_handoff->components[i].size = fw_info->entries[i].size; } - return vboot_load_stage(CONFIG_VBOOT_RAMSTAGE_INDEX, fw_main, fw_info); + timestamp_add_now(TS_START_COPYRAM); + ret = vboot_load_stage(CONFIG_VBOOT_RAMSTAGE_INDEX, fw_main, fw_info); + timestamp_add_now(TS_END_COPYRAM); + return ret; } /** diff --git a/src/vendorcode/google/chromeos/vboot2/verstage.c b/src/vendorcode/google/chromeos/vboot2/verstage.c index 289b93fefc..569e6e569c 100644 --- a/src/vendorcode/google/chromeos/vboot2/verstage.c +++ b/src/vendorcode/google/chromeos/vboot2/verstage.c @@ -21,7 +21,9 @@ #include #include #include +#include #include +#include #include #include "../chromeos.h" @@ -91,12 +93,22 @@ int vb2ex_read_resource(struct vb2_context *ctx, static int hash_body(struct vb2_context *ctx, struct vboot_region *fw_main) { + uint64_t load_ts; uint32_t expected_size; MAYBE_STATIC uint8_t block[TODO_BLOCK_SIZE]; size_t block_size = sizeof(block); uintptr_t offset; int rv; + /* + * Since loading the firmware and calculating its hash is intertwined, + * we use this little trick to measure them separately and pretend it + * was first loaded and then hashed in one piece with the timestamps. + * (This split won't make sense with memory-mapped media like on x86.) + */ + load_ts = timestamp_get(); + timestamp_add(TS_START_HASH_BODY, load_ts); + expected_size = fw_main->size; offset = fw_main->offset_addr; @@ -107,13 +119,17 @@ static int hash_body(struct vb2_context *ctx, struct vboot_region *fw_main) /* Extend over the body */ while (expected_size) { + uint64_t temp_ts; void *b; if (block_size > expected_size) block_size = expected_size; + temp_ts = timestamp_get(); b = vboot_get_region(offset, block_size, block); if (b == NULL) return VB2_ERROR_UNKNOWN; + load_ts += timestamp_get() - temp_ts; + rv = vb2api_extend_hash(ctx, b, block_size); if (rv) return rv; @@ -122,11 +138,16 @@ static int hash_body(struct vb2_context *ctx, struct vboot_region *fw_main) offset += block_size; } - /* Check the result */ + timestamp_add(TS_DONE_LOADING, load_ts); + timestamp_add_now(TS_DONE_HASHING); + + /* Check the result (with RSA signature verification) */ rv = vb2api_check_hash(ctx); if (rv) return rv; + timestamp_add_now(TS_END_HASH_BODY); + return VB2_SUCCESS; } @@ -173,6 +194,7 @@ void verstage_main(void) struct vboot_region fw_main; struct vb2_working_data *wd = vboot_get_working_data(); int rv; + timestamp_add_now(TS_START_VBOOT); /* Set up context and work buffer */ memset(&ctx, 0, sizeof(ctx)); @@ -185,7 +207,9 @@ void verstage_main(void) /* Read secdata from TPM. Initialize TPM if secdata not found. We don't * check the return value here because vb2api_fw_phase1 will catch * invalid secdata and tell us what to do (=reboot). */ + timestamp_add_now(TS_START_TPMINIT); antirollback_read_space_firmware(&ctx); + timestamp_add_now(TS_END_TPMINIT); if (get_developer_mode_switch()) ctx.flags |= VB2_CONTEXT_FORCE_DEVELOPER_MODE; @@ -194,17 +218,18 @@ void verstage_main(void) ctx.flags |= VB2_CONTEXT_FORCE_RECOVERY_MODE; } - /* Do early init */ + /* Do early init (set up secdata and NVRAM, load GBB) */ printk(BIOS_INFO, "Phase 1\n"); rv = vb2api_fw_phase1(&ctx); if (rv) { printk(BIOS_INFO, "Recovery requested (%x)\n", rv); /* If we need recovery mode, leave firmware selection now */ save_if_needed(&ctx); + timestamp_add_now(TS_END_VBOOT); return; } - /* Determine which firmware slot to boot */ + /* Determine which firmware slot to boot (based on NVRAM) */ printk(BIOS_INFO, "Phase 2\n"); rv = vb2api_fw_phase2(&ctx); if (rv) { @@ -213,9 +238,11 @@ void verstage_main(void) vboot_reboot(); } - /* Try that slot */ + /* Try that slot (verify its keyblock and preamble) */ printk(BIOS_INFO, "Phase 3\n"); + timestamp_add_now(TS_START_VERIFY_SLOT); rv = vb2api_fw_phase3(&ctx); + timestamp_add_now(TS_END_VERIFY_SLOT); if (rv) { printk(BIOS_INFO, "Reboot requested (%x)\n", rv); save_if_needed(&ctx); @@ -245,6 +272,7 @@ void verstage_main(void) printk(BIOS_INFO, "Slot %c is selected\n", is_slot_a(&ctx) ? 'A' : 'B'); vb2_set_selected_region(wd, &fw_main); + timestamp_add_now(TS_END_VBOOT); } #if IS_ENABLED(CONFIG_RETURN_FROM_VERSTAGE) diff --git a/src/vendorcode/google/chromeos/vboot2/verstub.c b/src/vendorcode/google/chromeos/vboot2/verstub.c index 8f2e9b2d49..323468333c 100644 --- a/src/vendorcode/google/chromeos/vboot2/verstub.c +++ b/src/vendorcode/google/chromeos/vboot2/verstub.c @@ -21,6 +21,7 @@ #include #include #include +#include #include "../chromeos.h" #include "misc.h" #include "symbols.h" @@ -58,20 +59,22 @@ void vboot2_verify_firmware(void) wd = init_vb2_working_data(); -#if CONFIG_RETURN_FROM_VERSTAGE - /* load verstage from RO */ - entry = cbfs_load_stage(CBFS_DEFAULT_MEDIA, - CONFIG_CBFS_PREFIX "/verstage"); - if (entry == (void *)-1) - die("failed to load verstage"); + if (IS_ENABLED(CONFIG_RETURN_FROM_VERSTAGE)) { + /* load verstage from RO */ + entry = cbfs_load_stage(CBFS_DEFAULT_MEDIA, + CONFIG_CBFS_PREFIX "/verstage"); + if (entry == (void *)-1) + die("failed to load verstage"); - /* verify and select a slot */ - stage_exit(entry); -#else - verstage_main(); -#endif /* CONFIG_RETURN_FROM_VERSTAGE */ + timestamp_add_now(TS_END_COPYVER); + /* verify and select a slot */ + stage_exit(entry); + } else { + verstage_main(); + } /* jump to the selected slot */ + timestamp_add_now(TS_START_COPYROM); entry = NULL; if (vboot_is_slot_selected(wd)) { /* RW A or B */ @@ -88,6 +91,7 @@ void vboot2_verify_firmware(void) entry = cbfs_load_stage(CBFS_DEFAULT_MEDIA, CONFIG_CBFS_PREFIX "/romstage"); } + timestamp_add_now(TS_END_COPYROM); if (entry != NULL && entry != (void *)-1) stage_exit(entry); -- cgit v1.2.3