summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
Diffstat
-rw-r--r--src/include/timestamp.h18
-rw-r--r--src/lib/loaders/load_and_run_romstage.c3
-rw-r--r--src/lib/lzma.c4
-rw-r--r--src/lib/timestamp.c2
-rw-r--r--src/vendorcode/google/chromeos/vboot2/vboot_handoff.c6
-rw-r--r--src/vendorcode/google/chromeos/vboot2/verstage.c36
-rw-r--r--src/vendorcode/google/chromeos/vboot2/verstub.c26
-rw-r--r--util/cbmem/cbmem.c52
8 files changed, 108 insertions, 39 deletions
diff --git a/src/include/timestamp.h b/src/include/timestamp.h
index c2bc6f148f..cd648ea00b 100644
--- a/src/include/timestamp.h
+++ b/src/include/timestamp.h
@@ -46,6 +46,10 @@ enum timestamp_id {
TS_START_RAMSTAGE = 10,
TS_START_BOOTBLOCK = 11,
TS_END_BOOTBLOCK = 12,
+ TS_START_COPYROM = 13,
+ TS_END_COPYROM = 14,
+ TS_START_ULZMA = 15,
+ TS_END_ULZMA = 16,
TS_DEVICE_ENUMERATE = 30,
TS_FSP_BEFORE_ENUMERATE,
TS_FSP_AFTER_ENUMERATE,
@@ -60,6 +64,20 @@ enum timestamp_id {
TS_LOAD_PAYLOAD = 90,
TS_ACPI_WAKE_JUMP = 98,
TS_SELFBOOT_JUMP = 99,
+
+ /* 500+ reserved for vendorcode extensions (500-600: google/chromeos) */
+ TS_START_COPYVER = 501,
+ TS_END_COPYVER = 502,
+ TS_START_TPMINIT = 503,
+ TS_END_TPMINIT = 504,
+ TS_START_VERIFY_SLOT = 505,
+ TS_END_VERIFY_SLOT = 506,
+ TS_START_HASH_BODY = 507,
+ TS_DONE_LOADING = 508,
+ TS_DONE_HASHING = 509,
+ TS_END_HASH_BODY = 510,
+
+ /* 1000+ reserved for payloads (1000-1200: ChromeOS depthcharge) */
};
#if CONFIG_COLLECT_TIMESTAMPS && (CONFIG_EARLY_CBMEM_INIT || !defined(__PRE_RAM__))
diff --git a/src/lib/loaders/load_and_run_romstage.c b/src/lib/loaders/load_and_run_romstage.c
index 8467e90129..9bd9603bab 100644
--- a/src/lib/loaders/load_and_run_romstage.c
+++ b/src/lib/loaders/load_and_run_romstage.c
@@ -24,6 +24,7 @@
#include <cbfs.h>
#include <halt.h>
#include <program_loading.h>
+#include <timestamp.h>
void run_romstage(void)
{
@@ -32,11 +33,13 @@ void run_romstage(void)
.type = PROG_ROMSTAGE,
};
+ timestamp_add_now(TS_START_COPYROM);
if (cbfs_load_prog_stage(CBFS_DEFAULT_MEDIA, &romstage) < 0) {
if (IS_ENABLED(CONFIG_BOOTBLOCK_CONSOLE))
die("Couldn't load romstage.\n");
halt();
}
+ timestamp_add_now(TS_END_COPYROM);
prog_run(&romstage);
}
diff --git a/src/lib/lzma.c b/src/lib/lzma.c
index 8efa1e6e1a..89e4d97600 100644
--- a/src/lib/lzma.c
+++ b/src/lib/lzma.c
@@ -12,6 +12,7 @@
#include <console/console.h>
#include <string.h>
#include <lib.h>
+#include <timestamp.h>
#include "lzmadecode.h"
@@ -27,6 +28,8 @@ unsigned long ulzma(unsigned char * src, unsigned char * dst)
MAYBE_STATIC unsigned char scratchpad[15980];
unsigned char *cp;
+ /* Note: these timestamps aren't useful for memory-mapped media (x86) */
+ timestamp_add_now(TS_START_ULZMA);
memcpy(properties, src, LZMA_PROPERTIES_SIZE);
/* The outSize in LZMA stream is a 64bit integer stored in little-endian
* (ref: lzma.cc@LZMACompress: put_64). To prevent accessing by
@@ -50,5 +53,6 @@ unsigned long ulzma(unsigned char * src, unsigned char * dst)
printk(BIOS_WARNING, "lzma: Decoding error = %d\n", res);
return 0;
}
+ timestamp_add_now(TS_END_ULZMA);
return outSize;
}
diff --git a/src/lib/timestamp.c b/src/lib/timestamp.c
index 67635f87ed..5846781706 100644
--- a/src/lib/timestamp.c
+++ b/src/lib/timestamp.c
@@ -25,7 +25,7 @@
#include <arch/early_variables.h>
#include <smp/node.h>
-#define MAX_TIMESTAMPS 30
+#define MAX_TIMESTAMPS 60
static struct timestamp_table* ts_table_p CAR_GLOBAL = NULL;
static uint64_t ts_basetime CAR_GLOBAL = 0;
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 <arch/exception.h>
#include <console/console.h>
#include <console/vtxprintf.h>
+#include <delay.h>
#include <string.h>
+#include <timestamp.h>
#include <vb2_api.h>
#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 <cbfs.h>
#include <console/console.h>
#include <string.h>
+#include <timestamp.h>
#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);
diff --git a/util/cbmem/cbmem.c b/util/cbmem/cbmem.c
index 7c96c6e5ce..042159192b 100644
--- a/util/cbmem/cbmem.c
+++ b/util/cbmem/cbmem.c
@@ -334,24 +334,17 @@ u64 arch_convert_raw_ts_entry(u64 ts)
/*
* Print an integer in 'normalized' form - with commas separating every three
- * decimal orders. The 'comma' parameter indicates if a comma is needed after
- * the value is printed.
+ * decimal orders.
*/
-static void print_norm(u64 v, int comma)
+static void print_norm(u64 v)
{
- int first_triple = 1;
-
- if (v > 1000) {
+ if (v >= 1000) {
/* print the higher order sections first */
- print_norm(v / 1000, 1);
- first_triple = 0;
+ print_norm(v / 1000);
+ printf(",%3.3u", (u32)(v % 1000));
+ } else {
+ printf("%u", (u32)(v % 1000));
}
- if (first_triple)
- printf("%d", (u32)(v % 1000));
- else
- printf("%3.3d", (u32)(v % 1000));
- if (comma)
- printf(",");
}
enum additional_timestamp_id {
@@ -381,11 +374,15 @@ static const struct timestamp_id_to_name {
{ TS_END_ROMSTAGE, "end of romstage" },
{ TS_START_VBOOT, "start of verified boot" },
{ TS_END_VBOOT, "end of verified boot" },
- { TS_START_COPYRAM, "start of copying ram stage" },
- { TS_END_COPYRAM, "end of copying ram stage" },
+ { TS_START_COPYRAM, "starting to load ramstage" },
+ { TS_END_COPYRAM, "finished loading ramstage" },
{ TS_START_RAMSTAGE, "start of ramstage" },
- { TS_START_BOOTBLOCK, "start of bootblock" },
- { TS_END_BOOTBLOCK, "end of bootblock" },
+ { TS_START_BOOTBLOCK, "start of bootblock" },
+ { TS_END_BOOTBLOCK, "end of bootblock" },
+ { TS_START_COPYROM, "starting to load romstage" },
+ { TS_END_COPYROM, "finished loading romstage" },
+ { TS_START_ULZMA, "starting LZMA decompress (ignore for x86)" },
+ { TS_END_ULZMA, "finished LZMA decompress (ignore for x86)" },
{ TS_DEVICE_ENUMERATE, "device enumeration" },
{ TS_DEVICE_CONFIGURE, "device configuration" },
{ TS_DEVICE_ENABLE, "device enable" },
@@ -396,6 +393,18 @@ static const struct timestamp_id_to_name {
{ TS_LOAD_PAYLOAD, "load payload" },
{ TS_ACPI_WAKE_JUMP, "ACPI wake jump" },
{ TS_SELFBOOT_JUMP, "selfboot jump" },
+
+ { TS_START_COPYVER, "starting to load verstage" },
+ { TS_END_COPYVER, "finished loading verstage" },
+ { TS_START_TPMINIT, "starting to initialize TPM" },
+ { TS_END_TPMINIT, "finished TPM initialization" },
+ { TS_START_VERIFY_SLOT, "starting to verify keyblock/preamble (RSA)" },
+ { TS_END_VERIFY_SLOT, "finished verifying keyblock/preamble (RSA)" },
+ { TS_START_HASH_BODY, "starting to verify body (load+SHA2+RSA) " },
+ { TS_DONE_LOADING, "finished loading body (ignore for x86)" },
+ { TS_DONE_HASHING, "finished calculating body hash (SHA2)" },
+ { TS_END_HASH_BODY, "finished verifying body signature (RSA)" },
+
{ TS_DC_START, "depthcharge start" },
{ TS_RO_PARAMS_INIT, "RO parameter init" },
{ TS_RO_VB_INIT, "RO vboot init" },
@@ -421,12 +430,11 @@ void timestamp_print_entry(uint32_t id, uint64_t stamp, uint64_t prev_stamp)
}
printf("%4d:", id);
- printf("%-30s", name);
- print_norm(arch_convert_raw_ts_entry(stamp), 0);
+ printf("%-50s", name);
+ print_norm(arch_convert_raw_ts_entry(stamp));
if (prev_stamp) {
printf(" (");
- print_norm(arch_convert_raw_ts_entry(stamp
- - prev_stamp), 0);
+ print_norm(arch_convert_raw_ts_entry(stamp - prev_stamp));
printf(")");
}
printf("\n");
generated by cgit v1.2.3 (git 2.25.1) at 2024-11-10 00:55:46 +0000