ast/events/hr-timestamp/input-events.html is flaky |
||||
Issue descriptionhttps://test-results.appspot.com/dashboards/flakiness_dashboard.html#testType=webkit_layout_tests&tests=fast%2Fevents%2Fhr-timestamp There are at least two issues: a) FAILURE which happens on all platforms b) TIMEOUT which seems to be limited to Mac.
,
May 25 2018
Case A seems to be due to changes in behavior of how we clamp time values in blink. The clamping logic was revamped recently. Previously we were clamping to 5us but we are now clamping to 100us with some additional psuedorandom jitter. [1] introduced the change and updates the test however I think the news clamping logic can introduce up to 200us difference for event time stamp. [1] https://chromium-review.googlesource.com/c/chromium/src/+/849993/4/third_party/WebKit/Source/core/timing/PerformanceBase.cpp I think the 200us max clamping difference is related to a change in how we clamp time values that need to be relative to time origin. The new logic clamps both the time origin and time value before computing the difference while the old logic computed the difference first and then clamped once. simplified old logic: double clamped_time_in_seconds = ClampTimeResolution(monotonic_time - time_origin); simplified new logic: double clamped_time_in_seconds = ClampTimeResolution(TimeTicksInSeconds(monotonic_time)) - ClampTimeResolution(TimeTicksInSeconds(time_origin)); I think dpending on the random jitter applied, the new logic can lead to clamped version to be different by 200us from original unclamped version. The test was only updated assuming a 100us max difference which is why it is failing occasionally. There are two possible simple fixes: 1. Update the test to reflect this change by having it expect a 200us clamp difference. 2. Change clamping logic to be similar to the old version. I assume we want 1 since the chance in [1] was intentional. skyostil@ wdyt? Example of case A: https://test-results.appspot.com/data/layout_results/WebKit_Linux_Trusty/45532/layout-test-results/results.html Output: PASS Event timestamp should be equal to the timestamp provided by the platform for mousedown FAIL Event timestamp should be equal to the timestamp provided by the platform for keydown assert_approx_equals: expected 29.200000000000003 +/- 0.100001 but got 29.399999999441206 PASS Event timestamp should be equal to the timestamp provided by the platform for touchstart FAIL Event timestamp should be equal to the timestamp provided by the platform for click assert_approx_equals: expected 31.200000000000003 +/- 0.100001 but got 31.39999999984866 PASS Event timestamp should be equal to the timestamp provided by the platform for contextmenu PASS Event timestamp should be equal to the timestamp provided by the platform for wheel
,
May 29 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/4e103290aaecba63db670aead636ee8733e10e35 commit 4e103290aaecba63db670aead636ee8733e10e35 Author: Majid Valipour <majidvp@chromium.org> Date: Tue May 29 15:22:53 2018 Fix flakiness in hr-timestamp/input-events.html test Update the test to expect the difference between expected unclamped time with observed time to be at most 200us instead of 100us. A recent change [1] made it so that the clamping can lead to up to 200us of adjustment for when we are computing a time values that is relative to time origin. The new logic, first clamps both the time origin and time value and then computes their delta while the old logic computed the delta first and then clamped it once. ## simplified old logic double clamped_time_in_seconds = ClampTimeResolution(monotonic_time - time_origin); ## simplified new logic double clamped_time_in_seconds = ClampTimeResolution(TimeTicksInSeconds(monotonic_time)) - ClampTimeResolution(TimeTicksInSeconds(time_origin)); Flakiness dashboard link: https://test-results.appspot.com/dashboards/flakiness_dashboard.html#testType=webkit_layout_tests&tests=fast%2Fevents%2Fhr-timestamp [1] https://chromium-review.googlesource.com/c/chromium/src/+/849993/4/third_party/WebKit/Source/core/timing/PerformanceBase.cpp TEST= locally ran the test 1000 times which all passed. run-webkit-tests --repeat-each=1000 fast/events/hr-timestamp/input-events.html Bug: 846750, 810437 Change-Id: I69547484838c3b21bc3c15441baec287db0f5e8e Reviewed-on: https://chromium-review.googlesource.com/1072466 Commit-Queue: Majid Valipour <majidvp@chromium.org> Reviewed-by: Sami Kyöstilä <skyostil@chromium.org> Cr-Commit-Position: refs/heads/master@{#562430} [modify] https://crrev.com/4e103290aaecba63db670aead636ee8733e10e35/third_party/WebKit/LayoutTests/fast/events/hr-timestamp/input-events.html
,
Jun 12 2018
FWIW, I cannot reproduce the timeout locally on MacOS 10.13 High Sierra. I am using the following with both release and debug builds: ./third_party/blink/tools/run_web_tests.py -t default --repeat-each=100 --iterations=10 fast/events/hr-timestamp My suspicion is that sometimes the event generators do not result in expected event so the callback is never called for some event types which causes time out. I am not sure why that will be but if I can narrow this down to a specific event type then it may help.
,
Jun 13 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/583b8a18aaef8bb463193cec014b12c9fdb40879 commit 583b8a18aaef8bb463193cec014b12c9fdb40879 Author: Majid Valipour <majidvp@chromium.org> Date: Wed Jun 13 17:46:35 2018 Speculative fix for timeout flakiness of hr-timestamp/input-events.html Now call prevent default in event handler to ensure context menu does not show up which can potentially hijack other events. Added an explicit timeout to help produce more detailed picture when timeout happens and hopefully help us identify the root cause if the above fix is not working. Also updated expectation to only expect timeout on Mac. Bug: 846750, 846726 Change-Id: Ica117c5cd7eafc559c3e457af008d1a1043deff6 Reviewed-on: https://chromium-review.googlesource.com/1099039 Commit-Queue: Majid Valipour <majidvp@chromium.org> Reviewed-by: Navid Zolghadr <nzolghadr@chromium.org> Cr-Commit-Position: refs/heads/master@{#566891} [modify] https://crrev.com/583b8a18aaef8bb463193cec014b12c9fdb40879/third_party/WebKit/LayoutTests/TestExpectations [modify] https://crrev.com/583b8a18aaef8bb463193cec014b12c9fdb40879/third_party/WebKit/LayoutTests/fast/events/hr-timestamp/input-events.html
,
Jun 20 2018
,
Jun 20 2018
,
Jun 22 2018
Now I can see specific tests timing out. Here is a few examples: - https://test-results.appspot.com/data/layout_results/Mac10_12_Tests/13920/layout-test-results/results.html - https://test-results.appspot.com/data/layout_results/Mac10_12_Tests/13902/layout-test-results/results.html - https://test-results.appspot.com/data/layout_results/Mac10_13_Tests/3657/layout-test-results/results.html - https://test-results.appspot.com/data/layout_results/Mac10_10_Tests/33279/layout-test-results/results.html In every case the output looks like below. Thanks to the new logging I can see that the failure is caused by not receiving the expected click and wheel events. It so happens that these two are just before and after the contextmenu. I think this strongly suggests that on Mac we are still somehow showing the context menu which is absorbing the other two adjacent events. My next step is to move the contextmenu test to its own test and see if that fixes the issue. --- Typical output ---- PASS Event timestamp should be equal to the timestamp provided by the platform for mousedown PASS Event timestamp should be equal to the timestamp provided by the platform for keydown PASS Event timestamp should be equal to the timestamp provided by the platform for touchstart FAIL Event timestamp should be equal to the timestamp provided by the platform for click assert_unreached: timeout with received events: mousedown, keydown, touchstart, contextmenu Reached unreachable code PASS Event timestamp should be equal to the timestamp provided by the platform for contextmenu FAIL Event timestamp should be equal to the timestamp provided by the platform for wheel assert_unreached: timeout with received events: mousedown, keydown, touchstart, contextmenu Reached unreachable code
,
Jul 12
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/8696fc59786065ffc8a2e06f2db8f9e9ebc772a1 commit 8696fc59786065ffc8a2e06f2db8f9e9ebc772a1 Author: Majid Valipour <majidvp@chromium.org> Date: Thu Jul 12 15:46:20 2018 [testing] Move context menu ever timestamp test to a separate test ContextMenu interaction with other events is a suspected cause of flakiness of the original test. This CL is separating it from the rest as a potential fix. Bug: 846750 Change-Id: I3d452388be65984ca82238d55a938d7a273fcf3f Reviewed-on: https://chromium-review.googlesource.com/1134180 Reviewed-by: Navid Zolghadr <nzolghadr@chromium.org> Commit-Queue: Majid Valipour <majidvp@chromium.org> Cr-Commit-Position: refs/heads/master@{#574573} [add] https://crrev.com/8696fc59786065ffc8a2e06f2db8f9e9ebc772a1/third_party/WebKit/LayoutTests/fast/events/hr-timestamp/context-menu-event.html [modify] https://crrev.com/8696fc59786065ffc8a2e06f2db8f9e9ebc772a1/third_party/WebKit/LayoutTests/fast/events/hr-timestamp/input-events.html
,
Jul 31
So I still see timeouts in the dashboard. My next step is to make tests run in a sequence removing all possible avenue for potential interference. |
||||
►
Sign in to add a comment |
||||
Comment 1 by majidvp@chromium.org
, May 25 2018