commit 8544c49d9efd9d578b259c0014ddb479509023da
author James Kuszmaul <james.kuszmaul@bluerivertech.com> Mon Jul 31 15:00:38 2023 -0700
committer James Kuszmaul <james.kuszmaul@bluerivertech.com> Wed Sep 13 10:24:04 2023 -0700
tree 0f788e0c26d28b08df5f641707eba659ed377258
parent 762e869c89dc843cd41909f7b8951ff91ccd1fe3

Make AOS starter print out application version on crashes

This way a journal log parser can unambiguously know what application
crahsed. Note that when an application crashes before it can send a
timing report out (e.g., if it crashes during initialization), this will
not end up helping.

Change-Id: I5217aecc395d2419ed7b622358f213cfd8ecd30f
Signed-off-by: James Kuszmaul <james.kuszmaul@bluerivertech.com>

aos/starter/subprocess.cc

diff --git a/aos/starter/subprocess.cc b/aos/starter/subprocess.cc
index b1320f4..a518c0b 100644
--- a/aos/starter/subprocess.cc
+++ b/aos/starter/subprocess.cc
@@ -8,6 +8,8 @@
 
 #include "glog/logging.h"
 
+#include "aos/flatbuffer_merge.h"
+
 namespace aos::starter {
 
 // RAII class to become root and restore back to the original user and group
@@ -202,6 +204,7 @@
       id_ = next_id_++;
       start_time_ = event_loop_->monotonic_now();
       status_ = aos::starter::State::STARTING;
+      latest_timing_report_version_.reset();
       LOG_IF(INFO, quiet_flag_ == QuietLogging::kNo)
           << "Starting '" << name_ << "' pid " << pid_;
 
@@ -308,6 +311,16 @@
   _exit(EXIT_FAILURE);
 }
 
+void Application::ObserveTimingReport(
+    const aos::monotonic_clock::time_point send_time,
+    const aos::timing::Report *msg) {
+  if (msg->name()->string_view() == name_ && msg->pid() == pid_ &&
+      msg->has_version()) {
+    latest_timing_report_version_ = msg->version()->str();
+    last_timing_report_ = send_time;
+  }
+}
+
 void Application::FetchOutputs() {
   if (capture_stdout_) {
     stdout_pipes_.read->Read(&stdout_);
@@ -462,6 +475,12 @@
   if (exit_code_.has_value()) {
     status_builder.add_last_exit_code(exit_code_.value());
   }
+  status_builder.add_has_active_timing_report(
+      last_timing_report_ +
+          // Leave a bit of margin on the timing report receipt time, to allow
+          // for timing errors.
+          3 * std::chrono::milliseconds(FLAGS_timing_report_ms) >
+      event_loop_->monotonic_now());
   status_builder.add_last_stop_reason(stop_reason_);
   if (pid_ != -1) {
     status_builder.add_pid(pid_);
@@ -572,9 +591,17 @@
             << "Application '" << name_ << "' pid " << pid_
             << " exited with status " << exit_code_.value();
       } else {
-        LOG_IF(WARNING, quiet_flag_ == QuietLogging::kNo)
-            << "Application '" << name_ << "' pid " << pid_
-            << " exited unexpectedly with status " << exit_code_.value();
+        if (quiet_flag_ == QuietLogging::kNo) {
+          std::string version_string =
+              latest_timing_report_version_.has_value()
+                  ? absl::StrCat("'", latest_timing_report_version_.value(),
+                                 "'")
+                  : "unknown";
+          LOG_IF(WARNING, quiet_flag_ == QuietLogging::kNo)
+              << "Application '" << name_ << "' pid " << pid_ << " version "
+              << version_string << " exited unexpectedly with status "
+              << exit_code_.value();
+        }
       }
       if (autorestart()) {
         QueueStart();