From 548a93ba2955cd2d8e754c4564ead4e367c90c4e Mon Sep 17 00:00:00 2001 From: Joe Mason Date: Mon, 3 May 2021 17:19:41 +0000 Subject: [PATCH] Deprecate Event.Latency.OS.* for Event.Latency.OS2.* The new metric is correct on Windows, has a wider range so that fewer samples land in the overflow bucket, and has a millisecond granularity instead of microsecond. Also removes the Event.Latency.OS_WIN.* metrics that were used to validate this code. Bug: 1189656 Change-Id: I555459596c3ed4f47a874ed27c943f254e230577 Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2840587 Reviewed-by: Gabriel Charette Reviewed-by: Brian White Reviewed-by: Sadrul Chowdhury Reviewed-by: Ted Choc Commit-Queue: Joe Mason Cr-Commit-Position: refs/heads/master@{#878451} --- .../android/content_ui_event_handler.cc | 5 +- .../render_widget_host_view_android.cc | 20 +- .../render_widget_host_view_mac_unittest.mm | 3 +- .../histograms_xml/event/histograms.xml | 33 ++- .../histogram_suffixes_list.xml | 19 +- ui/events/cocoa/events_mac.mm | 5 + ui/events/event_unittest.cc | 257 ++++++++---------- ui/events/event_utils.cc | 237 +++++----------- ui/events/event_utils.h | 36 ++- ui/events/events_default.cc | 5 + ui/events/events_stub.cc | 5 + ui/events/win/events_win.cc | 10 + ui/events/win/events_win_utils.cc | 61 +++++ ui/events/win/events_win_utils.h | 23 ++ .../x11/test/events_x_unittest.cc | 6 +- ui/views/win/hwnd_message_handler.cc | 22 +- ui/views/win/pen_event_processor.cc | 9 +- 17 files changed, 378 insertions(+), 378 deletions(-) diff --git a/content/browser/android/content_ui_event_handler.cc b/content/browser/android/content_ui_event_handler.cc index 0a7042d033eb2c..265c5ef7f5ac44 100644 --- a/content/browser/android/content_ui_event_handler.cc +++ b/content/browser/android/content_ui_event_handler.cc @@ -16,6 +16,7 @@ #include "ui/events/android/key_event_android.h" #include "ui/events/android/motion_event_android.h" #include "ui/events/base_event_utils.h" +#include "ui/events/event_utils.h" using base::android::AttachCurrentThread; using base::android::JavaParamRef; @@ -99,9 +100,7 @@ void ContentUiEventHandler::SendMouseWheelEvent( base::TimeTicks current_time = ui::EventTimeForNow(); base::TimeTicks event_time = base::TimeTicks() + base::TimeDelta::FromMilliseconds(time_ms); - base::TimeDelta delta = current_time - event_time; - UMA_HISTOGRAM_CUSTOM_COUNTS("Event.Latency.OS.MOUSE_WHEEL", - delta.InMicroseconds(), 1, 1000000, 50); + ComputeEventLatencyOS(ui::ET_MOUSEWHEEL, event_time, current_time); ui::MotionEventAndroid::Pointer pointer( 0, x, y, 0.0f /* touch_major */, 0.0f /* touch_minor */, 0.0f, 0.0f, 0); diff --git a/content/browser/renderer_host/render_widget_host_view_android.cc b/content/browser/renderer_host/render_widget_host_view_android.cc index 9dc89454814380..6bf39d0507211e 100644 --- a/content/browser/renderer_host/render_widget_host_view_android.cc +++ b/content/browser/renderer_host/render_widget_host_view_android.cc @@ -92,6 +92,7 @@ #include "ui/events/blink/blink_features.h" #include "ui/events/blink/did_overscroll_params.h" #include "ui/events/blink/web_input_event_traits.h" +#include "ui/events/event_utils.h" #include "ui/events/gesture_detection/gesture_provider_config_helper.h" #include "ui/gfx/android/view_configuration.h" #include "ui/gfx/codec/jpeg_codec.h" @@ -2304,25 +2305,24 @@ void RenderWidgetHostViewAndroid::OnStylusSelectTap(base::TimeTicks time, void RenderWidgetHostViewAndroid::ComputeEventLatencyOSTouchHistograms( const ui::MotionEvent& event) { base::TimeTicks event_time = event.GetEventTime(); - base::TimeDelta delta = base::TimeTicks::Now() - event_time; + base::TimeTicks current_time = base::TimeTicks::Now(); + ui::EventType event_type; switch (event.GetAction()) { case ui::MotionEvent::Action::DOWN: case ui::MotionEvent::Action::POINTER_DOWN: - UMA_HISTOGRAM_CUSTOM_COUNTS("Event.Latency.OS.TOUCH_PRESSED", - delta.InMicroseconds(), 1, 1000000, 50); - return; + event_type = ui::ET_TOUCH_PRESSED; + break; case ui::MotionEvent::Action::MOVE: - UMA_HISTOGRAM_CUSTOM_COUNTS("Event.Latency.OS.TOUCH_MOVED", - delta.InMicroseconds(), 1, 1000000, 50); - return; + event_type = ui::ET_TOUCH_MOVED; + break; case ui::MotionEvent::Action::UP: case ui::MotionEvent::Action::POINTER_UP: - UMA_HISTOGRAM_CUSTOM_COUNTS("Event.Latency.OS.TOUCH_RELEASED", - delta.InMicroseconds(), 1, 1000000, 50); - return; + event_type = ui::ET_TOUCH_RELEASED; + break; default: return; } + ui::ComputeEventLatencyOS(event_type, event_time, current_time); } void RenderWidgetHostViewAndroid::CreateOverscrollControllerIfPossible() { diff --git a/content/browser/renderer_host/render_widget_host_view_mac_unittest.mm b/content/browser/renderer_host/render_widget_host_view_mac_unittest.mm index d3f8bd79e2cea6..ea91436c3a855a 100644 --- a/content/browser/renderer_host/render_widget_host_view_mac_unittest.mm +++ b/content/browser/renderer_host/render_widget_host_view_mac_unittest.mm @@ -1697,7 +1697,7 @@ void SendEndPinchEvent() { base::HistogramTester histogram_tester; // Send an initial wheel event for scrolling by 3 lines. - // Verify that Event.Latency.OS.MOUSE_WHEEL histogram is computed properly. + // Verify that Event.Latency.OS2.MOUSE_WHEEL histogram is computed properly. NSEvent* wheelEvent = MockScrollWheelEventWithPhase(@selector(phaseBegan),3); [rwhv_mac_->GetInProcessNSView() scrollWheel:wheelEvent]; @@ -1708,6 +1708,7 @@ void SendEndPinchEvent() { blink::mojom::InputEventResultState::kConsumed); histogram_tester.ExpectTotalCount("Event.Latency.OS.MOUSE_WHEEL", 1); + histogram_tester.ExpectTotalCount("Event.Latency.OS2.MOUSE_WHEEL", 1); } // This test verifies that |selected_text_| is updated accordingly with diff --git a/tools/metrics/histograms/histograms_xml/event/histograms.xml b/tools/metrics/histograms/histograms_xml/event/histograms.xml index d1400f47602ccf..deb4dacd3564c8 100644 --- a/tools/metrics/histograms/histograms_xml/event/histograms.xml +++ b/tools/metrics/histograms/histograms_xml/event/histograms.xml @@ -380,13 +380,14 @@ reviews. Googlers can read more about this at go/gwsq-gerrit. - + flackr@chromium.org input-dev@chromium.org Time between input event received by OS and sent to Chrome, recorded for - each event when it is received by Chrome. + each event when it is received by Chrome. This is obsoleted by + Event.Latency.OS2 and should be removed after they've been run side-by-side + for M92. Warning: This metric may include reports from clients with low-resolution clocks (i.e. on Windows, ref. |TimeTicks::IsHighResolution()|). Such reports @@ -396,6 +397,21 @@ reviews. Googlers can read more about this at go/gwsq-gerrit. + + flackr@chromium.org + input-dev@chromium.org + + Time between input event received by OS and sent to Chrome, recorded for + each event when it is received by Chrome. + + Warning: On Windows, the timestamps of most events come from a clock with a + several msec resolution so will have an abnormal distribution even when + TimeTicks::IsHighResolution returns true. The exception is touch events + which usually come from the high-resolution clock when + TimeTicks::IsHighResolution returns true. + + + sullivan@chromium.org @@ -404,7 +420,7 @@ reviews. Googlers can read more about this at go/gwsq-gerrit. For Mac, a version of Event.Latency.OS that has the positive values it would contain if ValidateEventTimeClock() were not called on the timestamps. - This metric is intended to debug http://crbug.com/1039833, where very high + This metric is intended to debug http://crbug.com/1039833 where very high numbers are seen for PageLoad.InputDelay3. The units of this metric are the same as PageLoad.InputDelay3 for consistency while debugging. @@ -412,6 +428,9 @@ reviews. Googlers can read more about this at go/gwsq-gerrit. + + Removed 2021-04-22 - replaced by Event.Latency.OS2. + joenotcharles@chromium.org catan-team@chromium.org @@ -434,6 +453,9 @@ reviews. Googlers can read more about this at go/gwsq-gerrit. + + Removed 2021-04-22 - replaced by Event.Latency.OS2. + joenotcharles@chromium.org catan-team@chromium.org @@ -456,6 +478,9 @@ reviews. Googlers can read more about this at go/gwsq-gerrit. + + Removed 2021-04-22 - replaced by Event.Latency.OS2. + joenotcharles@chromium.org catan-team@chromium.org diff --git a/tools/metrics/histograms/histograms_xml/histogram_suffixes_list.xml b/tools/metrics/histograms/histograms_xml/histogram_suffixes_list.xml index 37b7bdc67d00d3..b97f7fc5eb08d4 100644 --- a/tools/metrics/histograms/histograms_xml/histogram_suffixes_list.xml +++ b/tools/metrics/histograms/histograms_xml/histogram_suffixes_list.xml @@ -6333,11 +6333,24 @@ reviews. Googlers can read more about this at go/gwsq-gerrit. + - - - + + + Removed 2021-04-22 - replaced by Event.Latency.OS2. + + + + + Removed 2021-04-22 - replaced by Event.Latency.OS2. + + + + + Removed 2021-04-22 - replaced by Event.Latency.OS2. + + diff --git a/ui/events/cocoa/events_mac.mm b/ui/events/cocoa/events_mac.mm index 6f0983524c29eb..b716ef85eec487 100644 --- a/ui/events/cocoa/events_mac.mm +++ b/ui/events/cocoa/events_mac.mm @@ -84,6 +84,11 @@ int EventFlagsFromNative(const PlatformEvent& event) { return timestamp; } +base::TimeTicks EventLatencyTimeFromNative(const PlatformEvent& native_event, + base::TimeTicks current_time) { + return EventTimeFromNative(native_event); +} + gfx::PointF EventLocationFromNative(const PlatformEvent& native_event) { NSWindow* window = [native_event window]; NSPoint location = [native_event locationInWindow]; diff --git a/ui/events/event_unittest.cc b/ui/events/event_unittest.cc index e651e1dbf36e91..0aede5b92219b3 100644 --- a/ui/events/event_unittest.cc +++ b/ui/events/event_unittest.cc @@ -29,6 +29,10 @@ #include "ui/events/test/test_event_target.h" #include "ui/gfx/transform.h" +#if defined(OS_WIN) +#include "ui/events/win/events_win_utils.h" +#endif + namespace ui { TEST(EventTest, NoNativeEvent) { @@ -652,19 +656,14 @@ TEST(EventTest, OrdinalMotionConversion) { EXPECT_FALSE(mouseev3.flags() & EF_UNADJUSTED_MOUSE); } -// Checks that Event.Latency.OS.MOUSE_WHEEL histogram is computed properly. +// Checks that Event.Latency.OS2.MOUSE_WHEEL histogram is computed properly. TEST(EventTest, EventLatencyOSMouseWheelHistogram) { #if defined(OS_WIN) base::HistogramTester histogram_tester; MSG event = {nullptr, WM_MOUSEWHEEL, 0, 0}; MouseWheelEvent mouseWheelEvent(event); histogram_tester.ExpectTotalCount("Event.Latency.OS.MOUSE_WHEEL", 1); - histogram_tester.ExpectTotalCount("Event.Latency.OS_WIN.HIGH_RES.MOUSE_WHEEL", - 0); - histogram_tester.ExpectTotalCount("Event.Latency.OS_WIN.LOW_RES.MOUSE_WHEEL", - 0); - histogram_tester.ExpectTotalCount("Event.Latency.OS_WIN_IS_VALID.MOUSE_WHEEL", - 0); + histogram_tester.ExpectTotalCount("Event.Latency.OS2.MOUSE_WHEEL", 1); #endif } @@ -841,104 +840,13 @@ INSTANTIATE_TEST_SUITE_P( ::testing::Combine(::testing::Values(WM_CHAR), ::testing::ValuesIn(kAltGraphEventTestCases))); -// Tests for ComputeEventLatencyOSWin - -constexpr struct EventLatencyTickCountTestCase { - EventType event_type; - const char* histogram_suffix; -} kEventLatencyTickCountTestCases[] = { - { - ET_KEY_PRESSED, - "KEY_PRESSED", - }, - { - ET_MOUSE_PRESSED, - "MOUSE_PRESSED", - }, - { - ET_TOUCH_PRESSED, - "TOUCH_PRESSED", - }, -}; - -class EventLatencyTestBase : public ::testing::Test { - protected: - static constexpr char kHighResHistogram[] = "Event.Latency.OS_WIN.HIGH_RES"; - static constexpr char kLowResHistogram[] = "Event.Latency.OS_WIN.LOW_RES"; - static constexpr char kIsValidHistogram[] = "Event.Latency.OS_WIN_IS_VALID"; - - std::string HighResEventHistogram(base::StringPiece suffix) const { - return base::StrCat({kHighResHistogram, ".", suffix}); - } - - std::string LowResEventHistogram(base::StringPiece suffix) const { - return base::StrCat({kLowResHistogram, ".", suffix}); - } - - std::string IsValidEventHistogram(base::StringPiece suffix) const { - return base::StrCat({kIsValidHistogram, ".", suffix}); - } - - // Tests for all expected histograms for an event that has a valid timestamp. - void ExpectValidHistograms(const base::HistogramTester& histogram_tester, - base::TimeDelta delta, - base::StringPiece suffix) { - // Expect both general and per-event histograms to be set. - histogram_tester.ExpectUniqueSample(kIsValidHistogram, true, 1); - histogram_tester.ExpectUniqueSample(IsValidEventHistogram(suffix), true, 1); - if (base::TimeTicks::IsHighResolution()) { - histogram_tester.ExpectUniqueTimeSample(kHighResHistogram, delta, 1); - histogram_tester.ExpectUniqueTimeSample(HighResEventHistogram(suffix), - delta, 1); - histogram_tester.ExpectTotalCount(kLowResHistogram, 0); - histogram_tester.ExpectTotalCount(LowResEventHistogram(suffix), 0); - } else { - histogram_tester.ExpectUniqueTimeSample(kLowResHistogram, delta, 1); - histogram_tester.ExpectUniqueTimeSample(LowResEventHistogram(suffix), - delta, 1); - histogram_tester.ExpectTotalCount(kHighResHistogram, 0); - histogram_tester.ExpectTotalCount(HighResEventHistogram(suffix), 0); - } - } - - // Tests for all expected histograms for an event that has an invalid - // timestamp. - void ExpectInvalidHistograms(const base::HistogramTester& histogram_tester, - base::StringPiece suffix) { - histogram_tester.ExpectUniqueSample(kIsValidHistogram, false, 1); - histogram_tester.ExpectUniqueSample(IsValidEventHistogram(suffix), false, - 1); - histogram_tester.ExpectTotalCount(kHighResHistogram, 0); - histogram_tester.ExpectTotalCount(HighResEventHistogram(suffix), 0); - histogram_tester.ExpectTotalCount(kLowResHistogram, 0); - histogram_tester.ExpectTotalCount(LowResEventHistogram(suffix), 0); - } - - // Tests that no histograms were recorded for the given event. (For example - // if it has a type that should be excluded from the metric.) - void ExpectNoHistograms(const base::HistogramTester& histogram_tester, - base::StringPiece suffix) { - histogram_tester.ExpectTotalCount(kIsValidHistogram, 0); - histogram_tester.ExpectTotalCount(IsValidEventHistogram(suffix), 0); - histogram_tester.ExpectTotalCount(kHighResHistogram, 0); - histogram_tester.ExpectTotalCount(HighResEventHistogram(suffix), 0); - histogram_tester.ExpectTotalCount(kLowResHistogram, 0); - histogram_tester.ExpectTotalCount(LowResEventHistogram(suffix), 0); - } - - base::test::TaskEnvironment task_environment_{ - base::test::TaskEnvironment::TimeSource::MOCK_TIME}; -}; +// Tests for ComputeEventLatencyOS variants. -class EventLatencyTickCountTest - : public EventLatencyTestBase, - public ::testing::WithParamInterface { +class EventLatencyTest : public ::testing::Test { public: - EventLatencyTickCountTest() { - SetEventLatencyTickClockForTesting(&tick_clock_); - } + EventLatencyTest() { SetEventLatencyTickClockForTesting(&tick_clock_); } - ~EventLatencyTickCountTest() { SetEventLatencyTickClockForTesting(nullptr); } + ~EventLatencyTest() override { SetEventLatencyTickClockForTesting(nullptr); } protected: void UpdateTickClock(DWORD timestamp) { @@ -946,17 +854,25 @@ class EventLatencyTickCountTest base::TimeDelta::FromMilliseconds(timestamp)); } - // The inherited |task_environment_| mocks the base::TimeTicks clock while - // |tick_clock_| mocks ::GetTickCount. + base::test::TaskEnvironment task_environment_{ + base::test::TaskEnvironment::TimeSource::MOCK_TIME}; + + // |task_environment_| mocks the base::TimeTicks clock while |tick_clock_| + // mocks ::GetTickCount. base::SimpleTestTickClock tick_clock_; }; -TEST_P(EventLatencyTickCountTest, ComputeEventLatencyOSWinFromTickCount) { - // Create an event whose timestamp is very close to the max range of +TEST_F(EventLatencyTest, ComputeEventLatencyOSFromTickCount) { + // Create events whose timestamps are very close to the max range of // ::GetTickCount. constexpr DWORD timestamp_msec = std::numeric_limits::max() - 10; - - const std::string suffix = GetParam().histogram_suffix; + constexpr TOUCHINPUT touch_input = { + .dwTime = timestamp_msec, + }; + constexpr POINTER_INFO pointer_info = { + .dwTime = timestamp_msec, + .PerformanceCount = 0UL, + }; // This test will create several events with the same timestamp, and change // the mocked result of ::GetTickCount for each measurement. This makes it @@ -967,10 +883,16 @@ TEST_P(EventLatencyTickCountTest, ComputeEventLatencyOSWinFromTickCount) { UpdateTickClock(timestamp_msec + 5); { base::HistogramTester histogram_tester; - ComputeEventLatencyOSWinFromTickCount(GetParam().event_type, timestamp_msec, + ComputeEventLatencyOSFromTOUCHINPUT(ET_TOUCH_PRESSED, touch_input, + base::TimeTicks::Now()); + ComputeEventLatencyOSFromPOINTER_INFO(ET_TOUCH_PRESSED, pointer_info, base::TimeTicks::Now()); - ExpectValidHistograms(histogram_tester, - base::TimeDelta::FromMilliseconds(5), suffix); + histogram_tester.ExpectUniqueSample( + "Event.Latency.OS.TOUCH_PRESSED", + base::TimeDelta::FromMilliseconds(5).InMicroseconds(), 2); + histogram_tester.ExpectUniqueTimeSample( + "Event.Latency.OS2.TOUCH_PRESSED", base::TimeDelta::FromMilliseconds(5), + 2); } // Simulate ::GetTickCount advancing 15 msec, which wraps around past 0. @@ -980,30 +902,34 @@ TEST_P(EventLatencyTickCountTest, ComputeEventLatencyOSWinFromTickCount) { UpdateTickClock(wrapped_timestamp_msec); { base::HistogramTester histogram_tester; - ComputeEventLatencyOSWinFromTickCount(GetParam().event_type, timestamp_msec, + ComputeEventLatencyOSFromTOUCHINPUT(ET_TOUCH_PRESSED, touch_input, + base::TimeTicks::Now()); + ComputeEventLatencyOSFromPOINTER_INFO(ET_TOUCH_PRESSED, pointer_info, base::TimeTicks::Now()); - ExpectValidHistograms(histogram_tester, - base::TimeDelta::FromMilliseconds(15), suffix); + histogram_tester.ExpectUniqueSample( + "Event.Latency.OS.TOUCH_PRESSED", + base::TimeDelta::FromMilliseconds(15).InMicroseconds(), 2); + histogram_tester.ExpectUniqueTimeSample( + "Event.Latency.OS2.TOUCH_PRESSED", + base::TimeDelta::FromMilliseconds(15), 2); } - // Simulate an event with a bogus timestamp. + // Simulate an event with a bogus timestamp. The delta should be recorded as + // 0. UpdateTickClock(timestamp_msec - 1000); { base::HistogramTester histogram_tester; - ComputeEventLatencyOSWinFromTickCount(GetParam().event_type, timestamp_msec, + ComputeEventLatencyOSFromTOUCHINPUT(ET_TOUCH_PRESSED, touch_input, + base::TimeTicks::Now()); + ComputeEventLatencyOSFromPOINTER_INFO(ET_TOUCH_PRESSED, pointer_info, base::TimeTicks::Now()); - ExpectInvalidHistograms(histogram_tester, suffix); + histogram_tester.ExpectUniqueSample("Event.Latency.OS.TOUCH_PRESSED", 0, 2); + histogram_tester.ExpectUniqueTimeSample("Event.Latency.OS2.TOUCH_PRESSED", + base::TimeDelta(), 2); } } -INSTANTIATE_TEST_SUITE_P(All, - EventLatencyTickCountTest, - ::testing::ValuesIn(kEventLatencyTickCountTestCases)); - -using EventLatencyPerformanceCounterTest = EventLatencyTestBase; - -TEST_F(EventLatencyPerformanceCounterTest, - ComputeEventLatencyOSWinFromPerformanceCounter) { +TEST_F(EventLatencyTest, ComputeEventLatencyOSFromPerformanceCounter) { // Make sure there's enough time before Now() to create an event that's // several minutes old. task_environment_.AdvanceClock(base::TimeDelta::FromMinutes(5)); @@ -1025,39 +951,82 @@ TEST_F(EventLatencyPerformanceCounterTest, // Event created shortly before now. { + const POINTER_INFO pointer_info = { + .dwTime = 0U, + .PerformanceCount = current_timestamp - ticks_per_second, + }; base::HistogramTester histogram_tester; - ComputeEventLatencyOSWinFromPerformanceCounter( - ET_TOUCH_PRESSED, current_timestamp - ticks_per_second, - base::TimeTicks::Now()); - ExpectValidHistograms(histogram_tester, base::TimeDelta::FromSeconds(1), - "TOUCH_PRESSED"); + ComputeEventLatencyOSFromPOINTER_INFO(ET_TOUCH_PRESSED, pointer_info, + base::TimeTicks::Now()); + histogram_tester.ExpectUniqueSample( + "Event.Latency.OS.TOUCH_PRESSED", + base::TimeDelta::FromSeconds(1).InMicroseconds(), 1); + histogram_tester.ExpectUniqueTimeSample("Event.Latency.OS2.TOUCH_PRESSED", + base::TimeDelta::FromSeconds(1), 1); } // Event created several minutes before now (IsValidTimebase should return - // false). + // false). The delta should be recorded as 0. + { + const POINTER_INFO pointer_info = { + .dwTime = 0U, + .PerformanceCount = current_timestamp - 5 * 60 * ticks_per_second, + }; + base::HistogramTester histogram_tester; + ComputeEventLatencyOSFromPOINTER_INFO(ET_TOUCH_PRESSED, pointer_info, + base::TimeTicks::Now()); + histogram_tester.ExpectUniqueSample("Event.Latency.OS.TOUCH_PRESSED", 0, 1); + histogram_tester.ExpectUniqueTimeSample("Event.Latency.OS2.TOUCH_PRESSED", + base::TimeDelta(), 1); + } + + // Event created in the future (IsValidTimebase should return false). The + // delta should be recorded as 0. { + const POINTER_INFO pointer_info = { + .dwTime = 0U, + .PerformanceCount = current_timestamp + ticks_per_second, + }; base::HistogramTester histogram_tester; - ComputeEventLatencyOSWinFromPerformanceCounter( - ET_TOUCH_PRESSED, current_timestamp - 5 * 60 * ticks_per_second, - base::TimeTicks::Now()); - ExpectInvalidHistograms(histogram_tester, "TOUCH_PRESSED"); + ComputeEventLatencyOSFromPOINTER_INFO(ET_TOUCH_PRESSED, pointer_info, + base::TimeTicks::Now()); + histogram_tester.ExpectUniqueSample("Event.Latency.OS.TOUCH_PRESSED", 0, 1); + histogram_tester.ExpectUniqueTimeSample("Event.Latency.OS2.TOUCH_PRESSED", + base::TimeDelta(), 1); } - // Event created in the future (IsValidTimebase should return false). + // Invalid event with no timestamp. { + const POINTER_INFO pointer_info = { + .dwTime = 0U, + .PerformanceCount = 0UL, + }; base::HistogramTester histogram_tester; - ComputeEventLatencyOSWinFromPerformanceCounter( - ET_TOUCH_PRESSED, current_timestamp + ticks_per_second, - base::TimeTicks::Now()); - ExpectInvalidHistograms(histogram_tester, "TOUCH_PRESSED"); + ComputeEventLatencyOSFromPOINTER_INFO(ET_TOUCH_PRESSED, pointer_info, + base::TimeTicks::Now()); + histogram_tester.ExpectTotalCount("Event.Latency.OS.TOUCH_PRESSED", 0); + histogram_tester.ExpectTotalCount("Event.Latency.OS2.TOUCH_PRESSED", 0); } - // Event that should not be recorded. + // Invalid event with 2 timestamps should take the higher-precision one. { + const DWORD now_msec = 1000; + UpdateTickClock(now_msec); + + const POINTER_INFO pointer_info = { + // 10 milliseconds ago. + .dwTime = now_msec - 10, + // 1 second ago. + .PerformanceCount = current_timestamp - ticks_per_second, + }; base::HistogramTester histogram_tester; - ComputeEventLatencyOSWinFromPerformanceCounter( - ET_TOUCH_MOVED, current_timestamp - 10, base::TimeTicks::Now()); - ExpectNoHistograms(histogram_tester, "TOUCH_MOVED"); + ComputeEventLatencyOSFromPOINTER_INFO(ET_TOUCH_PRESSED, pointer_info, + base::TimeTicks::Now()); + histogram_tester.ExpectUniqueSample( + "Event.Latency.OS.TOUCH_PRESSED", + base::TimeDelta::FromSeconds(1).InMicroseconds(), 1); + histogram_tester.ExpectUniqueTimeSample("Event.Latency.OS2.TOUCH_PRESSED", + base::TimeDelta::FromSeconds(1), 1); } } diff --git a/ui/events/event_utils.cc b/ui/events/event_utils.cc index 93045d6ba57026..98a61ac4fa5278 100644 --- a/ui/events/event_utils.cc +++ b/ui/events/event_utils.cc @@ -10,120 +10,25 @@ #include "base/check.h" #include "base/metrics/histogram_macros.h" -#include "base/no_destructor.h" #include "base/notreached.h" -#include "base/numerics/safe_conversions.h" -#include "base/time/tick_clock.h" #include "ui/display/display.h" #include "ui/display/screen.h" #include "ui/events/base_event_utils.h" +#if defined(OS_WIN) +#include "ui/events/win/events_win_utils.h" +#endif + namespace ui { namespace { int g_custom_event_types = ET_LAST; -#if defined(OS_WIN) - -#define UMA_HISTOGRAM_WIN_EVENT_LATENCY_TIMES(name, sample) \ +#define UMA_HISTOGRAM_EVENT_LATENCY_TIMES(name, sample) \ UMA_HISTOGRAM_CUSTOM_TIMES(name, sample, \ base::TimeDelta::FromMilliseconds(1), \ - base::TimeDelta::FromMilliseconds(100000), 100) - -class GetTickCountClock : public base::TickClock { - public: - GetTickCountClock() = default; - ~GetTickCountClock() override = default; - - base::TimeTicks NowTicks() const override { - return base::TimeTicks() + - base::TimeDelta::FromMilliseconds(::GetTickCount()); - } -}; - -const base::TickClock* g_tick_count_clock = nullptr; - -// Logs experimental Event.Latency.OS_WIN.* metrics to parallel -// Event.Latency.OS.*. -// TODO(crbug.com/1189656): Check that these are accurate enough to replace -// Event.Latency.OS.*. -void ComputeEventLatencyOSWin(ui::EventType event_type, - base::TimeTicks event_time, - base::TimeTicks current_time) { - // Check that the event doesn't come from a device giving bogus timestamps. - // On most platforms this is done inside EventTimeFromNative. - const bool is_valid = IsValidTimebase(current_time, event_time); - UMA_HISTOGRAM_BOOLEAN("Event.Latency.OS_WIN_IS_VALID", is_valid); - switch (event_type) { - case ET_KEY_PRESSED: - UMA_HISTOGRAM_BOOLEAN("Event.Latency.OS_WIN_IS_VALID.KEY_PRESSED", - is_valid); - break; - case ET_MOUSE_PRESSED: - UMA_HISTOGRAM_BOOLEAN("Event.Latency.OS_WIN_IS_VALID.MOUSE_PRESSED", - is_valid); - break; - case ET_TOUCH_PRESSED: - UMA_HISTOGRAM_BOOLEAN("Event.Latency.OS_WIN_IS_VALID.TOUCH_PRESSED", - is_valid); - break; - default: - // Caller should have filtered out unhandled events. - NOTREACHED(); - break; - } - if (!is_valid) - return; - - const base::TimeDelta delta = current_time - event_time; - - if (base::TimeTicks::IsHighResolution()) { - UMA_HISTOGRAM_WIN_EVENT_LATENCY_TIMES("Event.Latency.OS_WIN.HIGH_RES", - delta); - switch (event_type) { - case ET_KEY_PRESSED: - UMA_HISTOGRAM_WIN_EVENT_LATENCY_TIMES( - "Event.Latency.OS_WIN.HIGH_RES.KEY_PRESSED", delta); - break; - case ET_MOUSE_PRESSED: - UMA_HISTOGRAM_WIN_EVENT_LATENCY_TIMES( - "Event.Latency.OS_WIN.HIGH_RES.MOUSE_PRESSED", delta); - break; - case ET_TOUCH_PRESSED: - UMA_HISTOGRAM_WIN_EVENT_LATENCY_TIMES( - "Event.Latency.OS_WIN.HIGH_RES.TOUCH_PRESSED", delta); - break; - default: - // Caller should have filtered out unhandled events. - NOTREACHED(); - break; - } - } else { - UMA_HISTOGRAM_WIN_EVENT_LATENCY_TIMES("Event.Latency.OS_WIN.LOW_RES", - delta); - switch (event_type) { - case ET_KEY_PRESSED: - UMA_HISTOGRAM_WIN_EVENT_LATENCY_TIMES( - "Event.Latency.OS_WIN.LOW_RES.KEY_PRESSED", delta); - break; - case ET_MOUSE_PRESSED: - UMA_HISTOGRAM_WIN_EVENT_LATENCY_TIMES( - "Event.Latency.OS_WIN.LOW_RES.MOUSE_PRESSED", delta); - break; - case ET_TOUCH_PRESSED: - UMA_HISTOGRAM_WIN_EVENT_LATENCY_TIMES( - "Event.Latency.OS_WIN.LOW_RES.TOUCH_PRESSED", delta); - break; - default: - // Caller should have filtered out unhandled events. - NOTREACHED(); - break; - } - } -} - -#endif // OS_WIN + base::TimeDelta::FromMinutes(1), 50) } // namespace @@ -190,86 +95,22 @@ display::Display::TouchSupport GetInternalDisplayTouchSupport() { return display::Display::TouchSupport::UNAVAILABLE; } -#if defined(OS_WIN) -void SetEventLatencyTickClockForTesting(const base::TickClock* clock) { - g_tick_count_clock = clock; -} - -void ComputeEventLatencyOSWinFromTickCount(ui::EventType event_type, - DWORD event_time, - base::TimeTicks current_time) { - static const base::NoDestructor default_tick_count_clock; - if (!g_tick_count_clock) - g_tick_count_clock = default_tick_count_clock.get(); - - if (event_type != ET_KEY_PRESSED && event_type != ET_MOUSE_PRESSED && - event_type != ET_TOUCH_PRESSED) { - // Only log this metric for events that indicate strong user intent (eg. - // clicks and keypresses), not every move event. This will detect jank that - // causes the most user pain. - return; - } - - base::TimeTicks current_tick_count = g_tick_count_clock->NowTicks(); +void ComputeEventLatencyOS(const PlatformEvent& native_event) { + base::TimeTicks current_time = EventTimeForNow(); base::TimeTicks time_stamp = - base::TimeTicks() + base::TimeDelta::FromMilliseconds(event_time); - // Check if the 32-bit tick count wrapped around after the event. - if (current_tick_count < time_stamp) { - // ::GetTickCount returns an unsigned 32-bit value, which will fit into the - // signed 64-bit base::TimeTicks. - current_tick_count += - base::TimeDelta::FromMilliseconds(std::numeric_limits::max()); - } - - // |event_time| is from the GetTickCount clock, which has a different 0-point - // from |current_time| (which uses either the high-resolution timer or - // timeGetTime). Adjust it to be compatible. - // - // This offset will vary by up to ~16 msec because it depends on when exactly - // we sample the high-resolution clock. It would be more consistent to - // calculate one offset at the start of the program and apply it every time, - // but that consistency isn't needed for jank investigations and then we - // would have to adjust for clock drift. - const base::TimeDelta time_source_offset = current_time - current_tick_count; - time_stamp += time_source_offset; - - ComputeEventLatencyOSWin(event_type, time_stamp, current_time); -} - -void ComputeEventLatencyOSWinFromPerformanceCounter( - ui::EventType event_type, - UINT64 event_time, - base::TimeTicks current_time) { - if (event_type != ET_TOUCH_PRESSED) { - // Only log this metric for events that indicate strong user intent (ie. - // touch press), not every touch move event. This will detect jank that - // causes the most user pain. - return; - } - if (!base::TimeTicks::IsHighResolution()) { - // The tick clock will be incompatible with |event_time|. - return; - } - ComputeEventLatencyOSWin( - event_type, base::TimeTicks::FromQPCValue(event_time), current_time); + EventLatencyTimeFromNative(native_event, current_time); + EventType type = EventTypeFromNative(native_event); + ComputeEventLatencyOS(type, time_stamp, current_time); } -#endif -void ComputeEventLatencyOS(const PlatformEvent& native_event) { - base::TimeTicks current_time = EventTimeForNow(); - base::TimeTicks time_stamp = EventTimeFromNative(native_event); +void ComputeEventLatencyOS(EventType type, + base::TimeTicks time_stamp, + base::TimeTicks current_time) { base::TimeDelta delta = current_time - time_stamp; - EventType type = EventTypeFromNative(native_event); -#if defined(OS_WIN) - // Also record windows-only metrics. - // - // On Windows EventTimeFromNative returns the current time instead of the - // timestamp from |native_event|, which makes it useless for latency metrics, - // so retrieve the time stamp directly. - ComputeEventLatencyOSWinFromTickCount(type, native_event.time, current_time); -#endif - + // TODO(crbug.com/1189656): Remove the legacy Event.Latency.OS.* histograms + // after M92 (which introduced Event.Latency.OS2.*) has been replaced in the + // stable channel. switch (type) { #if defined(OS_APPLE) // On Mac, ET_SCROLL and ET_MOUSEWHEEL represent the same class of events. @@ -279,42 +120,86 @@ void ComputeEventLatencyOS(const PlatformEvent& native_event) { UMA_HISTOGRAM_CUSTOM_COUNTS( "Event.Latency.OS.MOUSE_WHEEL", base::saturated_cast(delta.InMicroseconds()), 1, 1000000, 50); + UMA_HISTOGRAM_EVENT_LATENCY_TIMES("Event.Latency.OS2.MOUSE_WHEEL", delta); return; case ET_TOUCH_MOVED: UMA_HISTOGRAM_CUSTOM_COUNTS( "Event.Latency.OS.TOUCH_MOVED", base::saturated_cast(delta.InMicroseconds()), 1, 1000000, 50); + UMA_HISTOGRAM_EVENT_LATENCY_TIMES("Event.Latency.OS2.TOUCH_MOVED", delta); return; case ET_TOUCH_PRESSED: UMA_HISTOGRAM_CUSTOM_COUNTS( "Event.Latency.OS.TOUCH_PRESSED", base::saturated_cast(delta.InMicroseconds()), 1, 1000000, 50); + UMA_HISTOGRAM_EVENT_LATENCY_TIMES("Event.Latency.OS2.TOUCH_PRESSED", + delta); return; case ET_TOUCH_RELEASED: UMA_HISTOGRAM_CUSTOM_COUNTS( "Event.Latency.OS.TOUCH_RELEASED", base::saturated_cast(delta.InMicroseconds()), 1, 1000000, 50); + UMA_HISTOGRAM_EVENT_LATENCY_TIMES("Event.Latency.OS2.TOUCH_RELEASED", + delta); return; case ET_TOUCH_CANCELLED: UMA_HISTOGRAM_CUSTOM_COUNTS( "Event.Latency.OS.TOUCH_CANCELLED", base::saturated_cast(delta.InMicroseconds()), 1, 1000000, 50); + UMA_HISTOGRAM_EVENT_LATENCY_TIMES("Event.Latency.OS2.TOUCH_CANCELLED", + delta); return; case ET_KEY_PRESSED: UMA_HISTOGRAM_CUSTOM_COUNTS( "Event.Latency.OS.KEY_PRESSED", base::saturated_cast(delta.InMicroseconds()), 1, 1000000, 50); + UMA_HISTOGRAM_EVENT_LATENCY_TIMES("Event.Latency.OS2.KEY_PRESSED", delta); return; case ET_MOUSE_PRESSED: UMA_HISTOGRAM_CUSTOM_COUNTS( "Event.Latency.OS.MOUSE_PRESSED", base::saturated_cast(delta.InMicroseconds()), 1, 1000000, 50); + UMA_HISTOGRAM_EVENT_LATENCY_TIMES("Event.Latency.OS2.MOUSE_PRESSED", + delta); return; default: return; } } +#if defined(OS_WIN) + +void ComputeEventLatencyOSFromTOUCHINPUT(EventType event_type, + TOUCHINPUT touch_input, + base::TimeTicks current_time) { + base::TimeTicks time_stamp = + EventLatencyTimeFromTickClock(touch_input.dwTime, current_time); + ComputeEventLatencyOS(event_type, time_stamp, current_time); +} + +void ComputeEventLatencyOSFromPOINTER_INFO(EventType event_type, + POINTER_INFO pointer_info, + base::TimeTicks current_time) { + base::TimeTicks time_stamp; + if (pointer_info.PerformanceCount) { + if (!base::TimeTicks::IsHighResolution()) { + // The tick clock will be incompatible with |event_time|. + return; + } + time_stamp = + EventLatencyTimeFromPerformanceCounter(pointer_info.PerformanceCount); + } else if (pointer_info.dwTime) { + time_stamp = + EventLatencyTimeFromTickClock(pointer_info.dwTime, current_time); + } else { + // Bad POINTER_INFO with no timestamp. + return; + } + ComputeEventLatencyOS(event_type, time_stamp, current_time); +} + +#endif // defined(OS_WIN) + void ConvertEventLocationToTargetWindowLocation( const gfx::Point& target_window_origin, const gfx::Point& current_window_origin, diff --git a/ui/events/event_utils.h b/ui/events/event_utils.h index e60e7d58cbac05..10311a01e5773b 100644 --- a/ui/events/event_utils.h +++ b/ui/events/event_utils.h @@ -33,7 +33,6 @@ class Vector2d; } // namespace gfx namespace base { -class TickClock; class TimeTicks; } @@ -87,6 +86,15 @@ EVENTS_EXPORT int EventFlagsFromNative(const PlatformEvent& native_event); EVENTS_EXPORT base::TimeTicks EventTimeFromNative( const PlatformEvent& native_event); +// Get the timestamp to use for latency metrics from |native_event|. +// |current_time| is a timestamp returned by EventTimeForNow which will be +// compared to the |native_event| timestamp to calculate latency. This is +// different from EventTimeFromNative because on some platforms (eg. Windows) +// EventTimeFromNative returns a synthesized timestamp. +EVENTS_EXPORT base::TimeTicks EventLatencyTimeFromNative( + const PlatformEvent& native_event, + base::TimeTicks current_time); + // Get the location from a native event. The coordinate system of the resultant // |Point| has the origin at top-left of the "root window". The nature of // this "root window" and how it maps to platform-specific drawing surfaces is @@ -169,25 +177,23 @@ EVENTS_EXPORT display::Display::TouchSupport GetInternalDisplayTouchSupport(); EVENTS_EXPORT void ComputeEventLatencyOS(const PlatformEvent& native_event); +EVENTS_EXPORT void ComputeEventLatencyOS(ui::EventType type, + base::TimeTicks time_stamp, + base::TimeTicks current_time); + #if defined(OS_WIN) -// Makes ComputeEventLatencyOSWinFromTickCount call the given |clock| to find -// the current time ticks to compare to an MSG timestamp. If |clock| is nullptr, -// it will call ::GetTickCount, which is the default. -EVENTS_EXPORT void SetEventLatencyTickClockForTesting( - const base::TickClock* clock); - -// Records Event.Latency.OS_WIN.* metrics for events whose timestamp comes from -// ::GetTickCount (such as an MSG). -EVENTS_EXPORT void ComputeEventLatencyOSWinFromTickCount( +// Like ComputeEventLatencyOS, but for events whose timestamp comes from a +// TOUCHINPUT structure instead of PlatformEvent. +EVENTS_EXPORT void ComputeEventLatencyOSFromTOUCHINPUT( ui::EventType event_type, - DWORD event_time, + TOUCHINPUT touch_input, base::TimeTicks current_time); -// Records Event.Latency.OS_WIN.* metrics for events whose timestamp comes from -// a Performance Counter (such as POINTER_INFO). -EVENTS_EXPORT void ComputeEventLatencyOSWinFromPerformanceCounter( +// Like ComputeEventLatencyOS, but for events whose timestamp comes from a +// POINTER_INFO structure instead of PlatformEvent. +EVENTS_EXPORT void ComputeEventLatencyOSFromPOINTER_INFO( ui::EventType event_type, - UINT64 event_time, + POINTER_INFO pointer_info, base::TimeTicks current_time); EVENTS_EXPORT int GetModifiersFromKeyState(); diff --git a/ui/events/events_default.cc b/ui/events/events_default.cc index e48fc5ca90ff82..aed4891fb07e19 100644 --- a/ui/events/events_default.cc +++ b/ui/events/events_default.cc @@ -15,6 +15,11 @@ base::TimeTicks EventTimeFromNative(const PlatformEvent& native_event) { return event->time_stamp(); } +base::TimeTicks EventLatencyTimeFromNative(const PlatformEvent& native_event, + base::TimeTicks current_time) { + return EventTimeFromNative(native_event); +} + int EventFlagsFromNative(const PlatformEvent& native_event) { const ui::Event* event = static_cast(native_event); return event->flags(); diff --git a/ui/events/events_stub.cc b/ui/events/events_stub.cc index 710c38411dd33d..badd355fab5e99 100644 --- a/ui/events/events_stub.cc +++ b/ui/events/events_stub.cc @@ -32,6 +32,11 @@ base::TimeTicks EventTimeFromNative(const PlatformEvent& native_event) { return base::TimeTicks(); } +base::TimeTicks EventLatencyTimeFromNative(const PlatformEvent& native_event, + base::TimeTicks current_time) { + return EventTimeFromNative(native_event); +} + gfx::PointF EventLocationFromNative(const PlatformEvent& native_event) { NOTIMPLEMENTED(); return gfx::PointF(); diff --git a/ui/events/win/events_win.cc b/ui/events/win/events_win.cc index 18a361f6219a5c..e65cb88c50e43e 100644 --- a/ui/events/win/events_win.cc +++ b/ui/events/win/events_win.cc @@ -17,9 +17,19 @@ int EventFlagsFromNative(const MSG& native_event) { } base::TimeTicks EventTimeFromNative(const MSG& native_event) { + // Note EventTimeFromMSG actually returns a time based on the current clock + // tick, ignoring MSG. See the comments in that function (which is in + // events_win_utils.cc) for the reason. return EventTimeFromMSG(native_event); } +base::TimeTicks EventLatencyTimeFromNative(const MSG& native_event, + base::TimeTicks current_time) { + // For latency calculations use the real timestamp, rather than the one + // returned from EventTimeFromMSG. + return EventLatencyTimeFromTickClock(native_event.time, current_time); +} + gfx::PointF EventLocationFromNative(const MSG& native_event) { return gfx::PointF(EventLocationFromMSG(native_event)); } diff --git a/ui/events/win/events_win_utils.cc b/ui/events/win/events_win_utils.cc index 655e113dd4edc9..ce5b9011d3b943 100644 --- a/ui/events/win/events_win_utils.cc +++ b/ui/events/win/events_win_utils.cc @@ -5,9 +5,12 @@ #include #include "base/check.h" +#include "base/no_destructor.h" #include "base/notreached.h" +#include "base/time/tick_clock.h" #include "base/time/time.h" #include "base/win/windowsx_shim.h" +#include "ui/events/base_event_utils.h" #include "ui/events/event_constants.h" #include "ui/events/event_utils.h" #include "ui/events/keycodes/dom/keycode_converter.h" @@ -153,6 +156,19 @@ int MouseStateFlags(const MSG& native_event) { return flags; } +class GetTickCountClock : public base::TickClock { + public: + GetTickCountClock() = default; + ~GetTickCountClock() override = default; + + base::TimeTicks NowTicks() const override { + return base::TimeTicks() + + base::TimeDelta::FromMilliseconds(::GetTickCount()); + } +}; + +const base::TickClock* g_tick_count_clock = nullptr; + } // namespace EventType EventTypeFromMSG(const MSG& native_event) { @@ -242,6 +258,47 @@ base::TimeTicks EventTimeFromMSG(const MSG& native_event) { return EventTimeForNow(); } +base::TimeTicks EventLatencyTimeFromTickClock(DWORD event_time, + base::TimeTicks current_time) { + static const base::NoDestructor default_tick_count_clock; + if (!g_tick_count_clock) + g_tick_count_clock = default_tick_count_clock.get(); + + base::TimeTicks time_stamp = + base::TimeTicks() + base::TimeDelta::FromMilliseconds(event_time); + + base::TimeTicks current_tick_count = g_tick_count_clock->NowTicks(); + // Check if the 32-bit tick count wrapped around after the event. + if (current_tick_count < time_stamp) { + // ::GetTickCount returns an unsigned 32-bit value, which will fit into the + // signed 64-bit base::TimeTicks. + current_tick_count += + base::TimeDelta::FromMilliseconds(std::numeric_limits::max()); + } + + // |time_stamp| is from the GetTickCount clock, which has a different 0-point + // from |current_time| (which uses either the high-resolution timer or + // timeGetTime). Adjust it to be compatible. + // + // This offset will vary by up to ~16 msec because it depends on when exactly + // we sample the high-resolution clock. It would be more consistent to + // calculate one offset at the start of the program and apply it every time, + // but that consistency isn't needed for jank investigations and then we + // would have to adjust for clock drift. + const base::TimeDelta time_source_offset = current_time - current_tick_count; + time_stamp += time_source_offset; + + ValidateEventTimeClock(&time_stamp); + return time_stamp; +} + +base::TimeTicks EventLatencyTimeFromPerformanceCounter(UINT64 event_time) { + DCHECK(base::TimeTicks::IsHighResolution()); + base::TimeTicks time_stamp = base::TimeTicks::FromQPCValue(event_time); + ValidateEventTimeClock(&time_stamp); + return time_stamp; +} + gfx::Point EventLocationFromMSG(const MSG& native_event) { // This code may use GetCursorPos() to get a mouse location. This may // fail in certain situations (see @@ -493,4 +550,8 @@ MouseWheelEvent MouseWheelEventFromMSG(const MSG& msg) { changed_button_flags); } +void SetEventLatencyTickClockForTesting(const base::TickClock* clock) { + g_tick_count_clock = clock; +} + } // namespace ui diff --git a/ui/events/win/events_win_utils.h b/ui/events/win/events_win_utils.h index 8aaa07f36343a0..4fb1550639f504 100644 --- a/ui/events/win/events_win_utils.h +++ b/ui/events/win/events_win_utils.h @@ -25,6 +25,7 @@ class Vector2d; } // namespace gfx namespace base { +class TickClock; class TimeTicks; } @@ -44,6 +45,22 @@ EVENTS_EXPORT int EventFlagsFromMSG(const MSG& native_event); // same native event may return different values. EVENTS_EXPORT base::TimeTicks EventTimeFromMSG(const MSG& native_event); +// Convert |event_time|, a count of milliseconds from the clock used by +// ::GetTickCount(), to a value comparable to the base::TimeTicks clock. +// |current_time| is a value returned in the recent past by EventTimeForNow, +// which will be compared to the current result of ::GetTickCount() for +// calibration. +EVENTS_EXPORT base::TimeTicks EventLatencyTimeFromTickClock( + DWORD event_time, + base::TimeTicks current_time); + +// Convert |event_time|, a timestamp from the clock used by +// ::QueryPerformanceCounter(), to a value comparable to the base::TimeTicks +// clock. Must not be called if base::TimeTicks::IsHighResolution() returns +// false. +EVENTS_EXPORT base::TimeTicks EventLatencyTimeFromPerformanceCounter( + UINT64 event_time); + // Get the location from a native event. The coordinate system of the resultant // |Point| has the origin at top-left of the "root window". The nature of // this "root window" and how it maps to platform-specific drawing surfaces is @@ -101,6 +118,12 @@ EVENTS_EXPORT bool GetFlingData(const MSG& native_event, // scrolled. EVENTS_EXPORT bool GetScrollOffsetsFromMSG(const MSG& native_event); +// Makes EventLatencyTimeFromTickClock call the given |clock| to find the +// current time ticks. If |clock| is nullptr, it will call ::GetTickCount(), +// which is the default. +EVENTS_EXPORT void SetEventLatencyTickClockForTesting( + const base::TickClock* clock); + } // namespace ui #endif // UI_EVENTS_WIN_EVENTS_WIN_UTILS_H_ diff --git a/ui/platform_window/x11/test/events_x_unittest.cc b/ui/platform_window/x11/test/events_x_unittest.cc index 817c3e87262ba2..15b886989fdb8f 100644 --- a/ui/platform_window/x11/test/events_x_unittest.cc +++ b/ui/platform_window/x11/test/events_x_unittest.cc @@ -763,7 +763,7 @@ TEST_F(EventsXTest, AutoRepeat) { } } -// Checks that Event.Latency.OS.TOUCH_PRESSED, TOUCH_MOVED, +// Checks that Event.Latency.OS2.TOUCH_PRESSED, TOUCH_MOVED, // and TOUCH_RELEASED histograms are computed properly. TEST_F(EventsXTest, EventLatencyOSTouchHistograms) { base::HistogramTester histogram_tester; @@ -780,14 +780,17 @@ TEST_F(EventsXTest, EventLatencyOSTouchHistograms) { gfx::Point(10, 10), {}); auto touch_begin = ui::BuildTouchEventFromXEvent(*scoped_xevent); histogram_tester.ExpectTotalCount("Event.Latency.OS.TOUCH_PRESSED", 1); + histogram_tester.ExpectTotalCount("Event.Latency.OS2.TOUCH_PRESSED", 1); scoped_xevent.InitTouchEvent(0, x11::Input::DeviceEvent::TouchUpdate, 5, gfx::Point(20, 20), {}); auto touch_update = ui::BuildTouchEventFromXEvent(*scoped_xevent); histogram_tester.ExpectTotalCount("Event.Latency.OS.TOUCH_MOVED", 1); + histogram_tester.ExpectTotalCount("Event.Latency.OS2.TOUCH_MOVED", 1); scoped_xevent.InitTouchEvent(0, x11::Input::DeviceEvent::TouchEnd, 5, gfx::Point(30, 30), {}); auto touch_end = ui::BuildTouchEventFromXEvent(*scoped_xevent); histogram_tester.ExpectTotalCount("Event.Latency.OS.TOUCH_RELEASED", 1); + histogram_tester.ExpectTotalCount("Event.Latency.OS2.TOUCH_RELEASED", 1); } TEST_F(EventsXTest, EventLatencyOSMouseWheelHistogram) { @@ -802,6 +805,7 @@ TEST_F(EventsXTest, EventLatencyOSMouseWheelHistogram) { }); auto mouse_ev = ui::BuildMouseWheelEventFromXEvent(native_event); histogram_tester.ExpectTotalCount("Event.Latency.OS.MOUSE_WHEEL", 1); + histogram_tester.ExpectTotalCount("Event.Latency.OS2.MOUSE_WHEEL", 1); } } // namespace ui diff --git a/ui/views/win/hwnd_message_handler.cc b/ui/views/win/hwnd_message_handler.cc index 91dd04b117e161..2d64e8ab2bf174 100644 --- a/ui/views/win/hwnd_message_handler.cc +++ b/ui/views/win/hwnd_message_handler.cc @@ -2730,8 +2730,8 @@ LRESULT HWNDMessageHandler::OnTouchEvent(UINT message, touch_ids_.insert(input[i].dwID); GenerateTouchEvent(ui::ET_TOUCH_PRESSED, touch_point, touch_id, event_time, &touch_events); - ui::ComputeEventLatencyOSWinFromTickCount(ui::ET_TOUCH_PRESSED, - input[i].dwTime, event_time); + ui::ComputeEventLatencyOSFromTOUCHINPUT(ui::ET_TOUCH_PRESSED, input[i], + event_time); touch_down_contexts_++; base::ThreadTaskRunnerHandle::Get()->PostDelayedTask( FROM_HERE, @@ -2742,16 +2742,16 @@ LRESULT HWNDMessageHandler::OnTouchEvent(UINT message, if (input[i].dwFlags & TOUCHEVENTF_MOVE) { GenerateTouchEvent(ui::ET_TOUCH_MOVED, touch_point, touch_id, event_time, &touch_events); - ui::ComputeEventLatencyOSWinFromTickCount( - ui::ET_TOUCH_MOVED, input[i].dwTime, event_time); + ui::ComputeEventLatencyOSFromTOUCHINPUT(ui::ET_TOUCH_MOVED, input[i], + event_time); } if (input[i].dwFlags & TOUCHEVENTF_UP) { touch_ids_.erase(input[i].dwID); GenerateTouchEvent(ui::ET_TOUCH_RELEASED, touch_point, touch_id, event_time, &touch_events); - ui::ComputeEventLatencyOSWinFromTickCount( - ui::ET_TOUCH_RELEASED, input[i].dwTime, event_time); + ui::ComputeEventLatencyOSFromTOUCHINPUT(ui::ET_TOUCH_RELEASED, + input[i], event_time); id_generator_.ReleaseNumber(input[i].dwID); } } @@ -3245,14 +3245,8 @@ LRESULT HWNDMessageHandler::HandlePointerEventTypeTouchOrNonClient( ui::PointerDetails(ui::EventPointerType::kTouch, mapped_pointer_id, radius_x, radius_y, pressure, rotation_angle), ui::GetModifiersFromKeyState()); - if (pointer_info.PerformanceCount) { - ui::ComputeEventLatencyOSWinFromPerformanceCounter( - event_type, pointer_info.PerformanceCount, event_time); - } else { - ui::ComputeEventLatencyOSWinFromTickCount(event_type, pointer_info.dwTime, - event_time); - } - + ui::ComputeEventLatencyOSFromPOINTER_INFO(event_type, pointer_info, + event_time); event.latency()->AddLatencyNumberWithTimestamp( ui::INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT, event_time); diff --git a/ui/views/win/pen_event_processor.cc b/ui/views/win/pen_event_processor.cc index 3f0bb80262a212..7257458f79a4a1 100644 --- a/ui/views/win/pen_event_processor.cc +++ b/ui/views/win/pen_event_processor.cc @@ -201,13 +201,8 @@ std::unique_ptr PenEventProcessor::GenerateTouchEvent( std::unique_ptr event = std::make_unique( event_type, point, event_time, pointer_details, flags | ui::GetModifiersFromKeyState()); - if (pointer_info.PerformanceCount) { - ui::ComputeEventLatencyOSWinFromPerformanceCounter( - event_type, pointer_info.PerformanceCount, event_time); - } else { - ui::ComputeEventLatencyOSWinFromTickCount(event_type, pointer_info.dwTime, - event_time); - } + ui::ComputeEventLatencyOSFromPOINTER_INFO(event_type, pointer_info, + event_time); event->set_hovering(event_type == ui::ET_TOUCH_RELEASED); event->latency()->AddLatencyNumberWithTimestamp( ui::INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT, event_time);