[coreboot-gerrit] Change in coreboot[master]: security/vboot/sync_ec: Add timestamps

[Patrick Georgi (Code Review)]

Patrick Georgi has submitted this change. ( https://review.coreboot.org/c/coreboot/+/36209 )

Change subject: security/vboot/sync_ec: Add timestamps
......................................................................

security/vboot/sync_ec: Add timestamps

Add 4 new timestamps to the EC software sync flow:
1) Beginning of EC software sync
2) EC finished calculating Vboot hash
3) EC is no longer requesting power limiting
4) End of EC software sync

BUG=none
BRANCH=none
TEST=verified timestamps show up in cbmem log

Change-Id: I6e5703c146b5ec27d01700fdb39cb3d2092ea8a8
Signed-off-by: Tim Wawrzynczak 
Reviewed-on: https://review.coreboot.org/c/coreboot/+/36209
Tested-by: build bot (Jenkins) 
Reviewed-by: Julius Werner 
---
M src/commonlib/include/commonlib/timestamp_serialized.h
M src/security/vboot/ec_sync.c
2 files changed, 22 insertions(+), 6 deletions(-)

Approvals:
  build bot (Jenkins): Verified
  Julius Werner: Looks good to me, approved

diff --git a/src/commonlib/include/commonlib/timestamp_serialized.h b/src/commonlib/include/commonlib/timestamp_serialized.h
index 7b1a730..d7d636e 100644
--- a/src/commonlib/include/commonlib/timestamp_serialized.h
+++ b/src/commonlib/include/commonlib/timestamp_serialized.h
@@ -79,6 +79,10 @@
    TS_END_TPMPCR = 512,
    TS_START_TPMLOCK = 513,
    TS_END_TPMLOCK = 514,
+	TS_START_EC_SYNC = 515,
+	TS_EC_HASH_READY = 516,
+	TS_EC_POWER_LIMIT_WAIT = 517,
+	TS_END_EC_SYNC = 518,
    TS_START_COPYVPD = 550,
    TS_END_COPYVPD_RO = 551,
    TS_END_COPYVPD_RW = 552,
@@ -202,6 +206,11 @@
    { TS_END_COPYVPD_RO,	"finished loading Chrome OS VPD (RO)" },
    { TS_END_COPYVPD_RW,	"finished loading Chrome OS VPD (RW)" },

+	{ TS_START_EC_SYNC,	"starting EC software sync" },
+	{ TS_EC_HASH_READY,	"EC vboot hash ready" },
+	{ TS_EC_POWER_LIMIT_WAIT,	"waiting for EC to allow higher power draw" },
+	{ TS_END_EC_SYNC,	"finished EC software sync" },
+
    { TS_DC_START,		"depthcharge start" },
    { TS_RO_PARAMS_INIT,	"RO parameter init" },
    { TS_RO_VB_INIT,	"RO vboot init" },
diff --git a/src/security/vboot/ec_sync.c b/src/security/vboot/ec_sync.c
index ec048aa..c2a6b25 100644
--- a/src/security/vboot/ec_sync.c
+++ b/src/security/vboot/ec_sync.c
@@ -20,6 +20,7 @@
 #include <security/vboot/vbnv.h>
 #include <security/vboot/vboot_common.h>
 #include <timer.h>
+#include <timestamp.h>
 #include <vb2_api.h>

#define _EC_FILENAME(select, suffix) \
@@ -51,6 +52,8 @@
    vb2_error_t retval = VB2_SUCCESS;
    struct vb2_context *ctx;

+	timestamp_add_now(TS_START_EC_SYNC);
+
    ctx = vboot_get_context();
    ctx->flags |= VB2_CONTEXT_EC_SYNC_SUPPORTED;

@@ -61,6 +64,8 @@
    	printk(BIOS_ERR, "EC software sync failed (%#x), rebooting\n", retval);
    	vboot_reboot();
    }
+
+	timestamp_add_now(TS_END_EC_SYNC);
 }

/* Convert firmware image type into a flash offset */
@@ -138,6 +143,8 @@
    } while (resp.status == EC_VBOOT_HASH_STATUS_BUSY &&
    	 !stopwatch_expired(&sw));

+	timestamp_add_now(TS_EC_HASH_READY);
+
    if (resp.status != EC_VBOOT_HASH_STATUS_DONE) {
    	printk(BIOS_ERR, "%s: Hash status not done: %d\n", __func__,
    	       resp.status);
@@ -415,7 +422,6 @@
    int limit_power = 0;
    bool message_printed = false;
    struct stopwatch sw;
-	vb2_error_t rv = VB2_SUCCESS;
    int in_recovery = !!(ctx->flags & VB2_CONTEXT_RECOVERY_MODE);

/*
@@ -425,15 +431,16 @@
    if (in_recovery)
    	return VB2_SUCCESS;

+	timestamp_add_now(TS_EC_POWER_LIMIT_WAIT);
+
    stopwatch_init_msecs_expire(&sw, LIMIT_POWER_WAIT_TIMEOUT_MS);

-	/* Ensure we have enough power to continue booting */
+	/* Ensure we have enough power to continue booting. */
    while (1) {
    	if (google_chromeec_read_limit_power_request(&limit_power)) {
    		printk(BIOS_ERR, "Failed to check EC limit power"
    		       "flag.\n");
-			rv = VB2_ERROR_UNKNOWN;
-			break;
+			return VB2_ERROR_UNKNOWN;
    	}

if (!limit_power || stopwatch_expired(&sw))
@@ -451,13 +458,13 @@
    if (limit_power) {
    	printk(BIOS_INFO,
    	       "EC requests limited power usage. Request shutdown.\n");
-		rv = VBERROR_SHUTDOWN_REQUESTED;
+		return VBERROR_SHUTDOWN_REQUESTED;
    } else {
    	printk(BIOS_INFO, "Waited %luus to clear limit power flag.\n",
    		stopwatch_duration_usecs(&sw));
    }

-	return rv;
+	return VB2_SUCCESS;
 }

/*