| Summary: | [ iOS Debug] 3 editing/pasteboard/smart-paste-paragraph tests are flaky failing | ||||||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| Product: | WebKit | Reporter: | ayumi_kojima | ||||||||||||||
| Component: | New Bugs | Assignee: | Wenson Hsieh <wenson_hsieh> | ||||||||||||||
| Status: | RESOLVED FIXED | ||||||||||||||||
| Severity: | Normal | CC: | akeerthi, hi, megan_gardner, thorton, webkit-bot-watchers-bugzilla, webkit-bug-importer, wenson_hsieh | ||||||||||||||
| Priority: | P2 | Keywords: | InRadar | ||||||||||||||
| Version: | WebKit Nightly Build | ||||||||||||||||
| Hardware: | iPhone / iPad | ||||||||||||||||
| OS: | Unspecified | ||||||||||||||||
| Attachments: |
|
||||||||||||||||
|
Description
ayumi_kojima
2021-07-26 10:42:59 PDT
I was not able to reproduce on iOS 15 simulator on my local machine using: run-webkit-tests --debug --iphone-simulator -f --exit-after-n-failures 2 --exit-after-n-crashes-or-timeouts 2 --iterations 50 --no-build editing/pasteboard/smart-paste-paragraph-002.html Looks like the crash happened only on 7/18/21 - 7/19/21 and is not occurring repeatedly. Updated test expectations that were previously set here for iPhone Debug (https://bugs.webkit.org/show_bug.cgi?id=203264) :https://trac.webkit.org/changeset/280305/webkit (In reply to ayumi_kojima from comment #4) > Updated test expectations that were previously set here for iPhone Debug > (https://bugs.webkit.org/show_bug.cgi?id=203264) > :https://trac.webkit.org/changeset/280305/webkit These tests are failing on iOS simulator, too, so maybe we need to move the test expectations out of the iPad directory? Removed test expectations from iPad and updated ones in iOS-wk2. https://trac.webkit.org/changeset/280634/webkit > --- /Volumes/Data/worker/ios-simulator-14-debug-tests-wk2/build/layout-test-results/editing/pasteboard/smart-paste-paragraph-002-expected.txt > +++ /Volumes/Data/worker/ios-simulator-14-debug-tests-wk2/build/layout-test-results/editing/pasteboard/smart-paste-paragraph-002-actual.txt > @@ -2,8 +2,6 @@ > EDITING DELEGATE: webViewDidBeginEditing:WebViewDidBeginEditingNotification > EDITING DELEGATE: webViewDidChangeSelection:WebViewDidChangeSelectionNotification > EDITING DELEGATE: shouldChangeSelectedDOMRange:range from 0 of PRE > BODY > HTML > #document to 0 of PRE > BODY > HTML > #document toDOMRange:range from 0 of PRE > BODY > HTML > #document to 0 of PRE > BODY > HTML > #document affinity:NSSelectionAffinityDownstream stillSelecting:FALSE > -EDITING DELEGATE: shouldChangeSelectedDOMRange:range from 0 of PRE > BODY > HTML > #document to 0 of PRE > BODY > HTML > #document toDOMRange:range from 0 of #text > SPAN > PRE > BODY > HTML > #document to 4 of #text > SPAN > PRE > BODY > HTML > #document affinity:NSSelectionAffinityDownstream stillSelecting:FALSE > -EDITING DELEGATE: webViewDidChangeSelection:WebViewDidChangeSelectionNotification This failure output is consistent with what happens if you turn the synthesized double tap in `selectWordByDoubleTapOrClick` into just a single tap, like so: ``` diff --git a/LayoutTests/resources/ui-helper.js b/LayoutTests/resources/ui-helper.js index 1ebe1c78b8c1..0285d741910b 100644 --- a/LayoutTests/resources/ui-helper.js +++ b/LayoutTests/resources/ui-helper.js @@ -335,7 +335,7 @@ window.UIHelper = class UIHelper { const y = boundingRect.y + relativeY; if (this.isIOSFamily()) { await UIHelper.activateAndWaitForInputSessionAt(x, y); - await UIHelper.doubleTapAt(x, y); + await UIHelper.activateAt(x, y); // This is only here to deal with async/sync copy/paste calls, so // once <rdar://problem/16207002> is resolved, should be able to remove for faster tests. await new Promise(resolve => testRunner.runUIScript("uiController.uiScriptComplete()", resolve)); ``` This suggests that when these tests fail, they fail because `UIHelper.doubleTapAt` is, for some reason, only resulting in a single tap. Created attachment 435317 [details]
Try to repro
It looks like run-layout-tests-in-stress-mode reproduced this test failure right away:
> Regressions: Unexpected text-only failures (10)
> editing/pasteboard/aac-smart-paste-paragraph-003.html [ Failure ]
> editing/pasteboard/aae-smart-paste-paragraph-002.html [ Failure ]
> editing/pasteboard/aam-smart-paste-paragraph-002.html [ Failure ]
> editing/pasteboard/aao-smart-paste-paragraph-002.html [ Failure ]
> editing/pasteboard/aao-smart-paste-paragraph-003.html [ Failure ]
> editing/pasteboard/aau-smart-paste-paragraph-003.html [ Failure ]
> editing/pasteboard/aaw-smart-paste-paragraph-002.html [ Failure ]
> editing/pasteboard/abd-smart-paste-paragraph-002.html [ Failure ]
> editing/pasteboard/abg-smart-paste-paragraph-003.html [ Failure ]
> editing/pasteboard/abo-smart-paste-paragraph-004.html [ Failure ]
...but the actual test runner passed all 1500 tests without any flakes. Not sure what's going on here, but at least this reproduces consistently in some fashion. Should be able to investigate further with some logging...
Created attachment 435360 [details]
More logging
From the output in https://ews-build.webkit.org/#/builders/51/builds/18999/steps/18/logs/stdio, we can compare logging in both the failure case: > 13:16:40.312 1361 worker/4 worker/4 editing/pasteboard/aaa-smart-paste-paragraph-002-1.html output stderr lines: > 13:16:40.312 1361 worker/3 dom/html/level2/html/HTMLSelectElement02.html passed > > <WK>: Selecting word via double tap - focusing editable area > <WK>: -[WKContentView textInteractionGesture:OneFingerTap shouldBeginAtPoint:{13, 411}] => NO > <WK>: Selecting word via double tap - performing double tap > <WK>: -[WKContentView textInteractionGesture:OneFingerTap shouldBeginAtPoint:{13, 411}] => YES > <WK>: -[WKContentView changeSelectionWithGestureAt:{13, 411} withGesture:OneFingerTap withState:Ended withFlags:00] > <WK>: Extending selection to line. > <WK>: Triggering copy. > <WK>: Moving selection forward (1). > <WK>: Moving selection forward (2). > <WK>: Triggering paste. > > 13:16:40.348 1361 worker/4 "ruby --version" took 0.03s > 13:16:40.358 1361 worker/1 dom/xhtml/level2/html/HTMLMapElement01.xhtml passed > 13:16:40.397 1361 worker/3 dom/html/level2/html/HTMLSelectElement03.html passed > 13:16:40.438 1361 worker/1 dom/xhtml/level2/html/HTMLMapElement02.xhtml passed > 13:16:40.600 1361 worker/7 editing/execCommand/indent-partial-table.html passed > 13:16:40.682 1361 worker/7 editing/execCommand/indent-pre-list.html passed > 13:16:40.715 1361 worker/4 "ruby -I /Volumes/Data/worker/iOS-14-Simulator-WK2-Tests-EWS/build/Websites/bugs.webkit.org/PrettyPatch /Volumes/Data/worker/iOS-14-Simulator-WK2-Tests-EWS/build/Websites/bugs.webkit.org/PrettyPatch/prettify.rb /Volumes/Data/worker/iOS-14-Simulator-WK2-Tests-EWS/build/layout-test-results/editing/pasteboard/aaa-smart-paste-paragraph-002-1-diff.txt" took 0.36s > 13:16:40.717 1361 [5281/49625] editing/pasteboard/aaa-smart-paste-paragraph-002-1.html failed unexpectedly (text diff) ..as well as the success case: > 13:16:42.137 1361 worker/4 worker/4 editing/pasteboard/aaa-smart-paste-paragraph-002-2.html output stderr lines: > 13:16:42.137 1361 worker/4 2021-08-11 13:16:40.316 WebKitTestRunnerApp[3120:190151] PBItemCollectionServicer connection disconnected. > 13:16:42.138 1361 worker/2 editing/deleting/merge-at-end-of-document.html passed > > <WK>: -[WKContentView changeSelectionWithGestureAt:{13, 482} withGesture:OneFingerTap withState:Ended withFlags:00] > <WK>: Selecting word via double tap - focusing editable area > <WK>: -[WKContentView textInteractionGesture:OneFingerTap shouldBeginAtPoint:{13, 411}] => NO > <WK>: Selecting word via double tap - performing double tap > <WK>: -[WKContentView textInteractionGesture:OneFingerTap shouldBeginAtPoint:{13, 411.5}] => YES > <WK>: -[WKContentView changeSelectionWithGestureAt:{13, 411.5} withGesture:OneFingerTap withState:Ended withFlags:00] > <WK>: -[WKContentView selectTextWithGranularity:Word atPoint:{13, 411.5} completionHandler:0x7ffee4576ed8] > <WK>: Extending selection to line. > <WK>: Triggering copy. > <WK>: Moving selection forward (1). > <WK>: Moving selection forward (2). > <WK>: Triggering paste. > > 13:16:42.141 1361 worker/4 editing/pasteboard/aaa-smart-paste-paragraph-002-2.html passed This confirms the theory that the test is failing because the double-tap-to-select-word text interaction gesture isn't firing. Still unclear why this is the case, though Created attachment 435395 [details]
Collect more data
(In reply to Wenson Hsieh from comment #12) > Created attachment 435395 [details] > Collect more data I think I have a clearer picture of what's going on. Logging in the failure case: ``` <WK>: *** Running /Volumes/Data/worker/iOS-14-Simulator-WK2-Tests-EWS/build/LayoutTests/editing/pasteboard/as-smart-paste-paragraph-002.html *** <WK>: Selecting word via double tap - focusing editable area <WK>: Synthesizing touchDown (#1 of 1) at {13, 431} <WK>: Synthesizing touchUp (#1 of 1) at {13, 431} <WK>: ...requesting posinfo at {13, 411} <WK>: -[WKContentView textInteractionGesture:OneFingerTap shouldBeginAtPoint:{13, 411}] => NO <WK>: Selecting word via double tap - performing double tap <WK>: Synthesizing touchDown (#1 of 2) at {13, 335} <WK>: Synthesizing touchUp (#1 of 2) at {13, 335} <WK>: Synthesizing touchDown (#2 of 2) at {13, 335} <WK>: Synthesizing touchUp (#2 of 2) at {13, 335} <WK>: ...skipping sync posinfo update at {13, 411} <WK>: -[WKContentView textInteractionGesture:OneFingerTap shouldBeginAtPoint:{13, 411}] => YES <WK>: -[UIWKTextSelectionInteraction _handleMultiTapGesture:] with UITextMultiTapRecognizer (Began, at {13, 411}) <WK>: -[WKContentView changeSelectionWithGestureAt:{13, 411} withGesture:OneFingerTap withState:Ended withFlags:00] <WK>: -[UIWKTextSelectionInteraction _handleMultiTapGesture:] with UITextMultiTapRecognizer (Cancelled, at {13, 482}) <WK>: -[WKContentView changeSelectionWithGestureAt:{13, 482} withGesture:OneFingerTap withState:Ended withFlags:00] ``` ...vs. the success case: ``` <WK>: *** Running /Volumes/Data/worker/iOS-14-Simulator-WK2-Tests-EWS/build/LayoutTests/editing/pasteboard/cc-smart-paste-paragraph-002.html *** <WK>: Selecting word via double tap - focusing editable area <WK>: Synthesizing touchDown (#1 of 1) at {13, 431} <WK>: Synthesizing touchUp (#1 of 1) at {13, 431} <WK>: ...requesting posinfo at {13, 411} <WK>: -[WKContentView textInteractionGesture:OneFingerTap shouldBeginAtPoint:{13, 411}] => NO <WK>: Selecting word via double tap - performing double tap <WK>: Synthesizing touchDown (#1 of 2) at {13, 131.5} <WK>: Synthesizing touchUp (#1 of 2) at {13, 131.5} <WK>: Synthesizing touchDown (#2 of 2) at {13, 131.5} <WK>: Synthesizing touchUp (#2 of 2) at {13, 131.5} <WK>: ...requesting posinfo at {13, 412} <WK>: -[WKContentView textInteractionGesture:OneFingerTap shouldBeginAtPoint:{13, 411.5}] => YES <WK>: -[UIWKTextSelectionInteraction _handleMultiTapGesture:] with UITextMultiTapRecognizer (Began, at {13, 411.5}) <WK>: -[WKContentView changeSelectionWithGestureAt:{13, 411.5} withGesture:OneFingerTap withState:Ended withFlags:00] <WK>: ...requesting posinfo at {13, 411} <WK>: ...skipping sync posinfo update at {13, 412} <WK>: -[UIWKTextSelectionInteraction _handleMultiTapGesture:] with UITextMultiTapRecognizer (Changed, at {13, 411.5}) <WK>: -[WKContentView selectTextWithGranularity:Word atPoint:{13, 411.5} completionHandler:0x7ffee4e28f58] ``` When this test fails, UITextMultiTapRecognizer (a part of the internal UIWKTextSelectionInteraction) transitions to Cancelled state instead of Changed state because it thinks the second touch location is (13, 482) instead of (13, 411), where the first touch is. I wonder why the touch location is translated to 482 instead of 411.. Not sure if this is related, but in the case where this test passes, something really strange happens — it would appear that we're trying to synthesize the double-tap while we're still scrolling as a result of bringing up the keyboard. As a result, we (or UIKit?) ends up mapping the touch location to (13, 411.5) in WKContentView coordinates instead of (13, 411). This rounds up to (13, 412) when we're trying to hit-test with a sync position information request, which means we don't immediately return with a cached result. Maybe there's stale data in the position information in the failure case? (In reply to Wenson Hsieh from comment #13) > > When this test fails, UITextMultiTapRecognizer (a part of the internal > UIWKTextSelectionInteraction) transitions to Cancelled state instead of > Changed state because it thinks the second touch location is (13, 482) > instead of (13, 411), where the first touch is. I wonder why the touch > location is translated to 482 instead of 411.. On that note, it doesn't make any sense to me that the software keyboard is coming up in this test since we're supposed to be simulating the hardware keyboard being always attached (some tests explicitly toggle this in order to test the software keyboard, but these failing smart paste tests don't do that). Putting a backtrace in UIKeyboardWillChangeFrameNotification, I can see what's causing us to try and present the software keyboard anyways: > Keyboard will change frame: { > UIKeyboardAnimationCurveUserInfoKey = 7; > UIKeyboardAnimationDurationUserInfoKey = "0.25"; > UIKeyboardBoundsUserInfoKey = "NSRect: {{0, 0}, {320, 260}}"; > UIKeyboardCenterBeginUserInfoKey = "NSPoint: {160, 546}"; > UIKeyboardCenterEndUserInfoKey = "NSPoint: {160, 438}"; > UIKeyboardFrameBeginUserInfoKey = "NSRect: {{0, 524}, {320, 44}}"; > UIKeyboardFrameEndUserInfoKey = "NSRect: {{0, 308}, {320, 260}}"; > UIKeyboardIsLocalUserInfoKey = 1; > } > 1 0x10c9edf7d WTR::handleKeyboardWillChangeFrameNotification(__CFNotificationCenter*, void*, __CFString const*, void const*, __CFDictionary const*) > 2 0x129b67882 __CFNOTIFICATIONCENTER_IS_CALLING_OUT_TO_AN_OBSERVER__ > 3 0x129b67851 ___CFXRegistrationPost_block_invoke > 4 0x129b66f81 _CFXRegistrationPost > 5 0x129b668ef _CFXNotificationPost > 6 0x129349027 -[NSNotificationCenter postNotificationName:object:userInfo:] > 7 0x155705730 __68-[UIInputWindowController postValidatedStartNotifications:withInfo:]_block_invoke > 8 0x155705327 -[UIInputWindowController postValidatedStartNotifications:withInfo:] > 9 0x155708a5e __77-[UIInputWindowController moveFromPlacement:toPlacement:starting:completion:]_block_invoke.879 > 10 0x155eba3a8 +[UIView _setupAnimationWithDuration:delay:view:options:factory:animations:start:animationStateGenerator:completion:] > 11 0x155eba6ef +[UIView(UIViewAnimationWithBlocks) _animateWithDuration:delay:options:animations:start:completion:] > 12 0x155709786 __77-[UIInputWindowController moveFromPlacement:toPlacement:starting:completion:]_block_invoke.904 > 13 0x1557084c7 -[UIInputWindowController moveFromPlacement:toPlacement:starting:completion:] > 14 0x15570e6cb -[UIInputWindowController setInputViewSet:] > 15 0x155707990 -[UIInputWindowController performOperations:withAnimationStyle:] > 16 0x15539b743 -[UIInputResponderController setKeyWindowSceneInputViews:animationStyle:] > 17 0x15539d415 -[UIInputResponderController maximizeWithAnimationStyle:force:] > 18 0x15539d383 -[UIInputResponderController maximizeWithAnimation:] > 19 0x155db4703 -[UIKeyboardAutomatic maximize] > 20 0x155761e4d -[UIKeyboardImpl _showKeyboardIgnoringPolicyDelegate:] > 21 0x1557653df -[UIKeyboardImpl showKeyboardIfNeeded] > 22 0x155c7e756 -[UIWKTextSelectionInteraction didUpdateSelectionWithGesture:] > 23 0x155c3864c -[UITextSelectionInteraction tappedToPositionCursorWithGesture:atPoint:granularity:completionHandler:] > 24 0x155c3838f -[UITextSelectionInteraction _checkForRepeatedTap:gestureLocationOut:] > 25 0x155c38e56 -[UITextSelectionInteraction _handleMultiTapGesture:] > 26 0x10c9ee143 swizzledHandleMultiTapGesture(objc_object*, objc_selector*, UIGestureRecognizer*) > 27 0x155974937 -[UIApplication sendAction:to:from:forEvent:] > 28 0x1553fb413 -[UITextMultiTapRecognizer onStateUpdate:] > 29 0x15549bfe3 -[UIGestureRecognizerTarget _sendActionWithGestureRecognizer:] > 30 0x1554a630d _UIGestureRecognizerSendTargetActions > 31 0x1554a2b6e _UIGestureRecognizerSendActions ...I think I know how to mitigate this. Created attachment 435438 [details]
Patch
Comment on attachment 435438 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=435438&action=review > Tools/WebKitTestRunner/ios/TestControllerIOS.mm:171 > + if (![preferencesActions oneTimeActionCompleted:@"HardwareKeyboardLastSeen"]) Nit: "HardwareKeyboardLastSeen" could be stored in a variable, similar to the other keys in this method. Comment on attachment 435438 [details] Patch View in context: https://bugs.webkit.org/attachment.cgi?id=435438&action=review >> Tools/WebKitTestRunner/ios/TestControllerIOS.mm:171 >> + if (![preferencesActions oneTimeActionCompleted:@"HardwareKeyboardLastSeen"]) > > Nit: "HardwareKeyboardLastSeen" could be stored in a variable, similar to the other keys in this method. Make sense! Created attachment 435439 [details]
Patch
Created attachment 435440 [details]
Manually set reviewers
Committed r280986 (240486@main): <https://commits.webkit.org/240486@main> All reviewed patches have been landed. Closing bug and clearing flags on attachment 435440 [details]. |