[Autofill Assistant] Add stopwatch tool for runtime measurements.

Bug: b/170722915
Change-Id: Ia887555904f1eba8c039ca6460c88d42b2b9352b
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2480522Reviewed-by: Sandro Maggi <sandromaggi@google.com>
Commit-Queue: Michele Mancina <micantox@google.com>
Cr-Commit-Position: refs/heads/master@{#818846}

components/autofill_assistant/browser/BUILD.gn

@@ -74,6 +74,8 @@ static_library("browser") {
     "actions/show_progress_bar_action.h",
     "actions/stop_action.cc",
     "actions/stop_action.h",
+    "actions/stopwatch.cc",
+    "actions/stopwatch.h",
     "actions/tell_action.cc",
     "actions/tell_action.h",
     "actions/unsupported_action.cc",
@@ -289,6 +291,7 @@ source_set("unit_tests") {
     "actions/show_details_action_unittest.cc",
     "actions/show_generic_ui_action_unittest.cc",
     "actions/show_progress_bar_action_unittest.cc",
+    "actions/stopwatch_unittest.cc",
     "actions/tell_action_unittest.cc",
     "actions/upload_dom_action_unittest.cc",
     "actions/use_address_action_unittest.cc",

components/autofill_assistant/browser/actions/stopwatch.cc

+// Copyright 2020 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+#include "components/autofill_assistant/browser/actions/stopwatch.h"
+
+#include <ostream>
+#include <string>
+
+#include "base/logging.h"
+
+namespace autofill_assistant {
+
+Stopwatch::Stopwatch() {
+  elapsed_time_.FromMilliseconds(0);
+}
+
+bool Stopwatch::Start() {
+  if (!running_) {
+    running_ = true;
+    start_time_ = base::TimeTicks::Now();
+    return true;
+  }
+  return false;
+}
+
+bool Stopwatch::StartAt(base::TimeTicks start_time) {
+  if (!running_) {
+    running_ = true;
+    start_time_ = start_time;
+    return true;
+  }
+  return false;
+}
+
+bool Stopwatch::Stop() {
+  if (!running_) {
+    return false;
+  }
+  elapsed_time_ += LastElapsedAt(base::TimeTicks::Now());
+  running_ = false;
+  return true;
+}
+
+bool Stopwatch::StopAt(base::TimeTicks stop_time) {
+  if (!running_) {
+    return false;
+  }
+  elapsed_time_ += LastElapsedAt(stop_time);
+  running_ = false;
+  return true;
+}
+
+void Stopwatch::AddTime(base::TimeDelta time) {
+  elapsed_time_ += time;
+}
+
+void Stopwatch::RemoveTime(base::TimeDelta time) {
+  if (elapsed_time_ > time) {
+    elapsed_time_ -= time;
+  } else {
+    elapsed_time_ = base::TimeDelta::FromMilliseconds(0);
+    if (running_) {
+      start_time_ += (time - elapsed_time_);
+    }
+  }
+}
+
+base::TimeDelta Stopwatch::TotalElapsed() const {
+  return elapsed_time_ + LastElapsedAt(base::TimeTicks::Now());
+}
+
+base::TimeDelta Stopwatch::LastElapsedAt(base::TimeTicks time) const {
+  if (!running_) {
+    return base::TimeDelta::FromMilliseconds(0);
+  }
+  return time > start_time_ ? time - start_time_
+                            : base::TimeDelta::FromMilliseconds(0);
+}
+
+bool Stopwatch::IsRunning() const {
+  return running_;
+}
+
+std::ostream& operator<<(std::ostream& out, const Stopwatch& stopwatch) {
+  out << (stopwatch.elapsed_time_ + stopwatch.LastElapsedAt(base::TimeTicks()))
+             .InMilliseconds()
+      << " (currently " << (stopwatch.running_ ? "" : "not ") << "running)";
+  return out;
+}
+
+void ActionStopwatch::TransferToActiveTime(base::TimeDelta time) {
+  active_time_stopwatch_.AddTime(time);
+  wait_time_stopwatch_.RemoveTime(time);
+}
+
+void ActionStopwatch::TransferToWaitTime(base::TimeDelta time) {
+  wait_time_stopwatch_.AddTime(time);
+  active_time_stopwatch_.RemoveTime(time);
+}
+
+void ActionStopwatch::StartActiveTime() {
+  wait_time_stopwatch_.Stop();
+  active_time_stopwatch_.Start();
+}
+void ActionStopwatch::StartActiveTimeAt(base::TimeTicks start_time) {
+  wait_time_stopwatch_.StopAt(start_time);
+  active_time_stopwatch_.StartAt(start_time);
+}
+void ActionStopwatch::StartWaitTime() {
+  active_time_stopwatch_.Stop();
+  wait_time_stopwatch_.Start();
+}
+
+void ActionStopwatch::StartWaitTimeAt(base::TimeTicks start_time) {
+  active_time_stopwatch_.StopAt(start_time);
+  wait_time_stopwatch_.StartAt(start_time);
+}
+
+void ActionStopwatch::Stop() {
+  active_time_stopwatch_.Stop();
+  wait_time_stopwatch_.Stop();
+}
+
+base::TimeDelta ActionStopwatch::TotalActiveTime() {
+  return active_time_stopwatch_.TotalElapsed();
+}
+
+base::TimeDelta ActionStopwatch::TotalWaitTime() {
+  return wait_time_stopwatch_.TotalElapsed();
+}
+
+std::ostream& operator<<(std::ostream& out,
+                         const ActionStopwatch& action_stopwatch) {
+  out << "Active time: " << action_stopwatch.active_time_stopwatch_
+      << " Wait time: " << action_stopwatch.wait_time_stopwatch_;
+  return out;
+}
+
+}  // namespace autofill_assistant

components/autofill_assistant/browser/actions/stopwatch.h

+// Copyright 2020 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#ifndef COMPONENTS_AUTOFILL_ASSISTANT_BROWSER_ACTIONS_STOPWATCH_H_
+#define COMPONENTS_AUTOFILL_ASSISTANT_BROWSER_ACTIONS_STOPWATCH_H_
+
+#include <ostream>
+#include <string>
+
+#include "base/time/time.h"
+
+namespace autofill_assistant {
+
+// A simple stopwatch to measure cumulative times.
+class Stopwatch {
+ public:
+  Stopwatch();
+  // Start measuring the time when the method is called.
+  bool Start();
+  // Starts measuring the time from `start_time`.
+  bool StartAt(base::TimeTicks start_time);
+  // Stops the stopwatch and, if it was running, adds to the elapsed time.
+  bool Stop();
+  // Same as above, but at `stop_time` rather than the current time.
+  bool StopAt(base::TimeTicks stop_time);
+  // Adds `time` to the cumulative elapsed time held by this stopwatch.
+  void AddTime(base::TimeDelta time);
+  // Remove `time` from the cumulative elapsed time held by this stopwatch.
+  void RemoveTime(base::TimeDelta time);
+  base::TimeDelta TotalElapsed() const;
+  bool IsRunning() const;
+
+  friend std::ostream& operator<<(std::ostream& out, const Stopwatch& action);
+
+ private:
+  base::TimeDelta LastElapsedAt(base::TimeTicks time) const;
+
+  bool running_ = false;
+  base::TimeTicks start_time_;
+  base::TimeDelta elapsed_time_;
+};
+
+// This class holds two stopwatches: one for active and one for wait time (e.g.
+// wait on preconditions or user action) spent while executing the action.
+class ActionStopwatch {
+ public:
+  // Removes `time` from the total wait time and adds it to the active time.
+  void TransferToActiveTime(base::TimeDelta time);
+  // Removes `time` from the total active time and adds it to the wait time.
+  void TransferToWaitTime(base::TimeDelta time);
+  // Starts the active time stopwatch, stopping the wait time one if it was
+  // running.
+  void StartActiveTime();
+  // Starts the active time and stops the wait time stopwatch at `start_time`,
+  // which can be a time in the past or the future.
+  void StartActiveTimeAt(base::TimeTicks start_time);
+  // Starts the wait time stopwatch, stopping the active time one if it was
+  // running.
+  void StartWaitTime();
+  // Starts the wait time and stops the active time stopwatch at `start_time`,
+  // which can be a time in the past or the future.
+  void StartWaitTimeAt(base::TimeTicks start_time);
+  // Stops both stopwatches.
+  void Stop();
+
+  base::TimeDelta TotalActiveTime();
+  base::TimeDelta TotalWaitTime();
+  friend std::ostream& operator<<(std::ostream& out,
+                                  const ActionStopwatch& action);
+
+ private:
+  Stopwatch active_time_stopwatch_;
+  Stopwatch wait_time_stopwatch_;
+};
+
+}  // namespace autofill_assistant
+#endif  // COMPONENTS_AUTOFILL_ASSISTANT_BROWSER_ACTIONS_ACTION_TIMER_H_

components/autofill_assistant/browser/actions/stopwatch_unittest.cc

+// Copyright 2020 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#include "components/autofill_assistant/browser/actions/stopwatch.h"
+
+#include "base/logging.h"
+#include "base/time/time_override.h"
+#include "testing/gmock/include/gmock/gmock.h"
+
+namespace autofill_assistant {
+namespace {
+
+class TimeTicksOverride {
+ public:
+  static base::TimeTicks Now() { return now_ticks_; }
+
+  static base::TimeTicks now_ticks_;
+};
+
+// static
+base::TimeTicks TimeTicksOverride::now_ticks_ = base::TimeTicks::Now();
+
+class StopwatchTest : public testing::Test {
+ protected:
+  Stopwatch stopwatch_;
+};
+
+TEST_F(StopwatchTest, StopwatchSimpleRun) {
+  base::subtle::ScopedTimeClockOverrides overrides(
+      nullptr, &TimeTicksOverride::Now, nullptr);
+  EXPECT_TRUE(stopwatch_.Start());
+  EXPECT_FALSE(stopwatch_.Start());
+  EXPECT_TRUE(stopwatch_.IsRunning());
+
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(1);
+  EXPECT_EQ(base::TimeDelta::FromSeconds(1), stopwatch_.TotalElapsed());
+
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(2);
+  EXPECT_TRUE(stopwatch_.Stop());
+  EXPECT_FALSE(stopwatch_.Stop());
+  EXPECT_EQ(base::TimeDelta::FromSeconds(3), stopwatch_.TotalElapsed());
+
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(2);
+  EXPECT_TRUE(stopwatch_.Start());
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(1);
+  EXPECT_EQ(base::TimeDelta::FromSeconds(4), stopwatch_.TotalElapsed());
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(1);
+  EXPECT_TRUE(stopwatch_.Stop());
+  EXPECT_EQ(base::TimeDelta::FromSeconds(5), stopwatch_.TotalElapsed());
+}
+
+TEST_F(StopwatchTest, StopwatchAddTime) {
+  base::subtle::ScopedTimeClockOverrides overrides(
+      nullptr, &TimeTicksOverride::Now, nullptr);
+  stopwatch_.Start();
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(1);
+  stopwatch_.Stop();
+  stopwatch_.AddTime(base::TimeDelta::FromSeconds(2));
+  EXPECT_EQ(base::TimeDelta::FromSeconds(3), stopwatch_.TotalElapsed());
+}
+
+TEST_F(StopwatchTest, StopwatchRemoveTime) {
+  base::subtle::ScopedTimeClockOverrides overrides(
+      nullptr, &TimeTicksOverride::Now, nullptr);
+  stopwatch_.Start();
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(2);
+  stopwatch_.Stop();
+  stopwatch_.RemoveTime(base::TimeDelta::FromSeconds(1));
+  EXPECT_EQ(base::TimeDelta::FromSeconds(1), stopwatch_.TotalElapsed());
+}
+
+TEST_F(StopwatchTest, StopwatchRemoveGreaterThanElapsed) {
+  base::subtle::ScopedTimeClockOverrides overrides(
+      nullptr, &TimeTicksOverride::Now, nullptr);
+  stopwatch_.Start();
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(1);
+  stopwatch_.Stop();
+  stopwatch_.RemoveTime(base::TimeDelta::FromSeconds(2));
+  EXPECT_EQ(base::TimeDelta::FromSeconds(0), stopwatch_.TotalElapsed());
+}
+
+class StopwatchStartStopTest
+    : public StopwatchTest,
+      public testing::WithParamInterface<std::tuple<long, long, long, long>> {};
+
+INSTANTIATE_TEST_SUITE_P(ParametrizedTests,
+                         StopwatchStartStopTest,
+                         testing::Values(std::make_tuple(-1, 1, 1, 2),
+                                         std::make_tuple(1, 2, 0, 1),
+                                         std::make_tuple(2, 1, 0, 0),
+                                         std::make_tuple(-1, 0, 1, 1),
+                                         std::make_tuple(1, 0, 0, 0),
+                                         std::make_tuple(0, 1, 0, 1)));
+
+TEST_P(StopwatchStartStopTest, StartAndStopAt) {
+  base::subtle::ScopedTimeClockOverrides overrides(
+      nullptr, &TimeTicksOverride::Now, nullptr);
+  long start_at = std::get<0>(GetParam());
+  long stop_at = std::get<1>(GetParam());
+  long expected_while_running = std::get<2>(GetParam());
+  long expected = std::get<3>(GetParam());
+  if (start_at) {
+    stopwatch_.StartAt(TimeTicksOverride::now_ticks_ +
+                       base::TimeDelta::FromSeconds(start_at));
+  } else {
+    stopwatch_.Start();
+  }
+  EXPECT_EQ(base::TimeDelta::FromSeconds(expected_while_running),
+            stopwatch_.TotalElapsed());
+  if (stop_at) {
+    stopwatch_.StopAt(TimeTicksOverride::now_ticks_ +
+                      base::TimeDelta::FromSeconds(stop_at));
+  } else {
+    stopwatch_.Stop();
+  }
+  EXPECT_EQ(base::TimeDelta::FromSeconds(expected), stopwatch_.TotalElapsed());
+}
+
+class ActionStopwatchTest : public testing::Test {
+ protected:
+  ActionStopwatch action_stopwatch_;
+};
+
+TEST_F(ActionStopwatchTest, SimpleRun) {
+  base::subtle::ScopedTimeClockOverrides overrides(
+      nullptr, &TimeTicksOverride::Now, nullptr);
+  action_stopwatch_.StartActiveTime();
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(1);
+  action_stopwatch_.StartWaitTime();
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(2);
+  action_stopwatch_.Stop();
+  EXPECT_EQ(base::TimeDelta::FromSeconds(1),
+            action_stopwatch_.TotalActiveTime());
+  EXPECT_EQ(base::TimeDelta::FromSeconds(2), action_stopwatch_.TotalWaitTime());
+}
+
+TEST_F(ActionStopwatchTest, TransferToActive) {
+  base::subtle::ScopedTimeClockOverrides overrides(
+      nullptr, &TimeTicksOverride::Now, nullptr);
+  action_stopwatch_.StartActiveTime();
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(4);
+  action_stopwatch_.StartWaitTime();
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(2);
+  action_stopwatch_.Stop();
+  action_stopwatch_.TransferToActiveTime(base::TimeDelta::FromSeconds(3));
+  EXPECT_EQ(base::TimeDelta::FromSeconds(7),
+            action_stopwatch_.TotalActiveTime());
+  EXPECT_EQ(base::TimeDelta::FromSeconds(0), action_stopwatch_.TotalWaitTime());
+}
+
+TEST_F(ActionStopwatchTest, TransferToWait) {
+  base::subtle::ScopedTimeClockOverrides overrides(
+      nullptr, &TimeTicksOverride::Now, nullptr);
+  action_stopwatch_.StartActiveTime();
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(2);
+  action_stopwatch_.StartWaitTime();
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(4);
+  action_stopwatch_.Stop();
+  action_stopwatch_.TransferToWaitTime(base::TimeDelta::FromSeconds(3));
+  EXPECT_EQ(base::TimeDelta::FromSeconds(0),
+            action_stopwatch_.TotalActiveTime());
+  EXPECT_EQ(base::TimeDelta::FromSeconds(7), action_stopwatch_.TotalWaitTime());
+}
+
+TEST_F(ActionStopwatchTest, StartTimesAt) {
+  base::subtle::ScopedTimeClockOverrides overrides(
+      nullptr, &TimeTicksOverride::Now, nullptr);
+  action_stopwatch_.StartActiveTimeAt(TimeTicksOverride::now_ticks_ +
+                                      base::TimeDelta::FromSeconds(1));
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(5);
+  action_stopwatch_.StartWaitTimeAt(TimeTicksOverride::now_ticks_ -
+                                    base::TimeDelta::FromSeconds(1));
+  TimeTicksOverride::now_ticks_ += base::TimeDelta::FromSeconds(2);
+  action_stopwatch_.Stop();
+  EXPECT_EQ(base::TimeDelta::FromSeconds(3),
+            action_stopwatch_.TotalActiveTime());
+  EXPECT_EQ(base::TimeDelta::FromSeconds(3), action_stopwatch_.TotalWaitTime());
+}
+
+}  // namespace
+}  // namespace autofill_assistant