Added tracking of the maximum translation time over the course of a page

load.

This CL adds tracking of the time between calls to LogTranslationStarted
and LogTranslationFinished of the TranslateMetricsLoggerImpl class. The
maximum such time is stored for each page load, and will later be logged
via UKM. Note that this time corresponds to the what the user
experiences between requesting a translation and the page being updated
with the translation.

Full design doc: https://docs.google.com/document/d/1dyWh1Xw5VgUA00VA-5PTgKQ6ItziPBnSyeDR8saJ9vM/edit?usp=sharing

Bug: 1114868
Change-Id: I142300e2f472c1de713e9035b5669f1e3d2c2c9f
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2572121
Commit-Queue: Max Curran <curranmax@chromium.org>
Reviewed-by: Scott Little <sclittle@chromium.org>
Cr-Commit-Position: refs/heads/master@{#835339}

components/translate/core/browser/translate_metrics_logger_impl.cc

@@ -164,6 +164,8 @@ void TranslateMetricsLoggerImpl::LogTranslationStarted() {
 
   current_state_is_translated_ = true;
   is_translation_in_progress_ = true;
+
+  time_of_last_translation_start_ = clock_->NowTicks();
 }
 
 void TranslateMetricsLoggerImpl::LogTranslationFinished(
@@ -172,6 +174,13 @@ void TranslateMetricsLoggerImpl::LogTranslationFinished(
   if (error_type == TranslateErrors::NONE) {
     UpdateTimeTranslated(previous_state_is_translated_, is_foreground_);
     num_translations_++;
+
+    // Calculate the time it took to complete this translation, and check if is
+    // the the longest translation for this page load.
+    base::TimeDelta time_of_translation =
+        clock_->NowTicks() - time_of_last_translation_start_;
+    if (time_of_translation > max_time_to_translate_)
+      max_time_to_translate_ = time_of_translation;
   } else {
     // If the translation fails, then undo the change to the current state.
     current_state_is_translated_ = previous_state_is_translated_;

components/translate/core/browser/translate_metrics_logger_impl.h

@@ -158,6 +158,14 @@ class TranslateMetricsLoggerImpl : public TranslateMetricsLogger {
   int num_translations_ = 0;
   int num_reversions_ = 0;
 
+  // Used to track the time it takes to translate. Specifically this will be the
+  // time between when LogTranslationStarted is called and
+  // LogTranslationFinished is called. It will therefore include all aspects of
+  // translation include: loading the translate script, loading dependent
+  // libraries, and running the translate script.
+  base::TimeTicks time_of_last_translation_start_;
+  base::TimeDelta max_time_to_translate_;
+
   // Tracks the amount of time the page is in the foreground and either
   // translated or not translated.
   const base::TickClock* clock_;

components/translate/core/browser/translate_metrics_logger_impl_unittest.cc

@@ -62,6 +62,11 @@ class TranslateMetricsLoggerImplTest : public ::testing::Test {
               total_time_not_translated);
   }
 
+  void CheckMaxTimeToTranslate(base::TimeDelta expected_max_time_to_translate) {
+    EXPECT_EQ(translate_metrics_logger_->max_time_to_translate_,
+              expected_max_time_to_translate);
+  }
+
  private:
   // Test target.
   std::unique_ptr<TranslateMetricsLoggerImpl> translate_metrics_logger_;
@@ -467,6 +472,74 @@ TEST_F(TranslateMetricsLoggerImplTest, LogTargetLanguage) {
       1);
 }
 
+TEST_F(TranslateMetricsLoggerImplTest, LogMaxTimeToTranslate) {
+  // Set constants for this test.
+  base::SimpleTestTickClock test_clock;
+
+  constexpr base::TimeDelta default_delay = base::TimeDelta::FromSeconds(100);
+  constexpr base::TimeDelta zero_delay = base::TimeDelta::FromSeconds(0);
+
+  // Simulate sucessfully translating a page.
+  translate_metrics_logger()->SetInternalClockForTesting(&test_clock);
+
+  translate_metrics_logger()->LogTranslationStarted();
+  test_clock.Advance(default_delay);
+  translate_metrics_logger()->LogTranslationFinished(TranslateErrors::NONE);
+
+  translate_metrics_logger()->RecordMetrics(true);
+
+  CheckMaxTimeToTranslate(default_delay);
+
+  // Simulate an error with the translation. In this case the value of the
+  // maximum time to translate should stay zero.
+  ResetTest();
+  translate_metrics_logger()->SetInternalClockForTesting(&test_clock);
+
+  translate_metrics_logger()->LogTranslationStarted();
+  test_clock.Advance(default_delay);
+  translate_metrics_logger()->LogTranslationFinished(TranslateErrors::NETWORK);
+
+  translate_metrics_logger()->RecordMetrics(true);
+
+  CheckMaxTimeToTranslate(zero_delay);
+
+  // Simulate a translation that doesn't finish. The maximum time to translate
+  // should also be zero here.
+  ResetTest();
+  translate_metrics_logger()->SetInternalClockForTesting(&test_clock);
+
+  translate_metrics_logger()->LogTranslationStarted();
+  test_clock.Advance(default_delay);
+
+  translate_metrics_logger()->RecordMetrics(true);
+
+  CheckMaxTimeToTranslate(zero_delay);
+
+  // Simulate multiple translations (some with errors). The maximum time to
+  // translate should only be from translations without an error.i
+  const struct {
+    base::TimeDelta time_to_translate;
+    TranslateErrors::Type translate_error_type;
+  } kTests[] = {
+      {base::TimeDelta::FromSeconds(100), TranslateErrors::NONE},
+      {base::TimeDelta::FromSeconds(200), TranslateErrors::NETWORK},
+      {base::TimeDelta::FromSeconds(400), TranslateErrors::NONE},
+      {base::TimeDelta::FromSeconds(500), TranslateErrors::NETWORK},
+      {base::TimeDelta::FromSeconds(300), TranslateErrors::NONE},
+  };
+
+  for (const auto& test : kTests) {
+    translate_metrics_logger()->LogTranslationStarted();
+    test_clock.Advance(test.time_to_translate);
+    translate_metrics_logger()->LogTranslationFinished(
+        test.translate_error_type);
+  }
+
+  translate_metrics_logger()->RecordMetrics(true);
+
+  CheckMaxTimeToTranslate(base::TimeDelta::FromSeconds(400));
+}
+
 }  // namespace testing
 
 }  // namespace translate