Changing code to have better error logging
This changes the error logs to show the file and line number instead of
naming a specific a function where the error originated. In some cases
the function name is kept where it made sense for readibility of the
logs.
Test: Run and tested using `atest keystore2_test` for Rust test and CTS test with `atest CtsKeystoreTestCases`
Bug: 241924261
Change-Id: I2ea970dd83e18033506555f2726c716626697cdf
diff --git a/keystore2/src/globals.rs b/keystore2/src/globals.rs
index edbe6ce..c617240 100644
--- a/keystore2/src/globals.rs
+++ b/keystore2/src/globals.rs
@@ -16,6 +16,7 @@
//! database connections and connections to services that Keystore needs
//! to talk to.
+use crate::ks_err;
use crate::gc::Gc;
use crate::legacy_blob::LegacyBlobLoader;
use crate::legacy_importer::LegacyImporter;
@@ -187,7 +188,7 @@
let km_dev = get_keymint_dev_by_uuid(uuid).map(|(dev, _)| dev)?;
let _wp = wd::watch_millis("In invalidate key closure: calling deleteKey", 500);
map_km_error(km_dev.deleteKey(blob))
- .context("In invalidate key closure: Trying to invalidate key blob.")
+ .context(ks_err!("Trying to invalidate key blob."))
}),
KeystoreDB::new(&DB_PATH.read().expect("Could not get the database directory."), None)
.expect("Failed to open database."),
@@ -224,9 +225,10 @@
}
}
_ => {
- return Err(Error::Km(ErrorCode::HARDWARE_TYPE_UNAVAILABLE)).context(format!(
- "In keymint_service_name_by_version: Trying to find keymint V{} for security level: {:?}",
- version, security_level
+ return Err(Error::Km(ErrorCode::HARDWARE_TYPE_UNAVAILABLE)).context(ks_err!(
+ "Trying to find keymint V{} for security level: {:?}",
+ version,
+ security_level
));
}
};
@@ -251,12 +253,12 @@
Ok(sl)
}
})
- .context("In connect_keymint.")?;
+ .context(ks_err!())?;
let (keymint, hal_version) = if let Some((version, service_name)) = service_name {
let km: Strong<dyn IKeyMintDevice> =
map_binder_status_code(binder::get_interface(&service_name))
- .context("In connect_keymint: Trying to connect to genuine KeyMint service.")?;
+ .context(ks_err!("Trying to connect to genuine KeyMint service."))?;
// Map the HAL version code for KeyMint to be <AIDL version> * 100, so
// - V1 is 100
// - V2 is 200
@@ -268,7 +270,7 @@
let keystore_compat_service: Strong<dyn IKeystoreCompatService> =
map_binder_status_code(binder::get_interface("android.security.compat"))
- .context("In connect_keymint: Trying to connect to compat service.")?;
+ .context(ks_err!("Trying to connect to compat service."))?;
(
map_binder_status(keystore_compat_service.getKeyMintDevice(*security_level))
.map_err(|e| match e {
@@ -277,7 +279,7 @@
}
e => e,
})
- .context("In connect_keymint: Trying to get Legacy wrapper.")?,
+ .context(ks_err!("Trying to get Legacy wrapper."))?,
None,
)
};
@@ -302,7 +304,7 @@
security_level
);
BacklevelKeyMintWrapper::wrap(KeyMintV1::new(*security_level), keymint)
- .context("In connect_keymint: Trying to create V1 compatibility wrapper.")?
+ .context(ks_err!("Trying to create V1 compatibility wrapper."))?
}
None => {
// Compatibility wrapper around a KeyMaster device: this roughly
@@ -312,21 +314,21 @@
"Add emulation wrapper around Keymaster device for security level: {:?}",
security_level
);
- BacklevelKeyMintWrapper::wrap(KeyMintV1::new(*security_level), keymint).context(
- "In connect_keymint: Trying to create km_compat V1 compatibility wrapper .",
- )?
+ BacklevelKeyMintWrapper::wrap(KeyMintV1::new(*security_level), keymint)
+ .context(ks_err!("Trying to create km_compat V1 compatibility wrapper ."))?
}
_ => {
- return Err(Error::Km(ErrorCode::HARDWARE_TYPE_UNAVAILABLE)).context(format!(
- "In connect_keymint: unexpected hal_version {:?} for security level: {:?}",
- hal_version, security_level
- ))
+ return Err(Error::Km(ErrorCode::HARDWARE_TYPE_UNAVAILABLE)).context(ks_err!(
+ "unexpected hal_version {:?} for security level: {:?}",
+ hal_version,
+ security_level
+ ));
}
};
let wp = wd::watch_millis("In connect_keymint: calling getHardwareInfo()", 500);
- let mut hw_info = map_km_error(keymint.getHardwareInfo())
- .context("In connect_keymint: Failed to get hardware info.")?;
+ let mut hw_info =
+ map_km_error(keymint.getHardwareInfo()).context(ks_err!("Failed to get hardware info."))?;
drop(wp);
// The legacy wrapper sets hw_info.versionNumber to the underlying HAL version like so:
@@ -356,7 +358,7 @@
if let Some((dev, hw_info, uuid)) = devices_map.dev_by_sec_level(security_level) {
Ok((dev, hw_info, uuid))
} else {
- let (dev, hw_info) = connect_keymint(security_level).context("In get_keymint_device.")?;
+ let (dev, hw_info) = connect_keymint(security_level).context(ks_err!())?;
devices_map.insert(*security_level, dev, hw_info);
// Unwrap must succeed because we just inserted it.
Ok(devices_map.dev_by_sec_level(security_level).unwrap())
@@ -374,7 +376,7 @@
if let Some((dev, hw_info, _)) = devices_map.dev_by_uuid(uuid) {
Ok((dev, hw_info))
} else {
- Err(Error::sys()).context("In get_keymint_dev_by_uuid: No KeyMint instance found.")
+ Err(Error::sys()).context(ks_err!("No KeyMint instance found."))
}
}
@@ -399,14 +401,14 @@
let secureclock = if secure_clock_available {
map_binder_status_code(binder::get_interface(&default_time_stamp_service_name))
- .context("In connect_secureclock: Trying to connect to genuine secure clock service.")
+ .context(ks_err!("Trying to connect to genuine secure clock service."))
} else {
// This is a no-op if it was called before.
keystore2_km_compat::add_keymint_device_service();
let keystore_compat_service: Strong<dyn IKeystoreCompatService> =
map_binder_status_code(binder::get_interface("android.security.compat"))
- .context("In connect_secureclock: Trying to connect to compat service.")?;
+ .context(ks_err!("Trying to connect to compat service."))?;
// Legacy secure clock services were only implemented by TEE.
map_binder_status(keystore_compat_service.getSecureClock())
@@ -416,7 +418,7 @@
}
e => e,
})
- .context("In connect_secureclock: Trying to get Legacy wrapper.")
+ .context(ks_err!("Trying to get Legacy wrapper."))
}?;
Ok(secureclock)
@@ -429,7 +431,7 @@
if let Some(dev) = &*ts_device {
Ok(dev.clone())
} else {
- let dev = connect_secureclock().context("In get_timestamp_service.")?;
+ let dev = connect_secureclock().context(ks_err!())?;
*ts_device = Some(dev.clone());
Ok(dev)
}
@@ -462,13 +464,11 @@
_ => None,
}
.ok_or(Error::Km(ErrorCode::HARDWARE_TYPE_UNAVAILABLE))
- .context("In connect_remotely_provisioned_component.")?;
+ .context(ks_err!())?;
let rem_prov_hal: Strong<dyn IRemotelyProvisionedComponent> =
- map_binder_status_code(binder::get_interface(&service_name)).context(concat!(
- "In connect_remotely_provisioned_component: Trying to connect to",
- " RemotelyProvisionedComponent service."
- ))?;
+ map_binder_status_code(binder::get_interface(&service_name))
+ .context(ks_err!("Trying to connect to RemotelyProvisionedComponent service."))?;
Ok(rem_prov_hal)
}
@@ -481,8 +481,7 @@
if let Some(dev) = devices_map.dev_by_sec_level(security_level) {
Ok(dev)
} else {
- let dev = connect_remotely_provisioned_component(security_level)
- .context("In get_remotely_provisioned_component.")?;
+ let dev = connect_remotely_provisioned_component(security_level).context(ks_err!())?;
devices_map.insert(*security_level, dev);
// Unwrap must succeed because we just inserted it.
Ok(devices_map.dev_by_sec_level(security_level).unwrap())