liteclient: Truncate log of update complete event

Truncate a description of the update complete event if the completion is
not successful and it exceeds the maximum allowed size (2048).
The truncation is done by erasing the description middle part, so a user
can see the beginning of the app starting log and the end of it which is
supposed to contain a reason of failure.

Signed-off-by: Mike Sul <[email protected]>

src/liteclient.cc

@@ -20,6 +20,8 @@
 #include "uptane/exceptions.h"
 #include "uptane/fetcher.h"
 
+static const size_t MaxDetailsSize{2048};
+
 class OfflineMetaFetcher : public Uptane::IMetadataFetcher {
  public:
   explicit OfflineMetaFetcher(boost::filesystem::path tuf_repo_path, Uptane::Version max_root_ver = Uptane::Version())
@@ -304,10 +306,9 @@ void LiteClient::notify(const Uptane::Target& t, std::unique_ptr<ReportEvent> ev
     event->custom["targetName"] = t.filename();
     event->custom["version"] = t.custom_version();
     if (event->custom.isMember("details")) {
-      static const size_t max_details_size{2048};
       const auto detail_str{event->custom["details"].asString()};
-      if (detail_str.size() > max_details_size) {
-        event->custom["details"] = detail_str.substr(0, max_details_size);
+      if (detail_str.size() > MaxDetailsSize) {
+        event->custom["details"] = detail_str.substr(0, MaxDetailsSize);
       }
     }
     report_queue->enqueue(std::move(event));
@@ -468,7 +469,17 @@ class DetailedInstallCompletedReport : public EcuInstallationCompletedReport {
   DetailedInstallCompletedReport(const Uptane::EcuSerial& ecu, const std::string& correlation_id, bool success,
                                  const std::string& details)
       : EcuInstallationCompletedReport(ecu, correlation_id, success) {
-    custom["details"] = details;
+    if (!success && details.size() > MaxDetailsSize) {
+      static const std::size_t err_tail_size{1024};
+      static const std::string truncated{"\n[TRUNCATED]\n"};
+
+      std::size_t head_size{MaxDetailsSize - err_tail_size - truncated.size()};
+
+      custom["details"] =
+          details.substr(0, head_size) + truncated + details.substr(details.size() - err_tail_size, err_tail_size);
+    } else {
+      custom["details"] = details;
+    }
   }
 };
 

tests/aklite_rollback_test.cc

@@ -368,7 +368,7 @@ TEST_P(AkliteTest, OstreeAndAppRollbackIfAppsStartFails) {
   // specifically its creation is successful but it fails to start after reboot caused by the ostree update
   auto app01_updated = registry.addApp(
       fixtures::ComposeApp::create("app-01", "service-01", "image-02", fixtures::ComposeApp::ServiceTemplate,
-                                   Docker::ComposeAppEngine::ComposeFile, "compose-start-failure"));
+                                   Docker::ComposeAppEngine::ComposeFile, "compose-start-failure-long-log"));
   std::vector<AppEngine::App> apps_updated{app01_updated};
   auto target_02 = createTarget(&apps_updated);
 
@@ -396,7 +396,8 @@ TEST_P(AkliteTest, OstreeAndAppRollbackIfAppsStartFails) {
 
     ASSERT_FALSE(client->finalizeInstall());
     // make sure that report events have been sent and EcuInstallationCompleted contains the error message
-    checkEvents(*client, target_01, UpdateType::kFinalized, "", "failed to bring Compose App up");
+    checkEvents(*client, target_01, UpdateType::kFinalized, "", "Failed to start container: " + app01_updated.name,
+                true);
 
     // for some reason ostreemanager::getCurrent() is driven by currently booted ostree hash,
     // so it thinks that current version is target_02

tests/docker-compose_fake.py

@@ -44,6 +44,12 @@ def up(out_dir, app_name, compose, flags):
         logger.info("Failed to start container: {}".format(app_name))
         exit(1)
 
+    if compose["x-fault-injection"]["failure-type"] == "compose-start-failure-long-log" and "-d" in flags:
+        for ii in range (0, 2000):
+            logger.info("Starting container...ok")
+        logger.info("Failed to start container: {}".format(app_name))
+        exit(1)
+
     try:
         with open(os.path.join(out_dir, "images.json"), "r") as f:
             images = json.load(f)

tests/fixtures/liteclienttest.cc

@@ -487,7 +487,8 @@ class ClientTest :virtual public ::testing::Test {
     ASSERT_EQ(req_headers.get("x-ats-dockerapps", ""), Target::appsStr(target, app_shortlist_));
   }
 
-  void checkEvents(fixtures::LiteClientMock& client, const Uptane::Target& target, UpdateType update_type, const std::string& download_failure_err_msg = "", const std::string& install_failure_err_msg = "") {
+  void checkEvents(fixtures::LiteClientMock& client, const Uptane::Target& target, UpdateType update_type, const std::string& download_failure_err_msg = "", const std::string& install_failure_err_msg = "",
+                   bool truncated = false) {
     const std::unordered_map<UpdateType, std::vector<std::string>> updateToevents = {
         { UpdateType::kOstree, { "EcuDownloadStarted", "EcuDownloadCompleted", "EcuInstallationStarted", "EcuInstallationApplied", "EcuInstallationCompleted" }},
         { UpdateType::kApp, { "EcuDownloadStarted", "EcuDownloadCompleted", "EcuInstallationStarted", "EcuInstallationCompleted" }},
@@ -521,6 +522,9 @@ class ClientTest :virtual public ::testing::Test {
       if (event_type == "EcuDownloadCompleted") {
         const auto event_details = rec_event_json["event"]["details"].asString();
         ASSERT_TRUE(event_details.find(download_failure_err_msg) != std::string::npos) << event_details;
+        if (truncated) {
+          ASSERT_TRUE(event_details.find("[TRUNCATED]") != std::string::npos) << event_details;
+        }
       }
     }
   }