Redirect debuggable VM's logs to host logd
Bug: 238593451
Test: atest MicrodroidTestApp MicrodroidHostTestCases
Test: run debuggable VM and see logcat
Change-Id: I9cdf69d539d07b5e8be40f872db3a3c222bd69e7
diff --git a/tests/hostside/java/com/android/microdroid/test/MicrodroidHostTests.java b/tests/hostside/java/com/android/microdroid/test/MicrodroidHostTests.java
index 2ee33e6..8767177 100644
--- a/tests/hostside/java/com/android/microdroid/test/MicrodroidHostTests.java
+++ b/tests/hostside/java/com/android/microdroid/test/MicrodroidHostTests.java
@@ -75,6 +75,7 @@
import java.util.Arrays;
import java.util.List;
import java.util.Map;
+import java.util.Optional;
import java.util.concurrent.Callable;
import java.util.concurrent.TimeUnit;
import java.util.function.Function;
@@ -96,6 +97,8 @@
private static final int BOOT_COMPLETE_TIMEOUT = 30000; // 30 seconds
+ private static final Pattern sCIDPattern = Pattern.compile("with CID (\\d+)");
+
private static class VmInfo {
final Process mProcess;
final String mCid;
@@ -387,16 +390,23 @@
return new VmInfo(process, extractCidFrom(pis));
}
+ private static Optional<String> tryExtractCidFrom(String str) {
+ Matcher matcher = sCIDPattern.matcher(str);
+ if (matcher.find()) {
+ return Optional.of(matcher.group(1));
+ }
+ return Optional.empty();
+ }
+
private static String extractCidFrom(InputStream input) throws IOException {
String cid = null;
- Pattern pattern = Pattern.compile("with CID (\\d+)");
String line;
try (BufferedReader out = new BufferedReader(new InputStreamReader(input))) {
while ((line = out.readLine()) != null) {
CLog.i("VM output: " + line);
- Matcher matcher = pattern.matcher(line);
- if (matcher.find()) {
- cid = matcher.group(1);
+ Optional<String> result = tryExtractCidFrom(line);
+ if (result.isPresent()) {
+ cid = result.get();
break;
}
}
diff --git a/tests/testapk/src/java/com/android/microdroid/test/MicrodroidTests.java b/tests/testapk/src/java/com/android/microdroid/test/MicrodroidTests.java
index 5c3be5f..7fceea9 100644
--- a/tests/testapk/src/java/com/android/microdroid/test/MicrodroidTests.java
+++ b/tests/testapk/src/java/com/android/microdroid/test/MicrodroidTests.java
@@ -50,6 +50,7 @@
import com.android.microdroid.test.device.MicrodroidDeviceTestBase;
import com.android.microdroid.testservice.ITestService;
+import com.google.common.base.Strings;
import com.google.common.truth.BooleanSubject;
import org.junit.After;
@@ -76,6 +77,8 @@
import java.nio.file.Files;
import java.nio.file.Path;
import java.nio.file.Paths;
+import java.time.LocalDateTime;
+import java.time.format.DateTimeFormatter;
import java.util.Arrays;
import java.util.List;
import java.util.OptionalLong;
@@ -1260,7 +1263,7 @@
}
@Test
- public void outputsShouldBeExplicitlyForwarded() throws Exception {
+ public void outputShouldBeExplicitlyCaptured() throws Exception {
assumeSupportedKernel();
final VirtualMachineConfig vmConfig =
@@ -1282,6 +1285,57 @@
}
}
+ private boolean checkVmOutputIsRedirectedToLogcat(boolean debuggable) throws Exception {
+ String time =
+ LocalDateTime.now().format(DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss.SSS"));
+ final VirtualMachineConfig vmConfig =
+ new VirtualMachineConfig.Builder(ApplicationProvider.getApplicationContext())
+ .setProtectedVm(mProtectedVm)
+ .setPayloadBinaryName("MicrodroidTestNativeLib.so")
+ .setDebugLevel(debuggable ? DEBUG_LEVEL_FULL : DEBUG_LEVEL_NONE)
+ .setVmOutputCaptured(false)
+ .build();
+ final VirtualMachine vm = forceCreateNewVirtualMachine("test_vm_logcat", vmConfig);
+
+ VmEventListener listener =
+ new VmEventListener() {
+ @Override
+ public void onPayloadStarted(VirtualMachine vm) {
+ forceStop(vm);
+ }
+ };
+ listener.runToFinish(TAG, vm);
+
+ // only check logs printed after this test
+ Process logcatProcess =
+ new ProcessBuilder()
+ .command(
+ "logcat",
+ "-e",
+ "virtualizationservice::aidl: Console.*executing main task",
+ "-t",
+ time)
+ .start();
+ logcatProcess.waitFor();
+ BufferedReader reader =
+ new BufferedReader(new InputStreamReader(logcatProcess.getInputStream()));
+ return !Strings.isNullOrEmpty(reader.readLine());
+ }
+
+ @Test
+ public void outputIsRedirectedToLogcatIfNotCaptured() throws Exception {
+ assumeSupportedKernel();
+
+ assertThat(checkVmOutputIsRedirectedToLogcat(true)).isTrue();
+ }
+
+ @Test
+ public void outputIsNotRedirectedToLogcatIfNotDebuggable() throws Exception {
+ assumeSupportedKernel();
+
+ assertThat(checkVmOutputIsRedirectedToLogcat(false)).isFalse();
+ }
+
private void assertFileContentsAreEqualInTwoVms(String fileName, String vmName1, String vmName2)
throws IOException {
File file1 = getVmFile(vmName1, fileName);
diff --git a/virtualizationservice/src/aidl.rs b/virtualizationservice/src/aidl.rs
index 374b90f..e968830 100644
--- a/virtualizationservice/src/aidl.rs
+++ b/virtualizationservice/src/aidl.rs
@@ -35,7 +35,7 @@
MemoryTrimLevel::MemoryTrimLevel,
Partition::Partition,
PartitionType::PartitionType,
- VirtualMachineAppConfig::{Payload::Payload, VirtualMachineAppConfig},
+ VirtualMachineAppConfig::{DebugLevel::DebugLevel, Payload::Payload, VirtualMachineAppConfig},
VirtualMachineConfig::VirtualMachineConfig,
VirtualMachineDebugInfo::VirtualMachineDebugInfo,
VirtualMachinePayloadConfig::VirtualMachinePayloadConfig,
@@ -63,6 +63,7 @@
use libc::VMADDR_CID_HOST;
use log::{debug, error, info, warn};
use microdroid_payload_config::{OsConfig, Task, TaskType, VmPayloadConfig};
+use nix::unistd::pipe;
use rpcbinder::RpcServer;
use rustutils::system_properties;
use semver::VersionReq;
@@ -70,7 +71,7 @@
use std::convert::TryInto;
use std::ffi::CStr;
use std::fs::{create_dir, read_dir, remove_dir, remove_file, set_permissions, File, OpenOptions, Permissions};
-use std::io::{Error, ErrorKind, Read, Write};
+use std::io::{BufRead, BufReader, Error, ErrorKind, Read, Write};
use std::num::NonZeroU32;
use std::os::unix::fs::PermissionsExt;
use std::os::unix::io::{FromRawFd, IntoRawFd};
@@ -622,8 +623,9 @@
})?;
let state = &mut *self.state.lock().unwrap();
- let console_fd = console_fd.map(clone_file).transpose()?;
- let log_fd = log_fd.map(clone_file).transpose()?;
+ let console_fd =
+ clone_or_prepare_logger_fd(config, console_fd, format!("Console({})", cid))?;
+ let log_fd = clone_or_prepare_logger_fd(config, log_fd, format!("Log({})", cid))?;
// Counter to generate unique IDs for temporary image files.
let mut next_temporary_image_id = 0;
@@ -1262,6 +1264,57 @@
})
}
+fn is_debuggable(config: &VirtualMachineConfig) -> bool {
+ match config {
+ VirtualMachineConfig::AppConfig(config) => config.debugLevel != DebugLevel::NONE,
+ _ => false,
+ }
+}
+
+fn clone_or_prepare_logger_fd(
+ config: &VirtualMachineConfig,
+ fd: Option<&ParcelFileDescriptor>,
+ tag: String,
+) -> Result<Option<File>, Status> {
+ if let Some(fd) = fd {
+ return Ok(Some(clone_file(fd)?));
+ }
+
+ if !is_debuggable(config) {
+ return Ok(None);
+ }
+
+ let (raw_read_fd, raw_write_fd) = pipe().map_err(|e| {
+ Status::new_service_specific_error_str(-1, Some(format!("Failed to create pipe: {:?}", e)))
+ })?;
+
+ // SAFETY: We are the sole owners of these fds as they were just created.
+ let mut reader = BufReader::new(unsafe { File::from_raw_fd(raw_read_fd) });
+ let write_fd = unsafe { File::from_raw_fd(raw_write_fd) };
+
+ std::thread::spawn(move || loop {
+ let mut buf = vec![];
+ match reader.read_until(b'\n', &mut buf) {
+ Ok(0) => {
+ // EOF
+ return;
+ }
+ Ok(size) => {
+ if buf[size - 1] == b'\n' {
+ buf.pop();
+ }
+ info!("{}: {}", &tag, &String::from_utf8_lossy(&buf));
+ }
+ Err(e) => {
+ error!("Could not read console pipe: {:?}", e);
+ return;
+ }
+ };
+ });
+
+ Ok(Some(write_fd))
+}
+
/// Simple utility for referencing Borrowed or Owned. Similar to std::borrow::Cow, but
/// it doesn't require that T implements Clone.
enum BorrowedOrOwned<'a, T> {