[provisioning] Log data from provisionging as json

1. Collect personalization data and timing statistics during
   personalization and log it as json when provisioning is
   done.

Signed-off-by: Chris Frantz <[email protected]>

sw/host/opentitanlib/src/dif/lc_ctrl.rs

@@ -10,7 +10,7 @@ use serde::{Deserialize, Serialize};
 use crate::with_unknown;
 
 with_unknown! {
-    pub enum DifLcCtrlState: u32 {
+    pub enum DifLcCtrlState: u32 [default = Self::StateInvalid] {
         Raw = bindgen::dif::dif_lc_ctrl_state_kDifLcCtrlStateRaw ,
         TestUnlocked0 = bindgen::dif::dif_lc_ctrl_state_kDifLcCtrlStateTestUnlocked0 ,
         TestLocked0 = bindgen::dif::dif_lc_ctrl_state_kDifLcCtrlStateTestLocked0 ,

sw/host/ot_certs/src/lib.rs

@@ -23,9 +23,10 @@ pub mod template;
 pub mod x509;
 
 use clap::ValueEnum;
+use serde::{Deserialize, Serialize};
 
 /// Supported OpenTitan certificate formats.
-#[derive(Clone, Debug, ValueEnum)]
+#[derive(Clone, Debug, ValueEnum, Serialize, Deserialize)]
 pub enum CertFormat {
     X509,
     Cwt,

sw/host/provisioning/cert_lib/BUILD

@@ -15,6 +15,7 @@ rust_library(
         "//sw/host/ot_certs",
         "@crate_index//:anyhow",
         "@crate_index//:arrayvec",
+        "@crate_index//:base64ct",
         "@crate_index//:elliptic-curve",
         "@crate_index//:hex",
         "@crate_index//:log",

sw/host/provisioning/cert_lib/src/lib.rs

@@ -8,12 +8,13 @@ use std::path::PathBuf;
 use std::process::Command;
 
 use anyhow::{bail, Context, Result};
+use base64ct::{Base64, Encoding};
 use elliptic_curve::SecretKey;
 use num_bigint_dig::BigUint;
 use openssl::ecdsa::EcdsaSig;
 use p256::ecdsa::SigningKey;
 use p256::NistP256;
-use serde::Deserialize;
+use serde::{Deserialize, Serialize, Serializer};
 
 use opentitanlib::crypto::sha256::sha256;
 use opentitanlib::util::tmpfilename;
@@ -219,15 +220,21 @@ fn write_cert_to_temp_pem_file(der_cert_bytes: &[u8], base_filename: &str) -> Re
     Ok(binding_pem)
 }
 
+fn serialize_certificate<S: Serializer>(cert: &Vec<u8>, serializer: S) -> Result<S::Ok, S::Error> {
+    let s = Base64::encode_string(cert.as_slice());
+    serializer.serialize_str(&s)
+}
+
 /// Container for an endorsed certificate.
 ///
 /// This is used to pass a collection of endorsed certificates, along with metadata,
 /// to various functions that check the certificates validate properly with third-party
 /// tools.
-#[derive(Clone, Debug)]
+#[derive(Clone, Debug, Serialize)]
 pub struct EndorsedCert {
     pub format: CertFormat,
     pub name: String,
+    #[serde(serialize_with = "serialize_certificate")]
     pub bytes: Vec<u8>,
     pub ignore_critical: bool,
 }

sw/host/provisioning/ft/BUILD

@@ -21,12 +21,14 @@ package(default_visibility = ["//visibility:public"])
             "//sw/host/provisioning/ujson_lib",
             "//sw/host/provisioning/util_lib",
             "@crate_index//:anyhow",
+            "@crate_index//:base64ct",
             "@crate_index//:clap",
             "@crate_index//:elliptic-curve",
             "@crate_index//:hex",
             "@crate_index//:humantime",
             "@crate_index//:log",
             "@crate_index//:p256",
+            "@crate_index//:serde_json",
             "@lowrisc_serde_annotate//serde_annotate",
         ],
     )

sw/host/provisioning/ft/src/main.rs

@@ -4,15 +4,17 @@
 
 use std::collections::HashMap;
 use std::path::PathBuf;
-use std::time::Duration;
+use std::time::{Duration, Instant};
 
 use anyhow::{bail, Context, Result};
+use base64ct::{Base64, Encoding};
 use clap::{Args, Parser};
 use elliptic_curve::pkcs8::DecodePrivateKey;
 use elliptic_curve::SecretKey;
 use p256::NistP256;
 
 use cert_lib::{CaConfig, CaKey, CaKeyType};
+use ft_lib::response::PersonalizeResponse;
 use ft_lib::{
     check_rom_ext_boot_up, run_ft_personalize, run_sram_ft_individualize, test_exit, test_unlock,
 };
@@ -76,6 +78,10 @@ pub struct ManufFtProvisioningDataInput {
     /// Token Encryption public key (RSA) DER file path.
     #[arg(long)]
     token_encrypt_key_der_file: PathBuf,
+
+    /// Pretty-print the provisioning data output.
+    #[arg(long, default_value = "false")]
+    pretty: bool,
 }
 
 #[derive(Debug, Parser)]
@@ -110,6 +116,8 @@ fn main() -> Result<()> {
     let opts = Opts::parse();
     opts.init.init_logging();
 
+    let mut response = PersonalizeResponse::default();
+
     // We call the below functions, instead of calling `opts.init.init_target()` since we do not
     // want to perform bootstrap yet.
     let transport = backend::create(&opts.init.backend_opts)?;
@@ -131,15 +139,19 @@ fn main() -> Result<()> {
     let token_encrypt_key =
         load_rsa_public_key(&opts.provisioning_data.token_encrypt_key_der_file)?;
     let encrypted_rma_unlock_token = encrypt_token(&token_encrypt_key, &rma_unlock_token)?;
-    log::info!(
-        "Encrypted rma_unlock_token = {}",
-        hex::encode(&encrypted_rma_unlock_token)
-    );
+    response.rma_unlock_token = Base64::encode_string(&encrypted_rma_unlock_token);
+    log::info!("Encrypted rma_unlock_token = {}", response.rma_unlock_token);
 
     // Parse and prepare individualization ujson data payload.
-    let _ft_individualize_data_in = ManufFtIndividualizeData {
+    let ft_individualize_data_in = ManufFtIndividualizeData {
         device_id: hex_string_to_u32_arrayvec::<8>(opts.provisioning_data.device_id.as_str())?,
     };
+    response.device_id = ft_individualize_data_in
+        .device_id
+        .iter()
+        .map(|v| format!("{v:08X}"))
+        .collect::<Vec<String>>()
+        .join("");
 
     // Parse and prepare CA key.
     let mut ca_cfgs: HashMap<String, CaConfig> = serde_annotate::from_str(
@@ -188,24 +200,27 @@ fn main() -> Result<()> {
     };
 
     // Only run test unlock operation if we are in a locked LC state.
-    match read_lc_state(
+    response.lc_state.initial = read_lc_state(
         &transport,
         &opts.init.jtag_params,
         opts.init.bootstrap.options.reset_delay,
-    )? {
+    )?;
+    match response.lc_state.initial {
         DifLcCtrlState::TestLocked0
         | DifLcCtrlState::TestLocked1
         | DifLcCtrlState::TestLocked2
         | DifLcCtrlState::TestLocked3
         | DifLcCtrlState::TestLocked4
         | DifLcCtrlState::TestLocked5
         | DifLcCtrlState::TestLocked6 => {
+            let t0 = Instant::now();
             test_unlock(
                 &transport,
                 &opts.init.jtag_params,
                 opts.init.bootstrap.options.reset_delay,
                 &_test_unlock_token,
             )?;
+            response.stats.log_elapsed_time("test-unlock", t0);
         }
         _ => {
             log::info!("Skipping test unlock operation. Device is already unlocked.");
@@ -214,11 +229,12 @@ fn main() -> Result<()> {
 
     // Only run the SRAM individualize program in a test unlocked state. If we have transitioned to
     // a mission state already, then we can skip this step.
-    match read_lc_state(
+    response.lc_state.unlocked = read_lc_state(
         &transport,
         &opts.init.jtag_params,
         opts.init.bootstrap.options.reset_delay,
-    )? {
+    )?;
+    match response.lc_state.unlocked {
         DifLcCtrlState::TestUnlocked0 => {
             bail!("FT stage cannot be run from test unlocked 0. Run CP stage first.");
         }
@@ -229,22 +245,29 @@ fn main() -> Result<()> {
         | DifLcCtrlState::TestUnlocked5
         | DifLcCtrlState::TestUnlocked6
         | DifLcCtrlState::TestUnlocked7 => {
+            response.lc_state.individualize = Some(response.lc_state.unlocked);
+            let t0 = Instant::now();
             run_sram_ft_individualize(
                 &transport,
                 &opts.init.jtag_params,
                 opts.init.bootstrap.options.reset_delay,
                 &opts.sram_program,
-                &_ft_individualize_data_in,
+                &ft_individualize_data_in,
                 opts.timeout,
                 &spi_console_device,
             )?;
+            response.stats.log_elapsed_time("ft-individualize", t0);
+            let t0 = Instant::now();
             test_exit(
                 &transport,
                 &opts.init.jtag_params,
                 opts.init.bootstrap.options.reset_delay,
                 &_test_exit_token,
                 opts.provisioning_data.target_mission_mode_lc_state,
             )?;
+            response.lc_state.mission_mode =
+                Some(opts.provisioning_data.target_mission_mode_lc_state);
+            response.stats.log_elapsed_time("test-exit", t0);
         }
         _ => {
             log::info!("Skipping individualize operation. Device is already in a mission mode.");
@@ -265,10 +288,17 @@ fn main() -> Result<()> {
         opts.second_bootstrap,
         &spi_console_device,
         opts.timeout,
+        &mut response,
     )?;
 
-    check_rom_ext_boot_up(&transport, &opts.init, opts.timeout)?;
+    check_rom_ext_boot_up(&transport, &opts.init, opts.timeout, &mut response)?;
     log::info!("Provisioning Done");
+    let doc = if opts.provisioning_data.pretty {
+        serde_json::to_string_pretty(&response)?
+    } else {
+        serde_json::to_string(&response)?
+    };
+    println!("PROVISIONING_DATA: {doc}");
 
     Ok(())
 }

sw/host/provisioning/ft_lib/BUILD

@@ -10,7 +10,10 @@ package(default_visibility = ["//visibility:public"])
 [
     rust_library(
         name = "ft_lib_{}".format(sku),
-        srcs = ["src/lib.rs"],
+        srcs = [
+            "src/lib.rs",
+            "src/response.rs",
+        ],
         crate_name = "ft_lib",
         deps = [
             "//sw/host/opentitanlib",
@@ -24,6 +27,7 @@ package(default_visibility = ["//visibility:public"])
             "@crate_index//:arrayvec",
             "@crate_index//:clap",
             "@crate_index//:hex",
+            "@crate_index//:indexmap",
             "@crate_index//:log",
             "@crate_index//:serde",
             "@crate_index//:serde_json",