commit 9a587a2b5dd42f3a63889ef6b239abbe1f2b9fb2
author Shaquille Johnson <ssjohnson@google.com> Wed Feb 28 19:54:24 2024 +0000
committer Shaquille Johnson <ssjohnson@google.com> Mon Jun 17 15:28:37 2024 +0000
tree cb6a680709351e22bb20926976ca3ff764cafa88
parent e975a41eed2c126693782857adc58525fe230129

Update the security logs for better understanding

We have had a good deal of reports about the logs
that come out of the security_level file and these update
the logs where there have been bugs made for these in
the past.

Test: atest keystore2_test
Test: atest CtsKeystoreTestCases
Change-Id: I89ec4f7fde67e4db16c1102f815abda9ea796163

keystore2/src/legacy_importer.rs

diff --git a/keystore2/src/legacy_importer.rs b/keystore2/src/legacy_importer.rs
index f64af0b..f9d5d1b 100644
--- a/keystore2/src/legacy_importer.rs
+++ b/keystore2/src/legacy_importer.rs
@@ -928,6 +928,6 @@
         },
         |_| Ok(()),
     )
-    .context(ks_err!())?;
+    .context(ks_err!("Key blob upgrade failed, possibly invalid keyblob for uuid {uuid:?}"))?;
     Ok((key_characteristics_to_internal(characteristics), upgraded_blob))
 }

keystore2/src/security_level.rs

diff --git a/keystore2/src/security_level.rs b/keystore2/src/security_level.rs
index 00e0480..5995a9c 100644
--- a/keystore2/src/security_level.rs
+++ b/keystore2/src/security_level.rs
@@ -34,7 +34,8 @@
 use crate::utils::{
     check_device_attestation_permissions, check_key_permission,
     check_unique_id_attestation_permissions, is_device_id_attestation_tag,
-    key_characteristics_to_internal, uid_to_android_user, watchdog as wd, UNDEFINED_NOT_AFTER,
+    key_characteristics_to_internal, log_security_safe_params, uid_to_android_user, watchdog as wd,
+    UNDEFINED_NOT_AFTER,
 };
 use crate::{
     database::{
@@ -516,6 +517,7 @@
         flags: i32,
         _entropy: &[u8],
     ) -> Result<KeyMetadata> {
+        log::info!("security_level: generate_key(key={:?})", key);
         if key.domain != Domain::BLOB && key.alias.is_none() {
             return Err(error::Error::Km(ErrorCode::INVALID_ARGUMENT))
                 .context(ks_err!("Alias must be specified"));
@@ -585,7 +587,12 @@
                         })
                     },
                 )
-                .context(ks_err!("Using user generated attestation key."))
+                .context(ks_err!(
+                    "While generating Key {:?} with remote \
+                    provisioned attestation key and params: {:?}.",
+                    key.alias,
+                    log_security_safe_params(&params)
+                ))
                 .map(|(result, _)| result),
             Some(AttestationKeyInfo::RkpdProvisioned { attestation_key, attestation_certs }) => {
                 self.upgrade_rkpd_keyblob_if_required_with(&attestation_key.keyBlob, &[], |blob| {
@@ -605,7 +612,12 @@
                         self.keymint.generateKey(&params, dynamic_attest_key.as_ref())
                     })
                 })
-                .context(ks_err!("While generating Key with remote provisioned attestation key."))
+                .context(ks_err!(
+                    "While generating Key {:?} with remote \
+                    provisioned attestation key and params: {:?}.",
+                    key.alias,
+                    log_security_safe_params(&params)
+                ))
                 .map(|(mut result, _)| {
                     result.certificateChain.push(attestation_certs);
                     result
@@ -621,7 +633,12 @@
                 );
                 self.keymint.generateKey(&params, None)
             })
-            .context(ks_err!("While generating Key without explicit attestation key.")),
+            .context(ks_err!(
+                "While generating Key {:?} with remote \
+                provisioned attestation key and params: {:?}.",
+                key.alias,
+                log_security_safe_params(&params)
+            )),
         }
         .context(ks_err!())?;
 
@@ -849,6 +866,7 @@
     where
         F: Fn(&[u8]) -> Result<T, Error>,
     {
+        log::info!("upgrade_keyblob_if_required_with(key_id={:?})", key_id_guard);
         let (v, upgraded_blob) = crate::utils::upgrade_keyblob_if_required_with(
             &*self.keymint,
             self.hw_info.versionNumber,
@@ -889,6 +907,10 @@
     where
         F: Fn(&[u8]) -> Result<T, Error>,
     {
+        log::info!(
+            "upgrade_rkpd_keyblob_if_required_with(params={:?})",
+            log_security_safe_params(params)
+        );
         let rpc_name = get_remotely_provisioned_component_name(&self.security_level)
             .context(ks_err!("Trying to get IRPC name."))?;
         crate::utils::upgrade_keyblob_if_required_with(

keystore2/src/utils.rs

diff --git a/keystore2/src/utils.rs b/keystore2/src/utils.rs
index 196cac5..c80bfa5 100644
--- a/keystore2/src/utils.rs
+++ b/keystore2/src/utils.rs
@@ -551,8 +551,8 @@
     items_to_return
 }
 
-/// List all key aliases for a given domain + namespace. whose alias is greater
-/// than start_past_alias (if provided).
+/// Log the key parameters, excluding sensitive ones such as
+/// APPLICATION_DATA and APPLICATION_ID
 pub fn list_key_entries(
     db: &mut KeystoreDB,
     domain: Domain,
@@ -591,6 +591,16 @@
     Ok((legacy_keys.len() + num_keys_in_db) as i32)
 }
 
+/// For params remove sensitive data before returning a string for logging
+pub fn log_security_safe_params(params: &[KmKeyParameter]) -> String {
+    format!(
+        "{:?}",
+        params
+            .iter()
+            .filter(|kp| (kp.tag != Tag::APPLICATION_ID && kp.tag != Tag::APPLICATION_DATA))
+    )
+}
+
 /// Trait implemented by objects that can be used to decrypt cipher text using AES-GCM.
 pub trait AesGcm {
     /// Deciphers `data` using the initialization vector `iv` and AEAD tag `tag`