ap RO verification: enable logging

When AP RO verification is attempted, a lot of thing could go wrong,
and the operator would usually have very little insight into what's
happening unless there is a terminal connected to the Cr50 console.

This patch adds a new log event for registering the AP RO verification
progress. The event payload is a single byte value, logging the
following events:

  0 - refresh key press is detected
  1 - power button has been released before AP RO check was triggered
  2 - trigger sequence timeout (refresh button not pressed in time)
  3 - AP RO check triggered
  4 - could not run the check, hash space not programmed
  5 - could not run the check, hash space corrupted
  6 - AP RO verification failed
  7 - AP RO verification succeeded

BUG=b:153764696
TEST=verified logging during various AP RO verification attempts:
    $ gsctool -a -L
    Log time zone is PST
    Dec 31 69 16:00:01 : 00
    May 06 20 21:20:49 : 09 01
    May 06 20 21:21:53 : 09 00
    May 06 20 21:21:54 : 09 00
    May 06 20 21:21:55 : 09 03
    May 06 20 21:21:56 : 09 07
    May 06 20 21:23:03 : 09 00
    May 06 20 21:23:04 : 09 00
    May 06 20 21:23:05 : 09 02
    May 07 20 11:21:52 : 09 00
    May 07 20 11:21:53 : 09 00
    May 07 20 11:21:54 : 09 01
    May 08 20 11:57:21 : 09 00
    May 08 20 11:57:22 : 09 00
    May 08 20 11:57:23 : 09 03
    May 08 20 11:57:24 : 09 04
    May 08 20 12:07:15 : 09 00
    May 08 20 12:07:16 : 09 00
    May 08 20 12:07:17 : 09 03
    May 08 20 12:07:19 : 09 07
    May 08 20 12:09:20 : 09 00
    May 08 20 12:09:21 : 09 00
    May 08 20 12:09:22 : 09 03
    May 08 20 12:09:23 : 09 06

Signed-off-by: Vadim Bendebury <vbendeb@chromium.org>
Change-Id: I739f9dbb2e7b8fc87601d61e1f87eb49d85bdf14
Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/platform/ec/+/2191283
Reviewed-by: Mary Ruthven <mruthven@chromium.org>
Reviewed-by: Namyoon Woo <namyoon@chromium.org>

4 files changed, 60 insertions, 4 deletions

diff --git a/board/cr50/power_button.c b/board/cr50/power_button.c
index bff6c4890c..6aca820caf 100644
--- a/board/cr50/power_button.c
+++ b/board/cr50/power_button.c
@@ -119,14 +119,29 @@ static int rctd_poll_handler(void)
 	} else {
 		/* Have this been running longer than the timeout? */
 		if ((get_time().le.lo - rctd_start_time) > RCTD_CUTOFF_TIME) {
-			CPRINTS("Timeout, no RO check triggered");
+			if (ref_press_count) {
+				/*
+				 * Report timeout only in case the process
+				 * started.
+				 */
+				ap_ro_add_flash_event(APROF_CHECK_TIMED_OUT);
+				CPRINTS("Timeout, no RO check triggered");
+			}
 			return 0;
 		}
 	}
 
 
 	if ((dior_state & GC_RBOX_CHECK_INPUT_PWRB_IN_MASK) != 0) {
-		CPRINTS("Power button released, RO Check Detection stopped");
+		if (ref_press_count) {
+			/*
+			 * Report interruption only in case the process
+			 * started.
+			 */
+			CPRINTS("Power button released, "
+				"RO Check Detection stopped");
+			ap_ro_add_flash_event(APROF_CHECK_STOPPED);
+		}
 		return 0;
 	}
 
@@ -147,11 +162,13 @@ static int rctd_poll_handler(void)
 		return 1;
 
 	if (++ref_press_count != PRESS_COUNT) {
+		ap_ro_add_flash_event(APROF_REFRESH_PRESSED);
 		CPRINTS("Refresh press registered");
 		return 1;
 	}
 
 	CPRINTS("RO Validation triggered");
+	ap_ro_add_flash_event(APROF_CHECK_TRIGGERED);
 	validate_ap_ro();
 	return 0;
 }
diff --git a/common/ap_ro_integrity_check.c b/common/ap_ro_integrity_check.c
index bb02f306db..fbf5bef488 100644
--- a/common/ap_ro_integrity_check.c
+++ b/common/ap_ro_integrity_check.c
@@ -5,6 +5,7 @@
  * Code supporting AP RO verification.
  */
 
+#include "ap_ro_integrity_check.h"
 #include "console.h"
 #include "crypto_api.h"
 #include "extension.h"
@@ -176,12 +177,15 @@ int validate_ap_ro(void)
 
 	if (p_chk->header.num_ranges == (uint16_t)~0) {
 		CPRINTS("%s: RO verification not programmed", __func__);
+		ap_ro_add_flash_event(APROF_SPACE_NOT_PROGRAMMED);
 		return EC_ERROR_INVAL;
 	}
 
 	/* Is the contents intact? */
-	if (verify_ap_ro_check_space() != EC_SUCCESS)
+	if (verify_ap_ro_check_space() != EC_SUCCESS) {
+		ap_ro_add_flash_event(APROF_SPACE_INVALID);
 		return EC_ERROR_INVAL; /* No verification possible. */
+	}
 
 	enable_ap_spi_hash_shortcut();
 	usb_spi_sha256_start(&ctx);
@@ -204,8 +208,10 @@ int validate_ap_ro(void)
 		CPRINTS("Stored digest %ph",
 			HEX_BUF(p_chk->payload.digest,
 				sizeof(p_chk->payload.digest)));
+		ap_ro_add_flash_event(APROF_CHECK_FAILED);
 		rv = EC_ERROR_CRC;
 	} else {
+		ap_ro_add_flash_event(APROF_CHECK_SUCCEEDED);
 		rv = EC_SUCCESS;
 		CPRINTS("AP RO verification SUCCEEDED!");
 	}
@@ -214,6 +220,14 @@ int validate_ap_ro(void)
 	return rv;
 }
 
+void ap_ro_add_flash_event(enum ap_ro_verification_ev event)
+{
+	struct ap_ro_entry_payload ev;
+
+	ev.event = event;
+	flash_log_add_event(FE_LOG_AP_RO_VERIFICATION, sizeof(ev), &ev);
+}
+
 static int ap_ro_info_cmd(int argc, char **argv)
 {
 	int rv;
diff --git a/include/ap_ro_integrity_check.h b/include/ap_ro_integrity_check.h
index 365bccbe8e..0edc477c88 100644
--- a/include/ap_ro_integrity_check.h
+++ b/include/ap_ro_integrity_check.h
@@ -6,6 +6,8 @@
 #ifndef __CR50_INCLUDE_AP_RO_INTEGRITY_CHECK_H
 #define __CR50_INCLUDE_AP_RO_INTEGRITY_CHECK_H
 
+#include "flash_log.h"
+
 /*
  * validate_ap_ro: based on information saved in an H1 RO flash page verify
  * contents of the AP flash.
@@ -19,4 +21,10 @@
  */
 int validate_ap_ro(void);
 
+/*
+ * ap_ro_add_flash_event: add a flash log event to keep track of AP RO
+ *       verification attempt progress.
+ */
+void ap_ro_add_flash_event(enum ap_ro_verification_ev event);
+
 #endif /* ! __CR50_INCLUDE_AP_RO_INTEGRITY_CHECK_H */
diff --git a/include/flash_log.h b/include/flash_log.h
index e504df6ee7..1c34d5e2b2 100644
--- a/include/flash_log.h
+++ b/include/flash_log.h
@@ -21,7 +21,7 @@ enum flash_event_type {
 	FE_LOG_TPM_WIPE_ERROR = 6,     /* Failed to wipe the TPM */
 	FE_LOG_TRNG_STALL = 7,     /* Stall while retrieving a random number. */
 	FE_LOG_DCRYPTO_FAILURE = 8, /* Dcrypto had to be reset. */
-
+	FE_LOG_AP_RO_VERIFICATION = 9, /* AP RO verification events. */
 	/*
 	 * Fixed padding value makes it easier to parse log space
 	 * snapshots.
@@ -85,6 +85,23 @@ struct nvmem_failure_payload {
 	} __packed;
 } __packed;
 
+
+/* AP RO verification events. */
+enum ap_ro_verification_ev {
+	APROF_REFRESH_PRESSED = 0,
+	APROF_CHECK_STOPPED = 1,
+	APROF_CHECK_TIMED_OUT = 2,
+	APROF_CHECK_TRIGGERED = 3,
+	APROF_SPACE_NOT_PROGRAMMED = 4,
+	APROF_SPACE_INVALID = 5,
+	APROF_CHECK_FAILED = 6,
+	APROF_CHECK_SUCCEEDED = 7,
+};
+
+struct ap_ro_entry_payload {
+	enum ap_ro_verification_ev event : 8;
+} __packed;
+
 /* Returned in the "type" field, when there is no entry available */
 #define FLASH_LOG_NO_ENTRY 0xff
 #define MAX_FLASH_LOG_PAYLOAD_SIZE ((1 << 6) - 1)