update_engine: Log output of alive subprocesses on exit.

Currently if an update engine spawned subprocess (like postinst) shuts down the
system, the update engine does not include the logs it buffered for that
subprocess in its log and debugging will may become impossible. This patch logs
the buffered output of all alive subprocesses upon exit.

BUG=chromium:818834
BUG=b:74120207
TEST=cros flashed and rebooted the system while UE was running postinst. Then
the postinst log was partially logged in the UE log.

Change-Id: I75035f14e310a43a087511daa2a674794e5f373e
Reviewed-on: https://chromium-review.googlesource.com/954327
Commit-Ready: Amin Hassani <ahassani@chromium.org>
Tested-by: Amin Hassani <ahassani@chromium.org>
Reviewed-by: Nicolas Norvez <norvez@chromium.org>
diff --git a/common/subprocess.cc b/common/subprocess.cc
index 4e6d352..bc02abc 100644
--- a/common/subprocess.cc
+++ b/common/subprocess.cc
@@ -23,6 +23,7 @@
 
 #include <memory>
 #include <string>
+#include <utility>
 #include <vector>
 
 #include <base/bind.h>
@@ -289,6 +290,22 @@
   return false;
 }
 
+void Subprocess::FlushBufferedLogsAtExit() {
+  if (!subprocess_records_.empty()) {
+    LOG(INFO) << "We are exiting, but there are still in flight subprocesses!";
+    for (auto& pid_record : subprocess_records_) {
+      SubprocessRecord* record = pid_record.second.get();
+      // Make sure we read any remaining process output.
+      OnStdoutReady(record);
+      if (!record->stdout.empty()) {
+        LOG(INFO) << "Subprocess(" << pid_record.first << ") output:\n"
+                  << record->stdout;
+      }
+    }
+  }
+}
+
+
 Subprocess* Subprocess::subprocess_singleton_ = nullptr;
 
 }  // namespace chromeos_update_engine
diff --git a/common/subprocess.h b/common/subprocess.h
index b655fb7..7b47176 100644
--- a/common/subprocess.h
+++ b/common/subprocess.h
@@ -104,6 +104,11 @@
   // Returns true iff there is at least one subprocess we're waiting on.
   bool SubprocessInFlight();
 
+  // Tries to log all in flight processes's output. It is used right before
+  // exiting the update_engine, probably when the subprocess caused a system
+  // shutdown.
+  void FlushBufferedLogsAtExit();
+
  private:
   FRIEND_TEST(SubprocessTest, CancelTest);
 
diff --git a/main.cc b/main.cc
index 0612c54..e7df4f8 100644
--- a/main.cc
+++ b/main.cc
@@ -194,6 +194,8 @@
   chromeos_update_engine::UpdateEngineDaemon update_engine_daemon;
   int exit_code = update_engine_daemon.Run();
 
+  chromeos_update_engine::Subprocess::Get().FlushBufferedLogsAtExit();
+
   LOG(INFO) << "Chrome OS Update Engine terminating with exit code "
             << exit_code;
   return exit_code;