Make starterd print out its own version on failed applications

We already printed out application versions if they had self-reported a
timing report before crashing; however, it is useful to always have
_some_ version information, so include the starterd's own version in the
log message.

Change-Id: Ia75b8a1b2f54bc659d05b05d131acefa6e2aa8ee
Signed-off-by: James Kuszmaul <james.kuszmaul@bluerivertech.com>
diff --git a/aos/starter/starter_demo.py b/aos/starter/starter_demo.py
index 89d06a0..12d8775 100755
--- a/aos/starter/starter_demo.py
+++ b/aos/starter/starter_demo.py
@@ -48,5 +48,5 @@
             os.makedirs(os.path.dirname(destination), exist_ok=True)
             shutil.copy(config, destination)
             shutil.copy(config, f"{tmpdir}/aos_config.{suffix}")
-        args = [tmpdir + "/starterd"]
+        args = [tmpdir + "/starterd", "--version_string=starter_version"]
         subprocess.run(args, check=True, cwd=tmpdir)
diff --git a/aos/starter/starterd.cc b/aos/starter/starterd.cc
index d6caf3f..1ac4514 100644
--- a/aos/starter/starterd.cc
+++ b/aos/starter/starterd.cc
@@ -10,6 +10,8 @@
 DEFINE_string(config, "aos_config.json", "File path of aos configuration");
 DEFINE_string(user, "",
               "Starter runs as though this user ran a SUID binary if set.");
+DEFINE_string(version_string, "",
+              "Version to report for starterd and subprocesses.");
 
 DECLARE_string(shm_base);
 DEFINE_bool(purge_shm_base, false,
@@ -58,6 +60,9 @@
   const aos::Configuration *config_msg = &config.message();
 
   aos::starter::Starter starter(config_msg);
+  if (!FLAGS_version_string.empty()) {
+    starter.event_loop()->SetVersionString(FLAGS_version_string);
+  }
 
   starter.Run();
 
diff --git a/aos/starter/subprocess.cc b/aos/starter/subprocess.cc
index b6a20f0..9606adc 100644
--- a/aos/starter/subprocess.cc
+++ b/aos/starter/subprocess.cc
@@ -725,17 +725,22 @@
     stop_reason_ = static_cast<aos::starter::LastStopReason>(*read_result);
   }
 
+  const std::string starter_version_string =
+      absl::StrCat("starter version '",
+                   event_loop_->VersionString().value_or("unknown"), "'");
   switch (status_) {
     case aos::starter::State::STARTING: {
       if (exit_code_.value() == 0) {
         LOG_IF(INFO, quiet_flag_ == QuietLogging::kNo)
             << "Application '" << name_ << "' pid " << pid_
-            << " exited with status " << exit_code_.value();
+            << " exited with status " << exit_code_.value() << " and "
+            << starter_version_string;
       } else {
         LOG_IF(WARNING, quiet_flag_ == QuietLogging::kNo ||
                             quiet_flag_ == QuietLogging::kNotForDebugging)
             << "Failed to start '" << name_ << "' on pid " << pid_
-            << " : Exited with status " << exit_code_.value();
+            << " : Exited with status " << exit_code_.value() << " and "
+            << starter_version_string;
       }
       if (autorestart()) {
         QueueStart();
@@ -753,13 +758,13 @@
       } else {
         if (quiet_flag_ == QuietLogging::kNo ||
             quiet_flag_ == QuietLogging::kNotForDebugging) {
-          std::string version_string =
+          const std::string version_string =
               latest_timing_report_version_.has_value()
-                  ? absl::StrCat("'", latest_timing_report_version_.value(),
-                                 "'")
-                  : "unknown";
+                  ? absl::StrCat("version '",
+                                 latest_timing_report_version_.value(), "'")
+                  : starter_version_string;
           LOG_IF(WARNING, quiet_flag_ == QuietLogging::kNo)
-              << "Application '" << name_ << "' pid " << pid_ << " version "
+              << "Application '" << name_ << "' pid " << pid_ << " "
               << version_string << " exited unexpectedly with status "
               << exit_code_.value();
         }
diff --git a/aos/starter/subprocess_test.cc b/aos/starter/subprocess_test.cc
index 12f7f6d..fcc1128 100644
--- a/aos/starter/subprocess_test.cc
+++ b/aos/starter/subprocess_test.cc
@@ -105,6 +105,89 @@
   ASSERT_EQ(aos::starter::State::STOPPED, echo_stderr.status());
 }
 
+// Checks that when a child application crashing results in the starter printing
+// out its own version by default.
+TEST_F(SubprocessTest, PrintNoTimingReportVersionString) {
+  const std::string config_file =
+      ::aos::testing::ArtifactPath("aos/events/pingpong_config.json");
+
+  ::testing::internal::CaptureStderr();
+
+  // Set up application without quiet flag active
+  aos::FlatbufferDetachedBuffer<aos::Configuration> config =
+      aos::configuration::ReadConfig(config_file);
+  aos::ShmEventLoop event_loop(&config.message());
+  event_loop.SetVersionString("version_string");
+  bool observed_stopped = false;
+  Application error_out(
+      "false", "bash", &event_loop,
+      [&observed_stopped, &error_out]() {
+        if (error_out.status() == aos::starter::State::STOPPED) {
+          observed_stopped = true;
+        }
+      },
+      Application::QuietLogging::kNo);
+  error_out.set_args({"-c", "sleep 3; false"});
+
+  error_out.Start();
+  aos::TimerHandler *exit_timer =
+      event_loop.AddTimer([&event_loop]() { event_loop.Exit(); });
+  event_loop.OnRun([&event_loop, exit_timer]() {
+    exit_timer->Schedule(event_loop.monotonic_now() +
+                         std::chrono::milliseconds(5000));
+  });
+
+  event_loop.Run();
+
+  // Ensure presence of logs without quiet flag
+  std::string output = ::testing::internal::GetCapturedStderr();
+  std::string expected = "starter version 'version_string'";
+
+  ASSERT_TRUE(output.find(expected) != std::string::npos) << output;
+  EXPECT_TRUE(observed_stopped);
+  EXPECT_EQ(aos::starter::State::STOPPED, error_out.status());
+}
+
+TEST_F(SubprocessTest, PrintFailedToStartVersionString) {
+  const std::string config_file =
+      ::aos::testing::ArtifactPath("aos/events/pingpong_config.json");
+
+  ::testing::internal::CaptureStderr();
+
+  // Set up application without quiet flag active
+  aos::FlatbufferDetachedBuffer<aos::Configuration> config =
+      aos::configuration::ReadConfig(config_file);
+  aos::ShmEventLoop event_loop(&config.message());
+  event_loop.SetVersionString("version_string");
+  bool observed_stopped = false;
+  Application error_out(
+      "false", "false", &event_loop,
+      [&observed_stopped, &error_out]() {
+        if (error_out.status() == aos::starter::State::STOPPED) {
+          observed_stopped = true;
+        }
+      },
+      Application::QuietLogging::kNo);
+
+  error_out.Start();
+  aos::TimerHandler *exit_timer =
+      event_loop.AddTimer([&event_loop]() { event_loop.Exit(); });
+  event_loop.OnRun([&event_loop, exit_timer]() {
+    exit_timer->Schedule(event_loop.monotonic_now() +
+                         std::chrono::milliseconds(1500));
+  });
+
+  event_loop.Run();
+
+  // Ensure presence of logs without quiet flag
+  std::string output = ::testing::internal::GetCapturedStderr();
+  std::string expected = "starter version 'version_string'";
+
+  ASSERT_TRUE(output.find(expected) != std::string::npos) << output;
+  EXPECT_TRUE(observed_stopped);
+  EXPECT_EQ(aos::starter::State::STOPPED, error_out.status());
+}
+
 TEST_F(SubprocessTest, UnactiveQuietFlag) {
   const std::string config_file =
       ::aos::testing::ArtifactPath("aos/events/pingpong_config.json");
@@ -142,7 +225,8 @@
   std::string expectedRun = "exited unexpectedly with status";
 
   ASSERT_TRUE(output.find(expectedStart) != std::string::npos ||
-              output.find(expectedRun) != std::string::npos);
+              output.find(expectedRun) != std::string::npos)
+      << output;
   EXPECT_TRUE(observed_stopped);
   EXPECT_EQ(aos::starter::State::STOPPED, error_out.status());
 }