timestamp,amd/common/apob_cache: Add timestamps for APOB

Updating the APOB takes a considerable amount of time. I decided to be
granular and split out the operations so we know when we read vs read +
erase + write.

BUG=b:179092979
TEST=Boot guybrush and dump timestamps
   3:after RAM initialization                          3,025,425 (44)
 920:starting APOB read                                3,025,430 (5)
 921:starting APOB erase                               3,025,478 (48)
 922:starting APOB write                               3,027,727 (2,249)
 923:finished APOB                                     3,210,965 (183,238)
   4:end of romstage                                   3,210,971 (6)

Signed-off-by: Raul E Rangel <rrangel@chromium.org>
Change-Id: I08e371873112e38f623f452af0eb946f5471c399
Reviewed-on: https://review.coreboot.org/c/coreboot/+/55401
Tested-by: build bot (Jenkins) <no-reply@coreboot.org>
Reviewed-by: Angel Pons <th3fanbus@gmail.com>

2 files changed, 22 insertions, 3 deletions

diff --git a/src/commonlib/include/commonlib/timestamp_serialized.h b/src/commonlib/include/commonlib/timestamp_serialized.h
index a69e1d3539..1351afacf3 100644
--- a/src/commonlib/include/commonlib/timestamp_serialized.h
+++ b/src/commonlib/include/commonlib/timestamp_serialized.h
@@ -78,7 +78,7 @@ enum timestamp_id {
 	TS_END_COPYVPD_RO = 551,
 	TS_END_COPYVPD_RW = 552,
 
-	/* 900-920 reserved for vendorcode extensions (900-940: AMD AGESA) */
+	/* 900-940 reserved for vendorcode extensions (900-940: AMD) */
 	TS_AGESA_INIT_RESET_START = 900,
 	TS_AGESA_INIT_RESET_DONE = 901,
 	TS_AGESA_INIT_EARLY_START = 902,
@@ -99,6 +99,10 @@ enum timestamp_id {
 	TS_AGESA_S3_LATE_DONE = 917,
 	TS_AGESA_S3_FINAL_START = 918,
 	TS_AGESA_S3_FINAL_DONE = 919,
+	TS_AMD_APOB_READ_START = 920,
+	TS_AMD_APOB_ERASE_START = 921,
+	TS_AMD_APOB_WRITE_START = 922,
+	TS_AMD_APOB_DONE = 923,
 
 	/* 940-950 reserved for vendorcode extensions (940-950: Intel ME) */
 	TS_ME_INFORM_DRAM_WAIT = 940,
@@ -222,7 +226,7 @@ static const struct timestamp_id_to_name {
 	{ TS_KERNEL_DECOMPRESSION, "starting kernel decompression/relocation" },
 	{ TS_START_KERNEL,	"jumping to kernel" },
 
-	/* AMD AGESA related timestamps */
+	/* AMD related timestamps */
 	{ TS_AGESA_INIT_RESET_START,	"calling AmdInitReset" },
 	{ TS_AGESA_INIT_RESET_DONE,	"back from AmdInitReset" },
 	{ TS_AGESA_INIT_EARLY_START,	"calling AmdInitEarly" },
@@ -243,6 +247,10 @@ static const struct timestamp_id_to_name {
 	{ TS_AGESA_S3_LATE_DONE,	"back from AmdS3LateRestore" },
 	{ TS_AGESA_S3_FINAL_START,	"calling AmdS3FinalRestore" },
 	{ TS_AGESA_S3_FINAL_DONE,	"back from AmdS3FinalRestore" },
+	{ TS_AMD_APOB_READ_START,	"starting APOB read" },
+	{ TS_AMD_APOB_ERASE_START,	"starting APOB erase" },
+	{ TS_AMD_APOB_WRITE_START,	"starting APOB write" },
+	{ TS_AMD_APOB_DONE,		"finished APOB" },
 
 	/* Intel ME related timestamps */
 	{ TS_ME_INFORM_DRAM_WAIT,	"waiting for ME acknowledgement of raminit"},
diff --git a/src/soc/amd/common/block/apob/apob_cache.c b/src/soc/amd/common/block/apob/apob_cache.c
index 6b31143f84..238ae7af2a 100644
--- a/src/soc/amd/common/block/apob/apob_cache.c
+++ b/src/soc/amd/common/block/apob/apob_cache.c
@@ -10,6 +10,7 @@
 #include <spi_flash.h>
 #include <stdint.h>
 #include <string.h>
+#include <timestamp.h>
 
 #define DEFAULT_MRC_CACHE "RW_MRC_CACHE"
 /* PSP requires this value to be 64KiB */
@@ -114,6 +115,8 @@ void soc_update_apob_cache(void)
 	if (get_nv_region(&region) != 0)
 		return;
 
+	timestamp_add_now(TS_AMD_APOB_READ_START);
+
 	apob_rom = get_apob_from_nv_region(&region);
 	if (apob_rom == NULL) {
 		update_needed = true;
@@ -123,8 +126,10 @@ void soc_update_apob_cache(void)
 	} else
 		printk(BIOS_DEBUG, "APOB valid copy is already in flash\n");
 
-	if (!update_needed)
+	if (!update_needed) {
+		timestamp_add_now(TS_AMD_APOB_DONE);
 		return;
+	}
 
 	printk(BIOS_SPEW, "Copy APOB from RAM 0x%p/0x%x to flash 0x%zx/0x%zx\n",
 		apob_src_ram, apob_src_ram->size,
@@ -135,17 +140,23 @@ void soc_update_apob_cache(void)
 		return;
 	}
 
+	timestamp_add_now(TS_AMD_APOB_ERASE_START);
+
 	/* write data to flash region */
 	if (rdev_eraseat(&write_rdev, 0, DEFAULT_MRC_CACHE_SIZE) < 0) {
 		printk(BIOS_ERR, "Error: APOB flash region erase failed\n");
 		return;
 	}
 
+	timestamp_add_now(TS_AMD_APOB_WRITE_START);
+
 	if (rdev_writeat(&write_rdev, apob_src_ram, 0, apob_src_ram->size) < 0) {
 		printk(BIOS_ERR, "Error: APOB flash region update failed\n");
 		return;
 	}
 
+	timestamp_add_now(TS_AMD_APOB_DONE);
+
 	printk(BIOS_INFO, "Updated APOB in flash\n");
 }