Implement native event observer for Windows.

This CL adds a new MessagePumpForUI::Observer class, which can be used to get
notifications pre and post MSG dispatch.

Change-Id: I16b0df6d30b41f04f124d4b64d850c278f2c10d9
Reviewed-on: https://chromium-review.googlesource.com/1166164
Commit-Queue: Erik Chen <erikchen@chromium.org>
Reviewed-by: Bruce Dawson <brucedawson@chromium.org>
Reviewed-by: Timothy Dresser <tdresser@chromium.org>
Reviewed-by: Gabriel Charette <gab@chromium.org>
Cr-Commit-Position: refs/heads/master@{#582324}

base/message_loop/message_loop_current.cc

@@ -178,6 +178,18 @@ void MessageLoopCurrentForUI::Abort() {
 }
 #endif  // defined(OS_ANDROID)
 
+#if defined(OS_WIN)
+void MessageLoopCurrentForUI::AddMessagePumpObserver(
+    MessagePumpForUI::Observer* observer) {
+  pump_->AddObserver(observer);
+}
+
+void MessageLoopCurrentForUI::RemoveMessagePumpObserver(
+    MessagePumpForUI::Observer* observer) {
+  pump_->RemoveObserver(observer);
+}
+#endif  // defined(OS_WIN)
+
 #endif  // !defined(OS_NACL)
 
 //------------------------------------------------------------------------------

base/message_loop/message_loop_current.h

@@ -236,6 +236,11 @@ class BASE_EXPORT MessageLoopCurrentForUI : public MessageLoopCurrent {
   void Abort();
 #endif
 
+#if defined(OS_WIN)
+  void AddMessagePumpObserver(MessagePumpForUI::Observer* observer);
+  void RemoveMessagePumpObserver(MessagePumpForUI::Observer* observer);
+#endif
+
  private:
   MessageLoopCurrentForUI(MessageLoop* current, MessagePumpForUI* pump)
       : MessageLoopCurrent(current), pump_(pump) {

base/message_loop/message_pump_win.cc

@@ -125,6 +125,14 @@ void MessagePumpForUI::EnableWmQuit() {
   enable_wm_quit_ = true;
 }
 
+void MessagePumpForUI::AddObserver(Observer* observer) {
+  observers_.AddObserver(observer);
+}
+
+void MessagePumpForUI::RemoveObserver(Observer* observer) {
+  observers_.RemoveObserver(observer);
+}
+
 //-----------------------------------------------------------------------------
 // MessagePumpForUI private:
 
@@ -368,8 +376,12 @@ bool MessagePumpForUI::ProcessMessageHelper(const MSG& msg) {
   if (msg.message == kMsgHaveWork && msg.hwnd == message_window_.hwnd())
     return ProcessPumpReplacementMessage();
 
+  for (Observer& observer : observers_)
+    observer.WillDispatchMSG(msg);
   TranslateMessage(&msg);
   DispatchMessage(&msg);
+  for (Observer& observer : observers_)
+    observer.DidDispatchMSG(msg);
 
   return true;
 }

base/message_loop/message_pump_win.h

@@ -12,6 +12,7 @@
 
 #include "base/base_export.h"
 #include "base/message_loop/message_pump.h"
+#include "base/observer_list.h"
 #include "base/time/time.h"
 #include "base/win/message_window.h"
 #include "base/win/scoped_handle.h"
@@ -122,6 +123,17 @@ class BASE_EXPORT MessagePumpForUI : public MessagePumpWin {
   // Make the MessagePumpForUI respond to WM_QUIT messages.
   void EnableWmQuit();
 
+  // An observer interface to give the scheduler an opportunity to log
+  // information about MSGs before and after they are dispatched.
+  class BASE_EXPORT Observer {
+   public:
+    virtual void WillDispatchMSG(const MSG& msg) = 0;
+    virtual void DidDispatchMSG(const MSG& msg) = 0;
+  };
+
+  void AddObserver(Observer* observer);
+  void RemoveObserver(Observer* obseerver);
+
  private:
   bool MessageCallback(
       UINT message, WPARAM wparam, LPARAM lparam, LRESULT* result);
@@ -139,6 +151,8 @@ class BASE_EXPORT MessagePumpForUI : public MessagePumpWin {
   // Whether MessagePumpForUI responds to WM_QUIT messages or not.
   // TODO(thestig): Remove when the Cloud Print Service goes away.
   bool enable_wm_quit_ = false;
+
+  ObserverList<Observer> observers_;
 };
 
 //-----------------------------------------------------------------------------

content/browser/scheduler/responsiveness/native_event_observer.cc

@@ -2,23 +2,61 @@
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
+// Needed for defined(OS_WIN)
+#include "build/build_config.h"
+
+// Windows headers must come first.
+#if defined(OS_WIN)
+#include <windows.h>
+
+#include <timeapi.h>
+#endif
+
+// Proceed with header includes in usual order.
 #include "content/browser/scheduler/responsiveness/native_event_observer.h"
 
 #include "ui/events/platform/platform_event_source.h"
 
-#if defined(OS_LINUX)
 #if defined(USE_X11)
 #include "ui/events/platform/x11/x11_event_source.h"  // nogncheck
 #elif defined(USE_OZONE)
 #include "ui/events/event.h"
 #endif
 
+#if defined(OS_LINUX)
 #include "ui/events/platform_event.h"
 #endif
 
+#if defined(OS_WIN)
+#include "base/message_loop/message_loop_current.h"
+#endif
+
 namespace content {
 namespace responsiveness {
 
+#if defined(OS_WIN) || (defined(OS_LINUX) && defined(USE_X11))
+
+namespace {
+
+// Clamps a TimeDelta to be within [0 seconds, 30 seconds].
+// Relies on the assumption that |delta| is >= 0 seconds.
+base::TimeDelta ClampDeltaFromExternalSource(const base::TimeDelta& delta) {
+  DCHECK_GE(delta, base::TimeDelta());
+
+  // Ignore pathologically long deltas. External source is probably having
+  // issues.
+  constexpr base::TimeDelta pathologically_long_duration =
+      base::TimeDelta::FromSeconds(30);
+  if (delta > pathologically_long_duration)
+    return base::TimeDelta();
+
+  return delta;
+}
+
+}  // namespace
+
+#endif  // defined(OS_WIN) || (defined(OS_LINUX) && defined(USE_X11))
+
 NativeEventObserver::NativeEventObserver(
     WillRunEventCallback will_run_event_callback,
     DidRunEventCallback did_run_event_callback)
@@ -31,7 +69,6 @@ NativeEventObserver::~NativeEventObserver() {
   DeregisterObserver();
 }
 
-#if !defined(OS_MACOSX)
 #if defined(OS_LINUX)
 void NativeEventObserver::RegisterObserver() {
   ui::PlatformEventSource::GetInstance()->AddPlatformEventObserver(this);
@@ -56,30 +93,65 @@ void NativeEventObserver::DidProcessEvent(const ui::PlatformEvent& event) {
   uint32_t current_server_time_ms = static_cast<uint32_t>(
       ui::X11EventSource::GetInstance()->GetCurrentServerTime());
 
-  int32_t delta_ms = current_server_time_ms - event_server_time_ms;
-
-  // If for some reason server time is not monotonically increasing, ignore it.
-  if (delta_ms < 0)
-    delta_ms = 0;
-
-  // Ignore pathologically long deltas. Server is probably having issues.
+  // On X11, event times are in X11 Server time. To convert to base::TimeTicks,
+  // we perform a round-trip to the X11 Server, subtract the two times to get a
+  // TimeDelta, and then subtract that from base::TimeTicks::Now(). Since we're
+  // working with units of time from an external source, we clamp the TimeDelta
+  // to reasonable values.
+  uint32_t delta_ms = current_server_time_ms - event_server_time_ms;
   base::TimeDelta delta = base::TimeDelta::FromMilliseconds(delta_ms);
-  base::TimeDelta long_duration = base::TimeDelta::FromSeconds(30);
-  if (delta > long_duration)
-    delta = base::TimeDelta();
+  base::TimeDelta sanitized = ClampDeltaFromExternalSource(delta);
 
-  did_run_event_callback_.Run(&event, base::TimeTicks::Now() - delta);
+  did_run_event_callback_.Run(&event, base::TimeTicks::Now() - sanitized);
 #else
 #error
 #endif
 }
-#else   // defined(OS_LINUX)
-// TODO(erikchen): Implement this for non-macOS, non-Linux platforms.
-// https://crbug.com/859155.
+#endif  // defined(OS_LINUX)
+
+#if defined(OS_WIN)
+void NativeEventObserver::RegisterObserver() {
+  base::MessageLoopCurrentForUI::Get()->AddMessagePumpObserver(this);
+}
+void NativeEventObserver::DeregisterObserver() {
+  base::MessageLoopCurrentForUI::Get()->RemoveMessagePumpObserver(this);
+}
+void NativeEventObserver::WillDispatchMSG(const MSG& msg) {
+  will_run_event_callback_.Run(&msg);
+}
+void NativeEventObserver::DidDispatchMSG(const MSG& msg) {
+  // On Windows, MSG.time is in units of milliseconds since system started. It
+  // uses the timer exposed by ::GetTickCount().
+  // https://blogs.msdn.microsoft.com/oldnewthing/20140122-00/?p=2013
+  //
+  // This timer has ~16ms granularity. This is okay for us since we require
+  // ~100ms granularity.
+  // https://randomascii.wordpress.com/2013/05/09/timegettime-versus-gettickcount/
+  //
+  // To convert MSG.time to TimeTicks, we subtract MSG.time from
+  // ::GetTickCount() to create a TimeDelta, and then subtract that from
+  // TimeTicks::Now().
+  //
+  // We cast both values to DWORD [uint32], perform subtraction to get a uint32,
+  // and then shove that into a TimeDelta.
+  //
+  // Note: Both measurements of time can experience rollover. If one of them has
+  // rolled over but the other has not, then the result will be very large.
+  // ClampDeltaFromExternalSource takes care of this, in addition to any other
+  // odd timing issues that may come up [e.g. MSG.time time-traveling to give a
+  // larger value than ::timeGetTime() -- this has not been observed in practice
+  // but since we don't control the code in question, we trust nothing].
+  base::TimeDelta delta = base::TimeDelta::FromMilliseconds(
+      ::GetTickCount() - static_cast<DWORD>(msg.time));
+  base::TimeDelta sanitized = ClampDeltaFromExternalSource(delta);
+  did_run_event_callback_.Run(&msg, base::TimeTicks::Now() - sanitized);
+}
+#endif  // defined(OS_WIN)
+
+#if defined(OS_ANDROID) || defined(OS_FUCHSIA)
 void NativeEventObserver::RegisterObserver() {}
 void NativeEventObserver::DeregisterObserver() {}
-#endif  // defined(OS_LINUX)
-#endif  // !defined(OS_MACOSX)
+#endif  // defined(OS_ANDROID) || defined(OS_FUCHSIA)
 
 }  // namespace responsiveness
 }  // namespace content

content/browser/scheduler/responsiveness/native_event_observer.h

@@ -18,6 +18,10 @@
 #include "ui/events/platform/platform_event_observer.h"
 #endif
 
+#if defined(OS_WIN)
+#include "base/message_loop/message_pump_win.h"
+#endif
+
 namespace content {
 namespace responsiveness {
 
@@ -37,6 +41,8 @@ class CONTENT_EXPORT NativeEventObserver
     : public NativeEventProcessorObserver
 #elif defined(OS_LINUX)
     : public ui::PlatformEventObserver
+#elif defined(OS_WIN)
+    : public base::MessagePumpForUI::Observer
 #endif
 {
  public:
@@ -71,6 +77,10 @@ class CONTENT_EXPORT NativeEventObserver
   // Exposed for tests.
   void WillProcessEvent(const ui::PlatformEvent& event) override;
   void DidProcessEvent(const ui::PlatformEvent& event) override;
+#elif defined(OS_WIN)
+  // base::MessagePumpForUI::Observer overrides:
+  void WillDispatchMSG(const MSG& msg) override;
+  void DidDispatchMSG(const MSG& msg) override;
 #endif
 
  private:

content/browser/scheduler/responsiveness/native_event_observer_browsertest_win.cc

+// Copyright 2018 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 "content/browser/scheduler/responsiveness/native_event_observer.h"
+
+#include "base/bind_helpers.h"
+#include "base/win/message_window.h"
+#include "content/public/test/content_browser_test.h"
+
+namespace content {
+namespace responsiveness {
+
+namespace {
+
+bool HandleMessage(UINT message,
+                   WPARAM wparam,
+                   LPARAM lparam,
+                   LRESULT* result) {
+  return false;
+}
+
+}  // namespace
+
+class ResponsivenessNativeEventObserverBrowserTest : public ContentBrowserTest {
+ public:
+  void WillRunEvent(const void* opaque_id) {
+    ASSERT_FALSE(will_run_id_);
+    will_run_id_ = opaque_id;
+  }
+  void DidRunEvent(const void* opaque_id, base::TimeTicks creation_time) {
+    ASSERT_FALSE(did_run_id_);
+    did_run_id_ = opaque_id;
+    creation_time_ = creation_time;
+    std::move(quit_closure_).Run();
+  }
+
+ protected:
+  const void* will_run_id_ = nullptr;
+  const void* did_run_id_ = nullptr;
+  base::TimeTicks creation_time_;
+  base::OnceClosure quit_closure_;
+};
+
+IN_PROC_BROWSER_TEST_F(ResponsivenessNativeEventObserverBrowserTest,
+                       EventForwarding) {
+  base::win::MessageWindow window;
+  EXPECT_TRUE(window.Create(base::BindRepeating(&HandleMessage)));
+
+  NativeEventObserver observer(
+      base::BindRepeating(
+          &ResponsivenessNativeEventObserverBrowserTest::WillRunEvent,
+          base::Unretained(this)),
+      base::BindRepeating(
+          &ResponsivenessNativeEventObserverBrowserTest::DidRunEvent,
+          base::Unretained(this)));
+  base::TimeTicks time_at_creation = base::TimeTicks::Now();
+
+  EXPECT_FALSE(will_run_id_);
+  EXPECT_FALSE(did_run_id_);
+
+  EXPECT_NE(PostMessage(window.hwnd(), WM_USER, 100, 0), 0);
+  base::RunLoop run_loop;
+  quit_closure_ = run_loop.QuitClosure();
+  run_loop.Run();
+
+  EXPECT_EQ(will_run_id_, did_run_id_);
+  EXPECT_NE(will_run_id_, nullptr);
+
+  // time_at_creation should be really similar to creation_time_. As a sanity
+  // check, make sure they're within a second of each other.
+  EXPECT_LT(fabs((creation_time_ - time_at_creation).InMilliseconds()), 1000);
+}
+
+}  // namespace responsiveness
+}  // namespace content

content/test/BUILD.gn

@@ -829,6 +829,7 @@ test("content_browsertests") {
     "../browser/renderer_host/render_widget_host_view_mac_browsertest.mm",
     "../browser/resource_loading_browsertest.cc",
     "../browser/scheduler/responsiveness/native_event_observer_browsertest.mm",
+    "../browser/scheduler/responsiveness/native_event_observer_browsertest_win.cc",
     "../browser/screen_orientation/screen_orientation_browsertest.cc",
     "../browser/security_exploit_browsertest.cc",
     "../browser/service_manager/service_manager_context_browsertest.cc",