imf: Record latency of key event handling.

Measure the time it takes for the extension to handle a key event.

Bug: 1009903
Change-Id: I4099ab7071d0cbbb414e534b3790d36763553d14
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1832854Reviewed-by: Steven Holte <holte@chromium.org>
Reviewed-by: Keith Lee <keithlee@chromium.org>
Commit-Queue: Darren Shen <shend@chromium.org>
Cr-Commit-Position: refs/heads/master@{#702652}

chrome/browser/chromeos/input_method/input_method_engine_unittest.cc

@@ -357,5 +357,17 @@ TEST_F(InputMethodEngineTest, TestDisableAfterSetCompositionRange) {
   EXPECT_EQ("text", mock_ime_input_context_handler_->last_commit_text());
 }
 
+TEST_F(InputMethodEngineTest, KeyEventHandledRecordsLatencyHistogram) {
+  CreateEngine(true);
+  base::HistogramTester histogram_tester;
+
+  const std::string request_id = engine_->AddPendingKeyEvent(
+      kTestExtensionId, base::BindOnce([](bool consumed) {}));
+  histogram_tester.ExpectTotalCount("InputMethod.KeyEventLatency", 0);
+
+  engine_->KeyEventHandled(kTestExtensionId, request_id, /* handled */ true);
+  histogram_tester.ExpectTotalCount("InputMethod.KeyEventLatency", 1);
+}
+
 }  // namespace input_method
 }  // namespace chromeos

chrome/browser/ui/input_method/input_method_engine_base.cc

@@ -464,6 +464,8 @@ void InputMethodEngineBase::KeyEventHandled(const std::string& extension_id,
   }
 
   std::move(it->second.callback).Run(handled);
+  UMA_HISTOGRAM_TIMES("InputMethod.KeyEventLatency",
+                      base::Time::Now() - it->second.created_time);
   pending_key_events_.erase(it);
 }
 

chrome/browser/ui/input_method/input_method_engine_base.h

@@ -219,6 +219,7 @@ class InputMethodEngineBase : virtual public ui::IMEEngineHandlerInterface {
 
     std::string component_id;
     ui::IMEEngineHandlerInterface::KeyEventDoneCallback callback;
+    base::Time created_time = base::Time::Now();
 
    private:
     DISALLOW_COPY_AND_ASSIGN(PendingKeyEvent);

chrome/browser/ui/input_method/input_method_engine_unittest.cc

@@ -5,6 +5,7 @@
 #include "chrome/browser/ui/input_method/input_method_engine.h"
 #include "base/bind.h"
 #include "base/run_loop.h"
+#include "base/test/metrics/histogram_tester.h"
 #include "chrome/browser/profiles/profile_manager.h"
 #include "chrome/browser/ui/input_method/input_method_engine_base.h"
 #include "chrome/test/base/testing_profile.h"
@@ -299,4 +300,15 @@ TEST_F(InputMethodEngineTest, TestDisableAfterSetComposition) {
   EXPECT_EQ("hello", mock_ime_input_context_handler_->last_commit_text());
 }
 
+TEST_F(InputMethodEngineTest, KeyEventHandledRecordsLatencyHistogram) {
+  base::HistogramTester histogram_tester;
+
+  const std::string request_id = engine_->AddPendingKeyEvent(
+      kTestExtensionId, base::BindOnce([](bool consumed) {}));
+  histogram_tester.ExpectTotalCount("InputMethod.KeyEventLatency", 0);
+
+  engine_->KeyEventHandled(kTestExtensionId, request_id, /* handled */ true);
+  histogram_tester.ExpectTotalCount("InputMethod.KeyEventLatency", 1);
+}
+
 }  // namespace input_method

tools/metrics/histograms/histograms.xml

@@ -54411,6 +54411,12 @@ uploading your change for review.
   <summary>The trigger type of input method switches by user.</summary>
 </histogram>
 
+<histogram name="InputMethod.KeyEventLatency" units="ms"
+    expires_after="2020-04-01">
+  <owner>essential-inputs-team@google.com</owner>
+  <summary>Time taken by the engine to handle a key event.</summary>
+</histogram>
+
 <histogram name="InputMethod.MatchesSystemLanguage" enum="BooleanMatched"
     expires_after="2019-01-30">
   <owner>aurimas@chromium.org</owner>