Implement elapsed_time for VmBooted and VmExited
Bug: 243613715
Test: atest MicrodroidTestCase#testTelemetryPushedAtoms
Change-Id: I837c3c1606aa128663b703898c62ffb777938d44
diff --git a/tests/hostside/java/com/android/microdroid/test/MicrodroidTestCase.java b/tests/hostside/java/com/android/microdroid/test/MicrodroidTestCase.java
index 5ac36a0..9336e77 100644
--- a/tests/hostside/java/com/android/microdroid/test/MicrodroidTestCase.java
+++ b/tests/hostside/java/com/android/microdroid/test/MicrodroidTestCase.java
@@ -558,6 +558,11 @@
AtomsProto.VmExited atomVmExited = data.get(0).getAtom().getVmExited();
assertEquals("VmRunApp", atomVmExited.getVmIdentifier());
assertEquals(AtomsProto.VmExited.DeathReason.KILLED, atomVmExited.getDeathReason());
+
+ // Check UID and elapsed_time by comparing each other.
+ assertEquals(atomVmCreationRequested.getUid(), atomVmBooted.getUid());
+ assertEquals(atomVmCreationRequested.getUid(), atomVmExited.getUid());
+ assertTrue(atomVmBooted.getElapsedTimeMillis() < atomVmExited.getElapsedTimeMillis());
}
@Test
diff --git a/virtualizationservice/src/aidl.rs b/virtualizationservice/src/aidl.rs
index 5f4b7a7..553ddb2 100644
--- a/virtualizationservice/src/aidl.rs
+++ b/virtualizationservice/src/aidl.rs
@@ -1046,7 +1046,8 @@
let stream = vm.stream.lock().unwrap().take();
vm.callbacks.notify_payload_started(cid, stream);
- write_vm_booted_stats(vm.requester_uid as i32, &vm.name);
+ let vm_start_timestamp = vm.vm_start_timestamp.lock().unwrap();
+ write_vm_booted_stats(vm.requester_uid as i32, &vm.name, *vm_start_timestamp);
Ok(())
} else {
error!("notifyPayloadStarted is called from an unknown CID {}", cid);
diff --git a/virtualizationservice/src/atom.rs b/virtualizationservice/src/atom.rs
index feaa72a..01f3e27 100644
--- a/virtualizationservice/src/atom.rs
+++ b/virtualizationservice/src/atom.rs
@@ -25,6 +25,7 @@
use log::{trace, warn};
use microdroid_payload_config::VmPayloadConfig;
use statslog_virtualization_rust::{vm_booted, vm_creation_requested, vm_exited};
+use std::time::{Duration, SystemTime};
use zip::ZipArchive;
fn get_vm_payload_config(config: &VirtualMachineAppConfig) -> Result<VmPayloadConfig> {
@@ -36,6 +37,13 @@
Ok(vm_payload_config)
}
+fn get_duration(vm_start_timestamp: Option<SystemTime>) -> Duration {
+ match vm_start_timestamp {
+ Some(vm_start_timestamp) => vm_start_timestamp.elapsed().unwrap_or_default(),
+ None => Duration::default(),
+ }
+}
+
/// Write the stats of VMCreation to statsd
pub fn write_vm_creation_stats(
config: &VirtualMachineConfig,
@@ -116,8 +124,17 @@
}
/// Write the stats of VM boot to statsd
-pub fn write_vm_booted_stats(uid: i32, vm_identifier: &String) {
- let vm_booted = vm_booted::VmBooted { uid, vm_identifier };
+pub fn write_vm_booted_stats(
+ uid: i32,
+ vm_identifier: &String,
+ vm_start_timestamp: Option<SystemTime>,
+) {
+ let duration = get_duration(vm_start_timestamp);
+ let vm_booted = vm_booted::VmBooted {
+ uid,
+ vm_identifier,
+ elapsed_time_millis: duration.as_millis() as i64,
+ };
match vm_booted.stats_write() {
Err(e) => {
warn!("statslog_rust failed with error: {}", e);
@@ -127,10 +144,17 @@
}
/// Write the stats of VM exit to statsd
-pub fn write_vm_exited_stats(uid: i32, vm_identifier: &String, reason: DeathReason) {
+pub fn write_vm_exited_stats(
+ uid: i32,
+ vm_identifier: &String,
+ reason: DeathReason,
+ vm_start_timestamp: Option<SystemTime>,
+) {
+ let duration = get_duration(vm_start_timestamp);
let vm_exited = vm_exited::VmExited {
uid,
vm_identifier,
+ elapsed_time_millis: duration.as_millis() as i64,
death_reason: match reason {
DeathReason::INFRASTRUCTURE_ERROR => vm_exited::DeathReason::InfrastructureError,
DeathReason::KILLED => vm_exited::DeathReason::Killed,
diff --git a/virtualizationservice/src/crosvm.rs b/virtualizationservice/src/crosvm.rs
index 29d2fe7..c579be2 100644
--- a/virtualizationservice/src/crosvm.rs
+++ b/virtualizationservice/src/crosvm.rs
@@ -33,7 +33,7 @@
use std::path::{Path, PathBuf};
use std::process::{Command, ExitStatus};
use std::sync::{Arc, Condvar, Mutex};
-use std::time::Duration;
+use std::time::{Duration, SystemTime};
use std::thread;
use vsock::VsockStream;
use android_system_virtualizationservice::aidl::android::system::virtualizationservice::DeathReason::DeathReason;
@@ -191,6 +191,8 @@
pub stream: Mutex<Option<VsockStream>>,
/// VirtualMachineService binder object for the VM.
pub vm_service: Mutex<Option<Strong<dyn IVirtualMachineService>>>,
+ /// Recorded timestamp when the VM is started.
+ pub vm_start_timestamp: Mutex<Option<SystemTime>>,
/// The latest lifecycle state which the payload reported itself to be in.
payload_state: Mutex<PayloadState>,
/// Represents the condition that payload_state was updated
@@ -222,6 +224,7 @@
callbacks: Default::default(),
stream: Mutex::new(None),
vm_service: Mutex::new(None),
+ vm_start_timestamp: Mutex::new(None),
payload_state: Mutex::new(PayloadState::Starting),
payload_state_updated: Condvar::new(),
})
@@ -230,6 +233,7 @@
/// Starts an instance of `crosvm` to manage the VM. The `crosvm` instance will be killed when
/// the `VmInstance` is dropped.
pub fn start(self: &Arc<Self>) -> Result<(), Error> {
+ *self.vm_start_timestamp.lock().unwrap() = Some(SystemTime::now());
self.vm_state.lock().unwrap().start(self.clone())
}
@@ -270,7 +274,14 @@
let death_reason = death_reason(&result, &failure_reason);
self.callbacks.callback_on_died(self.cid, death_reason);
- write_vm_exited_stats(self.requester_uid as i32, &self.name, death_reason);
+
+ let vm_start_timestamp = self.vm_start_timestamp.lock().unwrap();
+ write_vm_exited_stats(
+ self.requester_uid as i32,
+ &self.name,
+ death_reason,
+ *vm_start_timestamp,
+ );
// Delete temporary files.
if let Err(e) = remove_dir_all(&self.temporary_directory) {