Console output and OS logs are separated
The console output and the log output from a VM can now be redirected to
different file descriptors. IVirtualizationService.createVm method is
extended to accept two file descriptors - one for the console output and
the one for the OS logs. The Java framework, the vm tool, the demo app,
and the compos are also modified to correctly use the modified AIDL API.
The demo app is slightly refactored to better render the two outputs on
a small screen - smaller font size, no line wrap with horizontal
scrolling.
Bug: 200914564
Test: run MicrodroidDemoApp. run microdroid using the vm tool
Change-Id: Id7bcfd75cd775a8fba5a13d5f6d2faafce2370ff
diff --git a/compos/common/compos_client.rs b/compos/common/compos_client.rs
index 6277a55..e685267 100644
--- a/compos/common/compos_client.rs
+++ b/compos/common/compos_client.rs
@@ -85,6 +85,7 @@
.context("Failed to open config APK idsig file")?;
let idsig_fd = ParcelFileDescriptor::new(idsig_fd);
+ // Console output and the system log output from the VM are redirected to this file.
// TODO: Send this to stdout instead? Or specify None?
let log_fd = File::create(data_dir.join("vm.log")).context("Failed to create log file")?;
let log_fd = ParcelFileDescriptor::new(log_fd);
@@ -100,7 +101,9 @@
..Default::default()
});
- let vm = service.createVm(&config, Some(&log_fd)).context("Failed to create VM")?;
+ let vm = service
+ .createVm(&config, Some(&log_fd), Some(&log_fd))
+ .context("Failed to create VM")?;
let vm_state = Arc::new(VmStateMonitor::default());
let vm_state_clone = Arc::clone(&vm_state);
diff --git a/compos/compos_key_cmd/compos_key_cmd.cpp b/compos/compos_key_cmd/compos_key_cmd.cpp
index 7bf622d..2735f2e 100644
--- a/compos/compos_key_cmd/compos_key_cmd.cpp
+++ b/compos/compos_key_cmd/compos_key_cmd.cpp
@@ -197,6 +197,7 @@
return Error() << "Failed to connect to virtualization service.";
}
+ // Console output and the system log output from the VM are redirected to this file.
ScopedFileDescriptor logFd;
if (mLogFile.empty()) {
logFd.set(dup(STDOUT_FILENO));
@@ -239,7 +240,7 @@
appConfig.memoryMib = 0; // Use default
LOG(INFO) << "Starting VM";
- auto status = service->createVm(config, logFd, &mVm);
+ auto status = service->createVm(config, logFd, logFd, &mVm);
if (!status.isOk()) {
return Error() << status.getDescription();
}
diff --git a/demo/java/com/android/microdroid/demo/MainActivity.java b/demo/java/com/android/microdroid/demo/MainActivity.java
index 7f54abf..60e50bb 100644
--- a/demo/java/com/android/microdroid/demo/MainActivity.java
+++ b/demo/java/com/android/microdroid/demo/MainActivity.java
@@ -64,47 +64,14 @@
protected void onCreate(Bundle savedInstanceState) {
super.onCreate(savedInstanceState);
setContentView(R.layout.activity_main);
- TextView consoleView = (TextView) findViewById(R.id.consoleOutput);
- TextView payloadView = (TextView) findViewById(R.id.payloadOutput);
Button runStopButton = (Button) findViewById(R.id.runStopButton);
- ScrollView scrollView = (ScrollView) findViewById(R.id.scrollConsoleOutput);
+ TextView consoleView = (TextView) findViewById(R.id.consoleOutput);
+ TextView logView = (TextView) findViewById(R.id.logOutput);
+ TextView payloadView = (TextView) findViewById(R.id.payloadOutput);
+ ScrollView scrollConsoleView = (ScrollView) findViewById(R.id.scrollConsoleOutput);
+ ScrollView scrollLogView = (ScrollView) findViewById(R.id.scrollLogOutput);
- // When the console output or payload output is updated, append the new line to the
- // corresponding text view.
VirtualMachineModel model = new ViewModelProvider(this).get(VirtualMachineModel.class);
- model.getConsoleOutput()
- .observeForever(
- new Observer<String>() {
- @Override
- public void onChanged(String line) {
- consoleView.append(line + "\n");
- scrollView.fullScroll(View.FOCUS_DOWN);
- }
- });
- model.getPayloadOutput()
- .observeForever(
- new Observer<String>() {
- @Override
- public void onChanged(String line) {
- payloadView.append(line + "\n");
- }
- });
-
- // When the VM status is updated, change the label of the button
- model.getStatus()
- .observeForever(
- new Observer<VirtualMachine.Status>() {
- @Override
- public void onChanged(VirtualMachine.Status status) {
- if (status == VirtualMachine.Status.RUNNING) {
- runStopButton.setText("Stop");
- consoleView.setText("");
- payloadView.setText("");
- } else {
- runStopButton.setText("Run");
- }
- }
- });
// When the button is clicked, run or stop the VM
runStopButton.setOnClickListener(
@@ -119,12 +86,86 @@
}
}
});
+
+ // When the VM status is updated, change the label of the button
+ model.getStatus()
+ .observeForever(
+ new Observer<VirtualMachine.Status>() {
+ @Override
+ public void onChanged(VirtualMachine.Status status) {
+ if (status == VirtualMachine.Status.RUNNING) {
+ runStopButton.setText("Stop");
+ // Clear the outputs from the previous run
+ consoleView.setText("");
+ logView.setText("");
+ payloadView.setText("");
+ } else {
+ runStopButton.setText("Run");
+ }
+ }
+ });
+
+ // When the console, log, or payload output is updated, append the new line to the
+ // corresponding text view.
+ model.getConsoleOutput()
+ .observeForever(
+ new Observer<String>() {
+ @Override
+ public void onChanged(String line) {
+ consoleView.append(line + "\n");
+ scrollConsoleView.fullScroll(View.FOCUS_DOWN);
+ }
+ });
+ model.getLogOutput()
+ .observeForever(
+ new Observer<String>() {
+ @Override
+ public void onChanged(String line) {
+ logView.append(line + "\n");
+ scrollLogView.fullScroll(View.FOCUS_DOWN);
+ }
+ });
+ model.getPayloadOutput()
+ .observeForever(
+ new Observer<String>() {
+ @Override
+ public void onChanged(String line) {
+ payloadView.append(line + "\n");
+ }
+ });
}
- /** Models a virtual machine and console output from it. */
+ /** Reads data from an input stream and posts it to the output data */
+ static class Reader implements Runnable {
+ private final String mName;
+ private final MutableLiveData<String> mOutput;
+ private final InputStream mStream;
+
+ Reader(String name, MutableLiveData<String> output, InputStream stream) {
+ mName = name;
+ mOutput = output;
+ mStream = stream;
+ }
+
+ @Override
+ public void run() {
+ try {
+ BufferedReader reader = new BufferedReader(new InputStreamReader(mStream));
+ String line;
+ while ((line = reader.readLine()) != null && !Thread.interrupted()) {
+ mOutput.postValue(line);
+ }
+ } catch (IOException e) {
+ Log.e(TAG, "Exception while posting " + mName + " output: " + e.getMessage());
+ }
+ }
+ }
+
+ /** Models a virtual machine and outputs from it. */
public static class VirtualMachineModel extends AndroidViewModel {
private VirtualMachine mVirtualMachine;
private final MutableLiveData<String> mConsoleOutput = new MutableLiveData<>();
+ private final MutableLiveData<String> mLogOutput = new MutableLiveData<>();
private final MutableLiveData<String> mPayloadOutput = new MutableLiveData<>();
private final MutableLiveData<VirtualMachine.Status> mStatus = new MutableLiveData<>();
private ExecutorService mExecutorService;
@@ -134,20 +175,11 @@
mStatus.setValue(VirtualMachine.Status.DELETED);
}
- private static void postOutput(MutableLiveData<String> output, InputStream stream)
- throws IOException {
- BufferedReader reader = new BufferedReader(new InputStreamReader(stream));
- String line;
- while ((line = reader.readLine()) != null && !Thread.interrupted()) {
- output.postValue(line);
- }
- }
-
/** Runs a VM */
public void run(boolean debug) {
// Create a VM and run it.
// TODO(jiyong): remove the call to idsigPath
- mExecutorService = Executors.newFixedThreadPool(3);
+ mExecutorService = Executors.newFixedThreadPool(4);
VirtualMachineCallback callback =
new VirtualMachineCallback() {
@@ -162,23 +194,8 @@
return;
}
- mService.execute(
- new Runnable() {
- @Override
- public void run() {
- try {
- postOutput(
- mPayloadOutput,
- new FileInputStream(
- stream.getFileDescriptor()));
- } catch (IOException e) {
- Log.e(
- TAG,
- "IOException while reading payload: "
- + e.getMessage());
- }
- }
- });
+ InputStream input = new FileInputStream(stream.getFileDescriptor());
+ mService.execute(new Reader("payload", mPayloadOutput, input));
}
@Override
@@ -270,26 +287,14 @@
mVirtualMachine.run();
mVirtualMachine.setCallback(callback);
mStatus.postValue(mVirtualMachine.getStatus());
+
+ InputStream console = mVirtualMachine.getConsoleOutputStream();
+ InputStream log = mVirtualMachine.getLogOutputStream();
+ mExecutorService.execute(new Reader("console", mConsoleOutput, console));
+ mExecutorService.execute(new Reader("log", mLogOutput, log));
} catch (VirtualMachineException e) {
throw new RuntimeException(e);
}
-
- // Read console output from the VM in the background
- mExecutorService.execute(
- new Runnable() {
- @Override
- public void run() {
- try {
- postOutput(
- mConsoleOutput, mVirtualMachine.getConsoleOutputStream());
- } catch (IOException | VirtualMachineException e) {
- Log.e(
- TAG,
- "Exception while posting console output: "
- + e.getMessage());
- }
- }
- });
}
/** Stops the running VM */
@@ -309,6 +314,11 @@
return mConsoleOutput;
}
+ /** Returns the log output from the VM */
+ public LiveData<String> getLogOutput() {
+ return mLogOutput;
+ }
+
/** Returns the payload output from the VM */
public LiveData<String> getPayloadOutput() {
return mPayloadOutput;
diff --git a/demo/res/layout/activity_main.xml b/demo/res/layout/activity_main.xml
index e100027..f0e35d6 100644
--- a/demo/res/layout/activity_main.xml
+++ b/demo/res/layout/activity_main.xml
@@ -62,17 +62,50 @@
<ScrollView
android:id="@+id/scrollConsoleOutput"
- android:layout_width="match_parent"
+ android:layout_width="wrap_content"
android:layout_height="0dp"
android:layout_weight="2">
- <TextView
- android:id="@+id/consoleOutput"
+ <HorizontalScrollView
android:layout_width="match_parent"
- android:layout_height="wrap_content"
- android:background="#FFEB3B"
- android:fontFamily="monospace"
- android:textColor="#000000" />
+ android:layout_height="match_parent">
+
+ <TextView
+ android:id="@+id/consoleOutput"
+ android:layout_width="wrap_content"
+ android:layout_height="wrap_content"
+ android:background="#FFEB3B"
+ android:fontFamily="monospace"
+ android:textSize="10sp"
+ android:textColor="#000000" />
+ </HorizontalScrollView>
+ </ScrollView>
+
+ <TextView
+ android:layout_width="wrap_content"
+ android:layout_height="wrap_content"
+ android:layout_marginTop="10dp"
+ android:text="Log output:" />
+
+ <ScrollView
+ android:id="@+id/scrollLogOutput"
+ android:layout_width="wrap_content"
+ android:layout_height="0dp"
+ android:layout_weight="2">
+
+ <HorizontalScrollView
+ android:layout_width="match_parent"
+ android:layout_height="match_parent">
+
+ <TextView
+ android:id="@+id/logOutput"
+ android:layout_width="wrap_content"
+ android:layout_height="wrap_content"
+ android:background="#FFEB3B"
+ android:fontFamily="monospace"
+ android:textSize="10sp"
+ android:textColor="#000000" />
+ </HorizontalScrollView>
</ScrollView>
</LinearLayout>
diff --git a/javalib/src/android/system/virtualmachine/VirtualMachine.java b/javalib/src/android/system/virtualmachine/VirtualMachine.java
index d2e6253..63c9288 100644
--- a/javalib/src/android/system/virtualmachine/VirtualMachine.java
+++ b/javalib/src/android/system/virtualmachine/VirtualMachine.java
@@ -113,6 +113,9 @@
private @Nullable ParcelFileDescriptor mConsoleReader;
private @Nullable ParcelFileDescriptor mConsoleWriter;
+ private @Nullable ParcelFileDescriptor mLogReader;
+ private @Nullable ParcelFileDescriptor mLogWriter;
+
private final ExecutorService mExecutorService = Executors.newCachedThreadPool();
static {
@@ -297,6 +300,12 @@
mConsoleWriter = pipe[1];
}
+ if (mLogReader == null && mLogWriter == null) {
+ ParcelFileDescriptor[] pipe = ParcelFileDescriptor.createPipe();
+ mLogReader = pipe[0];
+ mLogWriter = pipe[1];
+ }
+
VirtualMachineAppConfig appConfig = getConfig().toParcel();
// Fill the idsig file by hashing the apk
@@ -310,7 +319,7 @@
android.system.virtualizationservice.VirtualMachineConfig vmConfigParcel =
android.system.virtualizationservice.VirtualMachineConfig.appConfig(appConfig);
- mVirtualMachine = service.createVm(vmConfigParcel, mConsoleWriter);
+ mVirtualMachine = service.createVm(vmConfigParcel, mConsoleWriter, mLogWriter);
mVirtualMachine.registerCallback(
new IVirtualMachineCallback.Stub() {
@Override
@@ -377,6 +386,14 @@
return new FileInputStream(mConsoleReader.getFileDescriptor());
}
+ /** Returns the stream object representing the log output from the virtual machine. */
+ public @NonNull InputStream getLogOutputStream() throws VirtualMachineException {
+ if (mLogReader == null) {
+ throw new VirtualMachineException("Log output not available");
+ }
+ return new FileInputStream(mLogReader.getFileDescriptor());
+ }
+
/**
* Stops this virtual machine. Stopping a virtual machine is like pulling the plug on a real
* computer; the machine halts immediately. Software running on the virtual machine is not
diff --git a/tests/vsock_test.cc b/tests/vsock_test.cc
index 480d05a..0b863a9 100644
--- a/tests/vsock_test.cc
+++ b/tests/vsock_test.cc
@@ -85,7 +85,7 @@
VirtualMachineConfig config(std::move(raw_config));
sp<IVirtualMachine> vm;
- status = virtualization_service->createVm(config, std::nullopt, &vm);
+ status = virtualization_service->createVm(config, std::nullopt, std::nullopt, &vm);
ASSERT_TRUE(status.isOk()) << "Error creating VM: " << status;
int32_t cid;
diff --git a/virtualizationservice/aidl/android/system/virtualizationservice/IVirtualizationService.aidl b/virtualizationservice/aidl/android/system/virtualizationservice/IVirtualizationService.aidl
index 8be7331..e417ec4 100644
--- a/virtualizationservice/aidl/android/system/virtualizationservice/IVirtualizationService.aidl
+++ b/virtualizationservice/aidl/android/system/virtualizationservice/IVirtualizationService.aidl
@@ -23,10 +23,13 @@
interface IVirtualizationService {
/**
* Create the VM with the given config file, and return a handle to it ready to start it. If
- * `logFd` is provided then console logs from the VM will be sent to it.
+ * `consoleFd` is provided then console output from the VM will be sent to it. If `osLogFd` is
+ * provided then the OS-level logs will be sent to it. `osLogFd` is supported only when the OS
+ * running in the VM has the logging system. In case of Microdroid, the logging system is logd.
*/
- IVirtualMachine createVm(
- in VirtualMachineConfig config, in @nullable ParcelFileDescriptor logFd);
+ IVirtualMachine createVm(in VirtualMachineConfig config,
+ in @nullable ParcelFileDescriptor consoleFd,
+ in @nullable ParcelFileDescriptor osLogFd);
/**
* Initialise an empty partition image of the given size to be used as a writable partition.
diff --git a/virtualizationservice/src/aidl.rs b/virtualizationservice/src/aidl.rs
index 2f901b4..74a9365 100644
--- a/virtualizationservice/src/aidl.rs
+++ b/virtualizationservice/src/aidl.rs
@@ -122,10 +122,12 @@
fn createVm(
&self,
config: &VirtualMachineConfig,
+ console_fd: Option<&ParcelFileDescriptor>,
log_fd: Option<&ParcelFileDescriptor>,
) -> binder::Result<Strong<dyn IVirtualMachine>> {
check_manage_access()?;
let state = &mut *self.state.lock().unwrap();
+ let mut console_fd = console_fd.map(clone_file).transpose()?;
let mut log_fd = log_fd.map(clone_file).transpose()?;
let requester_uid = ThreadState::get_calling_uid();
let requester_sid = get_calling_sid()?;
@@ -160,6 +162,9 @@
// doesn't understand the bootconfig parameters.
if let VirtualMachineConfig::AppConfig(config) = config {
if config.debugLevel != DebugLevel::FULL {
+ console_fd = None;
+ }
+ if config.debugLevel == DebugLevel::NONE {
log_fd = None;
}
}
@@ -212,6 +217,7 @@
params: config.params.to_owned(),
protected: config.protectedVm,
memory_mib: config.memoryMib.try_into().ok().and_then(NonZeroU32::new),
+ console_fd,
log_fd,
indirect_files,
};
diff --git a/virtualizationservice/src/crosvm.rs b/virtualizationservice/src/crosvm.rs
index dfb1cbb..49cab59 100644
--- a/virtualizationservice/src/crosvm.rs
+++ b/virtualizationservice/src/crosvm.rs
@@ -45,6 +45,7 @@
pub params: Option<String>,
pub protected: bool,
pub memory_mib: Option<NonZeroU32>,
+ pub console_fd: Option<File>,
pub log_fd: Option<File>,
pub indirect_files: Vec<File>,
}
@@ -251,23 +252,27 @@
// 2. virtio-console device: used as the console device
// 3. virtio-console device: used as the logcat output
//
- // When log_fd is not specified, the devices are attached to sink, which means what's written
- // there is discarded.
- let path = config.log_fd.as_ref().map(|fd| add_preserved_fd(&mut preserved_fds, fd));
- let backend = path.as_ref().map_or("sink", |_| "file");
- let path_arg = path.as_ref().map_or(String::new(), |path| format!(",path={}", path));
+ // When [console|log]_fd is not specified, the devices are attached to sink, which means what's
+ // written there is discarded.
+ let mut format_serial_arg = |fd: &Option<File>| {
+ let path = fd.as_ref().map(|fd| add_preserved_fd(&mut preserved_fds, fd));
+ let type_arg = path.as_ref().map_or("type=sink", |_| "type=file");
+ let path_arg = path.as_ref().map_or(String::new(), |path| format!(",path={}", path));
+ format!("{}{}", type_arg, path_arg)
+ };
+ let console_arg = format_serial_arg(&config.console_fd);
+ let log_arg = format_serial_arg(&config.log_fd);
// Warning: Adding more serial devices requires you to shift the PCI device ID of the boot
// disks in bootconfig.x86_64. This is because x86 crosvm puts serial devices and the block
// devices in the same PCI bus and serial devices comes before the block devices. Arm crosvm
// doesn't have the issue.
// /dev/ttyS0
- command.arg(format!("--serial=type={}{},hardware=serial", backend, &path_arg));
+ command.arg(format!("--serial={},hardware=serial", &console_arg));
// /dev/hvc0
- command.arg(format!("--serial=type={}{},hardware=virtio-console,num=1", backend, &path_arg));
+ command.arg(format!("--serial={},hardware=virtio-console,num=1", &console_arg));
// /dev/hvc1
- // TODO(b/200914564) use a different fd for logcat log
- command.arg(format!("--serial=type={}{},hardware=virtio-console,num=2", backend, &path_arg));
+ command.arg(format!("--serial={},hardware=virtio-console,num=2", &log_arg));
if let Some(bootloader) = &config.bootloader {
command.arg("--bios").arg(add_preserved_fd(&mut preserved_fds, bootloader));
diff --git a/vm/src/main.rs b/vm/src/main.rs
index 7e2a925..87bcda7 100644
--- a/vm/src/main.rs
+++ b/vm/src/main.rs
@@ -57,12 +57,16 @@
#[structopt(short, long)]
daemonize: bool,
+ /// Path to file for VM console output.
+ #[structopt(long)]
+ console: Option<PathBuf>,
+
/// Path to file for VM log output.
- #[structopt(short, long)]
+ #[structopt(long)]
log: Option<PathBuf>,
/// Debug level of the VM. Supported values: "none" (default), "app_only", and "full".
- #[structopt(short, long, default_value = "none", parse(try_from_str=parse_debug_level))]
+ #[structopt(long, default_value = "none", parse(try_from_str=parse_debug_level))]
debug: DebugLevel,
/// Memory size (in MiB) of the VM. If unspecified, defaults to the value of `memory_mib`
@@ -80,9 +84,9 @@
#[structopt(short, long)]
daemonize: bool,
- /// Path to file for VM log output.
- #[structopt(short, long)]
- log: Option<PathBuf>,
+ /// Path to file for VM console output.
+ #[structopt(long)]
+ console: Option<PathBuf>,
},
/// Stop a virtual machine running in the background
Stop {
@@ -134,7 +138,7 @@
.context("Failed to find VirtualizationService")?;
match opt {
- Opt::RunApp { apk, idsig, instance, config_path, daemonize, log, debug, mem } => {
+ Opt::RunApp { apk, idsig, instance, config_path, daemonize, console, log, debug, mem } => {
command_run_app(
service,
&apk,
@@ -142,13 +146,14 @@
&instance,
&config_path,
daemonize,
+ console.as_deref(),
log.as_deref(),
debug,
mem,
)
}
- Opt::Run { config, daemonize, log } => {
- command_run(service, &config, daemonize, log.as_deref(), /* mem */ None)
+ Opt::Run { config, daemonize, console } => {
+ command_run(service, &config, daemonize, console.as_deref(), /* mem */ None)
}
Opt::Stop { cid } => command_stop(service, cid),
Opt::List => command_list(service),
diff --git a/vm/src/run.rs b/vm/src/run.rs
index 2d771fc..15775cb 100644
--- a/vm/src/run.rs
+++ b/vm/src/run.rs
@@ -44,6 +44,7 @@
instance: &Path,
config_path: &str,
daemonize: bool,
+ console_path: Option<&Path>,
log_path: Option<&Path>,
debug_level: DebugLevel,
mem: Option<u32>,
@@ -76,7 +77,14 @@
debugLevel: debug_level,
memoryMib: mem.unwrap_or(0) as i32, // 0 means use the VM default
});
- run(service, &config, &format!("{:?}!{:?}", apk, config_path), daemonize, log_path)
+ run(
+ service,
+ &config,
+ &format!("{:?}!{:?}", apk, config_path),
+ daemonize,
+ console_path,
+ log_path,
+ )
}
/// Run a VM from the given configuration file.
@@ -84,7 +92,7 @@
service: Strong<dyn IVirtualizationService>,
config_path: &Path,
daemonize: bool,
- log_path: Option<&Path>,
+ console_path: Option<&Path>,
mem: Option<u32>,
) -> Result<(), Error> {
let config_file = File::open(config_path).context("Failed to open config file")?;
@@ -98,7 +106,8 @@
&VirtualMachineConfig::RawConfig(config),
&format!("{:?}", config_path),
daemonize,
- log_path,
+ console_path,
+ None,
)
}
@@ -119,9 +128,20 @@
config: &VirtualMachineConfig,
config_path: &str,
daemonize: bool,
+ console_path: Option<&Path>,
log_path: Option<&Path>,
) -> Result<(), Error> {
- let stdout = if let Some(log_path) = log_path {
+ let console = if let Some(console_path) = console_path {
+ Some(ParcelFileDescriptor::new(
+ File::create(console_path)
+ .with_context(|| format!("Failed to open console file {:?}", console_path))?,
+ ))
+ } else if daemonize {
+ None
+ } else {
+ Some(ParcelFileDescriptor::new(duplicate_stdout()?))
+ };
+ let log = if let Some(log_path) = log_path {
Some(ParcelFileDescriptor::new(
File::create(log_path)
.with_context(|| format!("Failed to open log file {:?}", log_path))?,
@@ -131,7 +151,9 @@
} else {
Some(ParcelFileDescriptor::new(duplicate_stdout()?))
};
- let vm = service.createVm(config, stdout.as_ref()).context("Failed to create VM")?;
+
+ let vm =
+ service.createVm(config, console.as_ref(), log.as_ref()).context("Failed to create VM")?;
let cid = vm.getCid().context("Failed to get CID")?;
println!(