Wire up Diagnostics Routine Log

This change wires up the RoutineLog to SystemRoutineController so that
the log is added to anytime a routine starts or finishes.

Bug: 1128204
Change-Id: I2ff1e23fccb4a3f6891ffa8a7a8c118278618c02
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2632872
Commit-Queue: Bailey Berro <baileyberro@chromium.org>
Reviewed-by: Zentaro Kavanagh <zentaro@chromium.org>
Cr-Commit-Position: refs/heads/master@{#845362}

chromeos/components/diagnostics_ui/backend/diagnostics_manager.cc

@@ -14,7 +14,8 @@ namespace diagnostics {
 DiagnosticsManager::DiagnosticsManager(SessionLogHandler* session_log_handler)
     : system_data_provider_(std::make_unique<SystemDataProvider>(
           session_log_handler->GetTelemetryLog())),
-      system_routine_controller_(std::make_unique<SystemRoutineController>()) {}
+      system_routine_controller_(std::make_unique<SystemRoutineController>(
+          session_log_handler->GetRoutineLog())) {}
 
 DiagnosticsManager::~DiagnosticsManager() = default;
 

chromeos/components/diagnostics_ui/backend/system_routine_controller.cc

@@ -16,6 +16,7 @@
 #include "base/values.h"
 #include "chromeos/components/diagnostics_ui/backend/cros_healthd_helpers.h"
 #include "chromeos/components/diagnostics_ui/backend/histogram_util.h"
+#include "chromeos/components/diagnostics_ui/backend/routine_log.h"
 #include "chromeos/services/cros_healthd/public/cpp/service_connection.h"
 
 namespace chromeos {
@@ -195,7 +196,11 @@ mojom::RoutineType DiagnosticRoutineEnumToRoutineType(
 
 }  // namespace
 
-SystemRoutineController::SystemRoutineController() {
+SystemRoutineController::SystemRoutineController()
+    : SystemRoutineController(/*routine_log_ptr=*/nullptr) {}
+
+SystemRoutineController::SystemRoutineController(RoutineLog* routine_log_ptr)
+    : routine_log_ptr_(routine_log_ptr) {
   inflight_routine_timer_ = std::make_unique<base::OneShotTimer>();
 }
 
@@ -273,43 +278,46 @@ void SystemRoutineController::ExecuteRoutine(mojom::RoutineType routine_type) {
           base::BindOnce(&SystemRoutineController::OnPowerRoutineStarted,
                          base::Unretained(this), routine_type));
 
-      return;
+      break;
     case mojom::RoutineType::kBatteryDischarge:
       diagnostics_service_->RunBatteryDischargeRoutine(
           kBatteryDurationInSeconds, kBatteryDischargeMaximumPercent,
           base::BindOnce(&SystemRoutineController::OnPowerRoutineStarted,
                          base::Unretained(this), routine_type));
 
-      return;
+      break;
     case mojom::RoutineType::kCpuCache:
       diagnostics_service_->RunCpuCacheRoutine(
           healthd::NullableUint32::New(kCpuCacheDurationInSeconds),
           base::BindOnce(&SystemRoutineController::OnRoutineStarted,
                          base::Unretained(this), routine_type));
-      return;
+      break;
     case mojom::RoutineType::kCpuFloatingPoint:
       diagnostics_service_->RunFloatingPointAccuracyRoutine(
           healthd::NullableUint32::New(kCpuFloatingPointDurationInSeconds),
           base::BindOnce(&SystemRoutineController::OnRoutineStarted,
                          base::Unretained(this), routine_type));
-      return;
+      break;
     case mojom::RoutineType::kCpuPrime:
       diagnostics_service_->RunPrimeSearchRoutine(
           healthd::NullableUint32::New(kCpuPrimeDurationInSeconds),
           base::BindOnce(&SystemRoutineController::OnRoutineStarted,
                          base::Unretained(this), routine_type));
-      return;
+      break;
     case mojom::RoutineType::kCpuStress:
       diagnostics_service_->RunCpuStressRoutine(
           healthd::NullableUint32::New(kCpuStressDurationInSeconds),
           base::BindOnce(&SystemRoutineController::OnRoutineStarted,
                          base::Unretained(this), routine_type));
-      return;
+      break;
     case mojom::RoutineType::kMemory:
       diagnostics_service_->RunMemoryRoutine(
           base::BindOnce(&SystemRoutineController::OnRoutineStarted,
                          base::Unretained(this), routine_type));
-      return;
+      break;
+  }
+  if (IsLoggingEnabled()) {
+    routine_log_ptr_->LogRoutineStarted(routine_type);
   }
 }
 
@@ -609,6 +617,9 @@ void SystemRoutineController::OnStandardRoutineResult(
   auto result_info =
       ConstructStandardRoutineResultInfoPtr(routine_type, result);
   SendRoutineResult(std::move(result_info));
+  if (IsLoggingEnabled()) {
+    routine_log_ptr_->LogRoutineCompleted(routine_type, result);
+  }
 }
 
 void SystemRoutineController::OnPowerRoutineResult(
@@ -620,6 +631,9 @@ void SystemRoutineController::OnPowerRoutineResult(
   auto result_info = ConstructPowerRoutineResultInfoPtr(
       routine_type, result, percent_change, seconds_elapsed);
   SendRoutineResult(std::move(result_info));
+  if (IsLoggingEnabled()) {
+    routine_log_ptr_->LogRoutineCompleted(routine_type, result);
+  }
 }
 
 void SystemRoutineController::SendRoutineResult(
@@ -669,5 +683,9 @@ void SystemRoutineController::OnRoutineCancelAttempted(
   }
 }
 
+bool SystemRoutineController::IsLoggingEnabled() const {
+  return routine_log_ptr_ != nullptr;
+}
+
 }  // namespace diagnostics
 }  // namespace chromeos

chromeos/components/diagnostics_ui/backend/system_routine_controller.h

@@ -29,6 +29,8 @@ class RoutineUpdatePtr;
 namespace chromeos {
 namespace diagnostics {
 
+class RoutineLog;
+
 constexpr int32_t kInvalidRoutineId = 0;
 
 using RunRoutineCallback =
@@ -37,6 +39,7 @@ using RunRoutineCallback =
 class SystemRoutineController : public mojom::SystemRoutineController {
  public:
   SystemRoutineController();
+  SystemRoutineController(RoutineLog* routine_log_ptr);
   ~SystemRoutineController() override;
 
   SystemRoutineController(const SystemRoutineController&) = delete;
@@ -115,6 +118,10 @@ class SystemRoutineController : public mojom::SystemRoutineController {
   void OnRoutineCancelAttempted(
       cros_healthd::mojom::RoutineUpdatePtr update_ptr);
 
+  bool IsLoggingEnabled() const;
+
+  RoutineLog* routine_log_ptr_ = nullptr;  // Not Owned.
+
   // Keeps track of the id created by CrosHealthd for the currently running
   // routine.
   int32_t inflight_routine_id_ = kInvalidRoutineId;

chromeos/components/diagnostics_ui/backend/system_routine_controller_unittest.cc

@@ -5,14 +5,17 @@
 #include "chromeos/components/diagnostics_ui/backend/system_routine_controller.h"
 
 #include "base/containers/contains.h"
+#include "base/files/file_path.h"
 #include "base/files/file_util.h"
 #include "base/files/scoped_file.h"
 #include "base/files/scoped_temp_dir.h"
 #include "base/json/json_writer.h"
 #include "base/run_loop.h"
+#include "base/strings/string_split.h"
 #include "base/test/bind.h"
 #include "base/test/metrics/histogram_tester.h"
 #include "base/test/task_environment.h"
+#include "chromeos/components/diagnostics_ui/backend/routine_log.h"
 #include "chromeos/dbus/cros_healthd/fake_cros_healthd_client.h"
 #include "chromeos/dbus/cros_healthd/fake_cros_healthd_service.h"
 #include "chromeos/services/cros_healthd/public/mojom/cros_healthd.mojom.h"
@@ -126,6 +129,19 @@ void SetAvailableRoutines(
       routines);
 }
 
+std::vector<std::string> GetLogLines(const std::string& log) {
+  return base::SplitString(log, "\n", base::WhitespaceHandling::TRIM_WHITESPACE,
+                           base::SplitResult::SPLIT_WANT_NONEMPTY);
+}
+
+std::vector<std::string> GetLogLineContents(const std::string& log_line) {
+  const std::vector<std::string> result = base::SplitString(
+      log_line, " - ", base::WhitespaceHandling::TRIM_WHITESPACE,
+      base::SplitResult::SPLIT_WANT_NONEMPTY);
+  DCHECK_EQ(3u, result.size());
+  return result;
+}
+
 }  // namespace
 
 struct FakeRoutineRunner : public mojom::RoutineRunner {
@@ -628,5 +644,57 @@ TEST_F(SystemRoutineControllerTest, RunRoutineCount1) {
                                      1);
 }
 
+TEST_F(SystemRoutineControllerTest, RoutineLog) {
+  base::ScopedTempDir temp_dir;
+  base::FilePath log_path;
+
+  EXPECT_TRUE(temp_dir.CreateUniqueTempDir());
+  log_path = temp_dir.GetPath().AppendASCII("routine_log");
+
+  RoutineLog log(log_path);
+  system_routine_controller_ = std::make_unique<SystemRoutineController>(&log);
+
+  SetRunRoutineResponse(/*id=*/1,
+                        healthd::DiagnosticRoutineStatusEnum::kRunning);
+
+  FakeRoutineRunner routine_runner;
+  system_routine_controller_->RunRoutine(
+      mojom::RoutineType::kCpuStress,
+      routine_runner.receiver.BindNewPipeAndPassRemote());
+  base::RunLoop().RunUntilIdle();
+
+  // Assert that the first routine is not complete.
+  EXPECT_TRUE(routine_runner.result.is_null());
+
+  // Verify that the Running status appears in the log.
+  std::vector<std::string> log_lines = GetLogLines(log.GetContents());
+  EXPECT_EQ(1u, log_lines.size());
+
+  std::vector<std::string> log_line_contents = GetLogLineContents(log_lines[0]);
+  ASSERT_EQ(3u, log_line_contents.size());
+  EXPECT_EQ("RoutineType::kCpuStress", log_line_contents[1]);
+  EXPECT_EQ("Started", log_line_contents[2]);
+
+  // Update the status on cros_healthd.
+  SetNonInteractiveRoutineUpdateResponse(
+      /*percent_complete=*/100, healthd::DiagnosticRoutineStatusEnum::kPassed,
+      mojo::ScopedHandle());
+
+  // After the update interval, the update is fetched and processed.
+  task_environment_.FastForwardBy(base::TimeDelta::FromSeconds(60));
+  EXPECT_FALSE(routine_runner.result.is_null());
+  VerifyRoutineResult(*routine_runner.result, mojom::RoutineType::kCpuStress,
+                      mojom::StandardRoutineResult::kTestPassed);
+
+  // Verify that the Passed status appears in the log.
+  log_lines = GetLogLines(log.GetContents());
+  EXPECT_EQ(2u, log_lines.size());
+
+  log_line_contents = GetLogLineContents(log_lines[1]);
+  ASSERT_EQ(3u, log_line_contents.size());
+  EXPECT_EQ("RoutineType::kCpuStress", log_line_contents[1]);
+  EXPECT_EQ("StandardRoutineResult::kTestPassed", log_line_contents[2]);
+}
+
 }  // namespace diagnostics
 }  // namespace chromeos