Better logging on failure
Log Anyhow errors with Debug not Display; that way we see the full
context rather than just the most recent failure.
Add context to calls to IPackageManagerNative. That's slightly ad hoc,
but useful, and calls to AIDL interfaces don't otherwise include much
detail.
Bug: 238312664
Test: Induce failure, see better logs
Change-Id: I3f119f937f2d07296d92d882c9fbabfbf17b0186
diff --git a/virtualizationservice/src/aidl.rs b/virtualizationservice/src/aidl.rs
index d8f0b2e..745110b 100644
--- a/virtualizationservice/src/aidl.rs
+++ b/virtualizationservice/src/aidl.rs
@@ -391,7 +391,7 @@
// At this point, we do not know the protected status of Vm
// setting it to false, though this may not be correct.
error!(
- "Failed to create temporary directory {:?} for VM files: {}",
+ "Failed to create temporary directory {:?} for VM files: {:?}",
temporary_directory, e
);
new_binder_exception(
@@ -408,7 +408,7 @@
let config = match config {
VirtualMachineConfig::AppConfig(config) => BorrowedOrOwned::Owned(
load_app_config(config, &temporary_directory).map_err(|e| {
- error!("Failed to load app config from {}: {}", &config.configPath, e);
+ error!("Failed to load app config from {}: {:?}", &config.configPath, e);
*is_protected = config.protectedVm;
new_binder_exception(
ExceptionCode::SERVICE_SPECIFIC,
@@ -442,7 +442,7 @@
let zero_filler_path = temporary_directory.join("zero.img");
write_zero_filler(&zero_filler_path).map_err(|e| {
- error!("Failed to make composite image: {}", e);
+ error!("Failed to make composite image: {:?}", e);
new_binder_exception(
ExceptionCode::SERVICE_SPECIFIC,
format!("Failed to make composite image: {}", e),
@@ -492,7 +492,7 @@
requester_debug_pid,
)
.map_err(|e| {
- error!("Failed to create VM with config {:?}: {}", config, e);
+ error!("Failed to create VM with config {:?}: {:?}", config, e);
new_binder_exception(
ExceptionCode::SERVICE_SPECIFIC,
format!("Failed to create VM: {}", e),
@@ -587,7 +587,7 @@
&composite_image_filenames.footer,
)
.map_err(|e| {
- error!("Failed to make composite image with config {:?}: {}", disk, e);
+ error!("Failed to make composite image with config {:?}: {:?}", disk, e);
new_binder_exception(
ExceptionCode::SERVICE_SPECIFIC,
format!("Failed to make composite image: {}", e),
@@ -838,7 +838,7 @@
let pfd = stream.map(vsock_stream_to_pfd);
for callback in callbacks {
if let Err(e) = callback.onPayloadStarted(cid as i32, pfd.as_ref()) {
- error!("Error notifying payload start event from VM CID {}: {}", cid, e);
+ error!("Error notifying payload start event from VM CID {}: {:?}", cid, e);
}
}
}
@@ -848,7 +848,7 @@
let callbacks = &*self.0.lock().unwrap();
for callback in callbacks {
if let Err(e) = callback.onPayloadReady(cid as i32) {
- error!("Error notifying payload ready event from VM CID {}: {}", cid, e);
+ error!("Error notifying payload ready event from VM CID {}: {:?}", cid, e);
}
}
}
@@ -858,7 +858,7 @@
let callbacks = &*self.0.lock().unwrap();
for callback in callbacks {
if let Err(e) = callback.onPayloadFinished(cid as i32, exit_code) {
- error!("Error notifying payload finish event from VM CID {}: {}", cid, e);
+ error!("Error notifying payload finish event from VM CID {}: {:?}", cid, e);
}
}
}
@@ -868,7 +868,7 @@
let callbacks = &*self.0.lock().unwrap();
for callback in callbacks {
if let Err(e) = callback.onError(cid as i32, error_code, message) {
- error!("Error notifying error event from VM CID {}: {}", cid, e);
+ error!("Error notifying error event from VM CID {}: {:?}", cid, e);
}
}
}
@@ -878,7 +878,7 @@
let callbacks = &*self.0.lock().unwrap();
for callback in callbacks {
if let Err(e) = callback.onDied(cid as i32, reason) {
- error!("Error notifying exit of VM CID {}: {}", cid, e);
+ error!("Error notifying exit of VM CID {}: {:?}", cid, e);
}
}
}
diff --git a/virtualizationservice/src/payload.rs b/virtualizationservice/src/payload.rs
index 8378df3..c0153b9 100644
--- a/virtualizationservice/src/payload.rs
+++ b/virtualizationservice/src/payload.rs
@@ -134,10 +134,13 @@
let pm =
wait_for_interface::<dyn IPackageManagerNative>(PACKAGE_MANAGER_NATIVE_SERVICE)
.context("Failed to get service when prefer_staged is set.")?;
- let staged = pm.getStagedApexModuleNames()?;
+ let staged =
+ pm.getStagedApexModuleNames().context("getStagedApexModuleNames failed")?;
for apex_info in list.list.iter_mut() {
if staged.contains(&apex_info.name) {
- if let Some(staged_apex_info) = pm.getStagedApexInfo(&apex_info.name)? {
+ if let Some(staged_apex_info) =
+ pm.getStagedApexInfo(&apex_info.name).context("getStagedApexInfo failed")?
+ {
apex_info.path = PathBuf::from(staged_apex_info.diskImagePath);
apex_info.has_classpath_jar = staged_apex_info.hasClassPathJars;
let metadata = metadata(&apex_info.path)?;