Add logs to help debug touchpad stops working issue.

Users report touchpad sometime stop working. But it can not reproduce on our
side. I suspected the issue maybe:

1. Direct Manipulation failed at initialize
2. Direct Manipulation on incorrect state similar to issue 847611
3. Chrome does not cover some state transition for Direct Manipulation

In this patch, we add logs behind feature flag PrecisionTouchpadLogging to
help us debug. We use feature flag instead of VLOG because VLOG is not working
on Windows (issue 440172).

Bug: 914914
Change-Id: I02a28418914f18558667666f9e0779cb8d4d2eb7
Reviewed-on: https://chromium-review.googlesource.com/c/1450612
Commit-Queue: Jianpeng Chao <chaopeng@chromium.org>
Reviewed-by: Bruce Dawson <brucedawson@chromium.org>
Reviewed-by: Scott Violet <sky@chromium.org>
Cr-Commit-Position: refs/heads/master@{#629786}

ui/base/ui_base_features.cc

@@ -100,6 +100,11 @@ bool IsUsingWMPointerForTouch() {
 // Enables DirectManipulation API for processing Precision Touchpad events.
 const base::Feature kPrecisionTouchpad{"PrecisionTouchpad",
                                        base::FEATURE_ENABLED_BY_DEFAULT};
+
+// Enables Logging for DirectManipulation.
+const base::Feature kPrecisionTouchpadLogging{
+    "PrecisionTouchpadLogging", base::FEATURE_DISABLED_BY_DEFAULT};
+
 // Enables Swipe left/right to navigation back/forward API for processing
 // Precision Touchpad events.
 const base::Feature kPrecisionTouchpadScrollPhase{

ui/base/ui_base_features.h

@@ -35,6 +35,7 @@ UI_BASE_EXPORT extern const base::Feature kCalculateNativeWinOcclusion;
 UI_BASE_EXPORT extern const base::Feature kInputPaneOnScreenKeyboard;
 UI_BASE_EXPORT extern const base::Feature kPointerEventsForTouch;
 UI_BASE_EXPORT extern const base::Feature kPrecisionTouchpad;
+UI_BASE_EXPORT extern const base::Feature kPrecisionTouchpadLogging;
 UI_BASE_EXPORT extern const base::Feature kPrecisionTouchpadScrollPhase;
 UI_BASE_EXPORT extern const base::Feature kTSFImeSupport;
 

ui/base/win/direct_manipulation.cc

@@ -7,7 +7,9 @@
 #include <objbase.h>
 #include <cmath>
 
+#include "base/logging.h"
 #include "base/memory/ptr_util.h"
+#include "base/optional.h"
 #include "base/threading/thread_task_runner_handle.h"
 #include "base/win/windows_version.h"
 #include "ui/base/ui_base_features.h"
@@ -17,6 +19,30 @@
 namespace ui {
 namespace win {
 
+namespace {
+base::Optional<bool> logging_enabled;
+
+bool LoggingEnabled() {
+  if (!logging_enabled.has_value()) {
+    logging_enabled =
+        base::FeatureList::IsEnabled(features::kPrecisionTouchpadLogging);
+  }
+
+  return logging_enabled.value();
+}
+
+// TODO(crbug.com/914914) This is added for help us getting debug log on
+// machine with scrolling issue on Windows Precision Touchpad. We will remove it
+// after Windows Precision Touchpad scrolling issue fixed.
+void DebugLogging(const std::string& s, HRESULT hr) {
+  if (!LoggingEnabled())
+    return;
+
+  LOG(ERROR) << "Windows PTP: " << s << " " << hr;
+}
+
+}  // namespace
+
 // static
 std::unique_ptr<DirectManipulationHelper>
 DirectManipulationHelper::CreateInstance(HWND window,
@@ -79,18 +105,24 @@ bool DirectManipulationHelper::Initialize(WindowEventTarget* event_target) {
   HRESULT hr =
       ::CoCreateInstance(CLSID_DirectManipulationManager, nullptr,
                          CLSCTX_INPROC_SERVER, IID_PPV_ARGS(&manager_));
-  if (!SUCCEEDED(hr))
+  if (!SUCCEEDED(hr)) {
+    DebugLogging("DirectManipulationManager create failed.", hr);
     return false;
+  }
 
   // Since we want to use fake viewport, we need UpdateManager to tell a fake
   // fake render frame.
   hr = manager_->GetUpdateManager(IID_PPV_ARGS(&update_manager_));
-  if (!SUCCEEDED(hr))
+  if (!SUCCEEDED(hr)) {
+    DebugLogging("Get UpdateManager failed.", hr);
     return false;
+  }
 
   hr = manager_->CreateViewport(nullptr, window_, IID_PPV_ARGS(&viewport_));
-  if (!SUCCEEDED(hr))
+  if (!SUCCEEDED(hr)) {
+    DebugLogging("Viewport create failed.", hr);
     return false;
+  }
 
   DIRECTMANIPULATION_CONFIGURATION configuration =
       DIRECTMANIPULATION_CONFIGURATION_INTERACTION |
@@ -102,15 +134,19 @@ bool DirectManipulationHelper::Initialize(WindowEventTarget* event_target) {
       DIRECTMANIPULATION_CONFIGURATION_SCALING;
 
   hr = viewport_->ActivateConfiguration(configuration);
-  if (!SUCCEEDED(hr))
+  if (!SUCCEEDED(hr)) {
+    DebugLogging("Viewport set ActivateConfiguration failed.", hr);
     return false;
+  }
 
   // Since we are using fake viewport and only want to use Direct Manipulation
   // for touchpad, we need to use MANUALUPDATE option.
   hr = viewport_->SetViewportOptions(
       DIRECTMANIPULATION_VIEWPORT_OPTIONS_MANUALUPDATE);
-  if (!SUCCEEDED(hr))
+  if (!SUCCEEDED(hr)) {
+    DebugLogging("Viewport set ViewportOptions failed.", hr);
     return false;
+  }
 
   event_handler_ =
       Microsoft::WRL::Make<DirectManipulationHandler>(this, event_target);
@@ -119,50 +155,81 @@ bool DirectManipulationHelper::Initialize(WindowEventTarget* event_target) {
   // IDirectManipulationViewportEventHandler.
   hr = viewport_->AddEventHandler(window_, event_handler_.Get(),
                                   &view_port_handler_cookie_);
-  if (!SUCCEEDED(hr))
+  if (!SUCCEEDED(hr)) {
+    DebugLogging("Viewport add EventHandler failed.", hr);
     return false;
+  }
 
   // Set default rect for viewport before activate.
   viewport_size_ = {1000, 1000};
   RECT rect = gfx::Rect(viewport_size_).ToRECT();
   hr = viewport_->SetViewportRect(&rect);
-  if (!SUCCEEDED(hr))
+  if (!SUCCEEDED(hr)) {
+    DebugLogging("Viewport set rect failed.", hr);
     return false;
+  }
 
   hr = manager_->Activate(window_);
-  if (!SUCCEEDED(hr))
+  if (!SUCCEEDED(hr)) {
+    DebugLogging("DirectManipulationManager activate failed.", hr);
     return false;
+  }
 
   hr = viewport_->Enable();
-  if (!SUCCEEDED(hr))
+  if (!SUCCEEDED(hr)) {
+    DebugLogging("Viewport enable failed.", hr);
     return false;
+  }
 
   hr = update_manager_->Update(nullptr);
-  if (!SUCCEEDED(hr))
+  if (!SUCCEEDED(hr)) {
+    DebugLogging("UpdateManager update failed.", hr);
     return false;
+  }
 
+  DebugLogging("DirectManipulation initialization complete", S_OK);
   return true;
 }
 
 void DirectManipulationHelper::Activate() {
-  viewport_->Stop();
-  manager_->Activate(window_);
+  HRESULT hr = viewport_->Stop();
+  if (!SUCCEEDED(hr)) {
+    DebugLogging("Viewport stop failed.", hr);
+    return;
+  }
+
+  hr = manager_->Activate(window_);
+  if (!SUCCEEDED(hr))
+    DebugLogging("DirectManipulationManager activate failed.", hr);
 }
 
 void DirectManipulationHelper::Deactivate() {
-  viewport_->Stop();
-  manager_->Deactivate(window_);
+  HRESULT hr = viewport_->Stop();
+  if (!SUCCEEDED(hr)) {
+    DebugLogging("Viewport stop failed.", hr);
+    return;
+  }
+
+  hr = manager_->Deactivate(window_);
+  if (!SUCCEEDED(hr))
+    DebugLogging("DirectManipulationManager deactivate failed.", hr);
 }
 
 void DirectManipulationHelper::SetSize(const gfx::Size& size) {
   if (viewport_size_ == size)
     return;
 
-  viewport_->Stop();
+  HRESULT hr = viewport_->Stop();
+  if (!SUCCEEDED(hr)) {
+    DebugLogging("Viewport stop failed.", hr);
+    return;
+  }
 
   viewport_size_ = size;
   RECT rect = gfx::Rect(viewport_size_).ToRECT();
-  viewport_->SetViewportRect(&rect);
+  hr = viewport_->SetViewportRect(&rect);
+  if (!SUCCEEDED(hr))
+    DebugLogging("Viewport set rect failed.", hr);
 }
 
 bool DirectManipulationHelper::OnPointerHitTest(
@@ -187,7 +254,12 @@ bool DirectManipulationHelper::OnPointerHitTest(
       GetProcAddress(GetModuleHandleA("user32.dll"), "GetPointerType"));
   if (get_pointer_type && get_pointer_type(pointer_id, &pointer_type) &&
       pointer_type == PT_TOUCHPAD && event_target) {
-    viewport_->SetContact(pointer_id);
+    HRESULT hr = viewport_->SetContact(pointer_id);
+    if (!SUCCEEDED(hr)) {
+      DebugLogging("Viewport set contact failed.", hr);
+      return false;
+    }
+
     // Request begin frame for fake viewport.
     need_poll_events_ = true;
   }
@@ -201,8 +273,10 @@ HRESULT DirectManipulationHelper::ResetViewport(bool need_poll_events) {
       viewport_->ZoomToRect(static_cast<float>(0), static_cast<float>(0),
                             static_cast<float>(viewport_size_.width()),
                             static_cast<float>(viewport_size_.height()), FALSE);
-  if (!SUCCEEDED(hr))
+  if (!SUCCEEDED(hr)) {
+    DebugLogging("Viewport zoom to rect failed.", hr);
     return hr;
+  }
 
   need_poll_events_ = need_poll_events;
   return S_OK;
@@ -210,7 +284,9 @@ HRESULT DirectManipulationHelper::ResetViewport(bool need_poll_events) {
 
 bool DirectManipulationHelper::PollForNextEvent() {
   // Simulate 1 frame in update_manager_.
-  update_manager_->Update(nullptr);
+  HRESULT hr = update_manager_->Update(nullptr);
+  if (!SUCCEEDED(hr))
+    DebugLogging("UpdateManager update failed.", hr);
   return need_poll_events_;
 }
 
@@ -234,6 +310,13 @@ void DirectManipulationHandler::TransitionToState(Gesture new_gesture_state) {
   if (gesture_state_ == new_gesture_state)
     return;
 
+  if (LoggingEnabled()) {
+    std::string s = "TransitionToState " +
+                    std::to_string(static_cast<int>(gesture_state_)) + " -> " +
+                    std::to_string(static_cast<int>(new_gesture_state));
+    DebugLogging(s, S_OK);
+  }
+
   Gesture previous_gesture_state = gesture_state_;
   gesture_state_ = new_gesture_state;
 
@@ -303,6 +386,12 @@ HRESULT DirectManipulationHandler::OnViewportStatusChanged(
   // testing.
   DCHECK(viewport);
 
+  if (LoggingEnabled()) {
+    std::string s = "ViewportStatusChanged " + std::to_string(previous) +
+                    " -> " + std::to_string(current);
+    DebugLogging(s, S_OK);
+  }
+
   // The state of our viewport has changed! We'l be in one of three states:
   // - ENABLED: initial state
   // - READY: the previous gesture has been completed
@@ -397,8 +486,10 @@ HRESULT DirectManipulationHandler::OnContentUpdated(
 
   float xform[6];
   hr = content->GetContentTransform(xform, ARRAYSIZE(xform));
-  if (!SUCCEEDED(hr))
+  if (!SUCCEEDED(hr)) {
+    DebugLogging("DirectManipulationContent get transform failed.", hr);
     return hr;
+  }
 
   float scale = xform[0];
   int x_offset = xform[4] / device_scale_factor_;