Merge "Log details if payload exits via signal"
diff --git a/compos/Android.bp b/compos/Android.bp
index 2af19c8..f77b2ca 100644
--- a/compos/Android.bp
+++ b/compos/Android.bp
@@ -42,6 +42,7 @@
         "libbinder_rs",
         "libclap",
         "libcompos_common",
+        "libenv_logger",
         "liblibc",
         "liblog_rust",
         "libminijail_rust",
diff --git a/compos/apk/assets/vm_config.json b/compos/apk/assets/vm_config.json
index 9be60d0..9c71942 100644
--- a/compos/apk/assets/vm_config.json
+++ b/compos/apk/assets/vm_config.json
@@ -5,7 +5,10 @@
   },
   "task": {
     "type": "executable",
-    "command": "/apex/com.android.compos/bin/compsvc"
+    "command": "/apex/com.android.compos/bin/compsvc",
+    "args": [
+      "--log_to_stderr"
+    ]
   },
   "apexes": [
     {
diff --git a/compos/apk/assets/vm_test_config.json b/compos/apk/assets/vm_test_config.json
new file mode 100644
index 0000000..54a0aac
--- /dev/null
+++ b/compos/apk/assets/vm_test_config.json
@@ -0,0 +1,18 @@
+{
+    "version": 1,
+    "os": {
+        "name": "microdroid"
+    },
+    "task": {
+        "type": "executable",
+        "command": "/apex/com.android.compos/bin/compsvc"
+    },
+    "apexes": [
+        {
+            "name": "com.android.art"
+        },
+        {
+            "name": "com.android.compos"
+        }
+    ]
+}
\ No newline at end of file
diff --git a/compos/common/compos_client.rs b/compos/common/compos_client.rs
index 03cc331..6600f6f 100644
--- a/compos/common/compos_client.rs
+++ b/compos/common/compos_client.rs
@@ -34,8 +34,9 @@
     FromIBinder,
 };
 use compos_aidl_interface::aidl::com::android::compos::ICompOsService::ICompOsService;
-use log::warn;
+use log::{info, warn};
 use std::fs::File;
+use std::io::{BufRead, BufReader};
 use std::os::raw;
 use std::os::unix::io::IntoRawFd;
 use std::path::Path;
@@ -45,7 +46,9 @@
 
 /// This owns an instance of the CompOS VM.
 pub struct VmInstance {
-    #[allow(dead_code)] // Keeps the vm alive even if we don`t touch it
+    #[allow(dead_code)] // Prevent service manager from killing the dynamic service
+    service: Strong<dyn IVirtualizationService>,
+    #[allow(dead_code)] // Keeps the VM alive even if we don`t touch it
     vm: Strong<dyn IVirtualMachine>,
     cid: i32,
 }
@@ -108,26 +111,16 @@
         // TODO: Use onPayloadReady to avoid this
         thread::sleep(Duration::from_secs(3));
 
-        Ok(VmInstance { vm, cid })
+        Ok(VmInstance { service, vm, cid })
     }
 
     /// Create and return an RPC Binder connection to the Comp OS service in the VM.
     pub fn get_service(&self) -> Result<Strong<dyn ICompOsService>> {
         let mut vsock_factory = VsockFactory::new(&*self.vm);
-        let param = vsock_factory.as_void_ptr();
 
-        let ibinder = unsafe {
-            // SAFETY: AIBinder returned by RpcPreconnectedClient has correct reference count, and
-            // the ownership can be safely taken by new_spibinder.
-            // RpcPreconnectedClient does not take ownership of param, only passing it to
-            // request_fd.
-            let binder = binder_rpc_unstable_bindgen::RpcPreconnectedClient(
-                Some(VsockFactory::request_fd),
-                param,
-            ) as *mut AIBinder;
-            new_spibinder(binder)
-        }
-        .ok_or_else(|| anyhow!("Failed to connect to CompOS service"))?;
+        let ibinder = vsock_factory
+            .connect_rpc_client()
+            .ok_or_else(|| anyhow!("Failed to connect to CompOS service"))?;
 
         FromIBinder::try_from(ibinder).context("Connecting to CompOS service")
     }
@@ -147,6 +140,21 @@
         Self { vm }
     }
 
+    fn connect_rpc_client(&mut self) -> Option<binder::SpIBinder> {
+        let param = self.as_void_ptr();
+
+        unsafe {
+            // SAFETY: AIBinder returned by RpcPreconnectedClient has correct reference count, and
+            // the ownership can be safely taken by new_spibinder.
+            // RpcPreconnectedClient does not take ownership of param, only passing it to
+            // request_fd.
+            let binder =
+                binder_rpc_unstable_bindgen::RpcPreconnectedClient(Some(Self::request_fd), param)
+                    as *mut AIBinder;
+            new_spibinder(binder)
+        }
+    }
+
     fn as_void_ptr(&mut self) -> *mut raw::c_void {
         self as *mut _ as *mut raw::c_void
     }
@@ -168,8 +176,8 @@
         // SAFETY: This is only ever called by RpcPreconnectedClient, within the lifetime of the
         // VsockFactory, with param taking the value returned by as_void_ptr (so a properly aligned
         // non-null pointer to an initialized instance).
-        let holder = param as *mut Self;
-        holder.as_ref().unwrap().new_vsock_fd()
+        let vsock_factory = param as *mut Self;
+        vsock_factory.as_ref().unwrap().new_vsock_fd()
     }
 }
 
@@ -245,10 +253,14 @@
     fn onPayloadStarted(
         &self,
         cid: i32,
-        _stream: Option<&binder::parcel::ParcelFileDescriptor>,
+        stream: Option<&ParcelFileDescriptor>,
     ) -> BinderResult<()> {
         self.0.set_started(cid);
-        // TODO: Use the stream?
+        if let Some(pfd) = stream {
+            if let Err(e) = start_logging(pfd) {
+                warn!("Can't log vm output: {}", e);
+            };
+        }
         log::info!("VM payload started, cid = {}", cid);
         Ok(())
     }
@@ -267,3 +279,19 @@
         Ok(())
     }
 }
+
+fn start_logging(pfd: &ParcelFileDescriptor) -> Result<()> {
+    let reader = BufReader::new(pfd.as_ref().try_clone().context("Cloning fd failed")?);
+    thread::spawn(move || {
+        for line in reader.lines() {
+            match line {
+                Ok(line) => info!("VM: {}", line),
+                Err(e) => {
+                    warn!("Reading VM output failed: {}", e);
+                    break;
+                }
+            }
+        }
+    });
+    Ok(())
+}
diff --git a/compos/compos_key_cmd/compos_key_cmd.cpp b/compos/compos_key_cmd/compos_key_cmd.cpp
index ff53548..4e51d8d 100644
--- a/compos/compos_key_cmd/compos_key_cmd.cpp
+++ b/compos/compos_key_cmd/compos_key_cmd.cpp
@@ -31,6 +31,7 @@
 #include <openssl/mem.h>
 #include <openssl/sha.h>
 #include <openssl/x509.h>
+#include <stdio.h>
 #include <unistd.h>
 
 #include <binder_rpc_unstable.hpp>
@@ -41,6 +42,7 @@
 #include <mutex>
 #include <string>
 #include <string_view>
+#include <thread>
 
 #include "compos_signature.pb.h"
 
@@ -56,6 +58,7 @@
 using aidl::com::android::compos::ICompOsService;
 using android::base::ErrnoError;
 using android::base::Error;
+using android::base::Fdopen;
 using android::base::Result;
 using android::base::unique_fd;
 using compos::proto::Signature;
@@ -94,12 +97,35 @@
 }
 
 namespace {
+
+void copyToLog(unique_fd&& fd) {
+    FILE* source = Fdopen(std::move(fd), "r");
+    size_t size = 0;
+    char* line = nullptr;
+
+    LOG(INFO) << "Started logging VM output";
+
+    for (;;) {
+        ssize_t len = getline(&line, &size, source);
+        if (len < 0) {
+            LOG(INFO) << "VM logging ended: " << ErrnoError().str();
+            break;
+        }
+        LOG(DEBUG) << "VM: " << std::string_view(line, len);
+    }
+    free(line);
+}
+
 class Callback : public BnVirtualMachineCallback {
 public:
-    ::ndk::ScopedAStatus onPayloadStarted(
-            int32_t in_cid, const ::ndk::ScopedFileDescriptor& /*in_stream*/) override {
-        // TODO: Consider copying stdout somewhere useful?
+    ::ndk::ScopedAStatus onPayloadStarted(int32_t in_cid,
+                                          const ::ndk::ScopedFileDescriptor& stream) override {
         LOG(INFO) << "Payload started! cid = " << in_cid;
+
+        unique_fd stream_fd(dup(stream.get()));
+        std::thread logger([fd = std::move(stream_fd)]() mutable { copyToLog(std::move(fd)); });
+        logger.detach();
+
         {
             std::unique_lock lock(mMutex);
             mStarted = true;
@@ -255,6 +281,7 @@
     std::shared_ptr<Callback> mCallback;
     std::shared_ptr<IVirtualMachine> mVm;
 };
+
 } // namespace
 
 static Result<std::vector<uint8_t>> extractRsaPublicKey(
diff --git a/compos/src/compsvc_main.rs b/compos/src/compsvc_main.rs
index 9855b53..2b445c1 100644
--- a/compos/src/compsvc_main.rs
+++ b/compos/src/compsvc_main.rs
@@ -28,9 +28,16 @@
 use log::debug;
 
 fn main() -> Result<()> {
-    android_logger::init_once(
-        android_logger::Config::default().with_tag("compsvc").with_min_level(log::Level::Debug),
-    );
+    let args = clap::App::new("compsvc")
+        .arg(clap::Arg::with_name("log_to_stderr").long("log_to_stderr"))
+        .get_matches();
+    if args.is_present("log_to_stderr") {
+        env_logger::builder().filter_level(log::LevelFilter::Debug).init();
+    } else {
+        android_logger::init_once(
+            android_logger::Config::default().with_tag("compsvc").with_min_level(log::Level::Debug),
+        );
+    }
 
     let mut service = compsvc::new_binder()?.as_binder();
     debug!("compsvc is starting as a rpc service.");
diff --git a/compos/tests/java/android/compos/test/ComposKeyTestCase.java b/compos/tests/java/android/compos/test/ComposKeyTestCase.java
index 64fd969..00b002f 100644
--- a/compos/tests/java/android/compos/test/ComposKeyTestCase.java
+++ b/compos/tests/java/android/compos/test/ComposKeyTestCase.java
@@ -158,7 +158,7 @@
                         getBuild(),
                         apkName,
                         packageName,
-                        "assets/vm_config.json",
+                        "assets/vm_test_config.json",
                         /* debug */ false);
         adbConnectToMicrodroid(getDevice(), mCid);
     }
diff --git a/compos/tests/java/android/compos/test/ComposTestCase.java b/compos/tests/java/android/compos/test/ComposTestCase.java
index 8409f44..42a323f 100644
--- a/compos/tests/java/android/compos/test/ComposTestCase.java
+++ b/compos/tests/java/android/compos/test/ComposTestCase.java
@@ -149,7 +149,7 @@
                         getBuild(),
                         apkName,
                         packageName,
-                        "assets/vm_config.json",
+                        "assets/vm_test_config.json",
                         /* debug */ false);
         adbConnectToMicrodroid(getDevice(), mCid);
     }