Bug 190052 – Regression(r236512): http/tests/navigation/keyboard-events-during-provisional-navigation.html is flaky

• Status: RESOLVED
• Resolution: FIXED
• Component: WebKit2

[Chris Dumez]

http/tests/navigation/keyboard-events-during-provisional-navigation.html is flaky after r236512:
Diff:
--- /Volumes/Data/slave/highsierra-release-tests-wk2/build/layout-test-results/http/tests/navigation/keyboard-events-during-provisional-navigation-expected.txt
+++ /Volumes/Data/slave/highsierra-release-tests-wk2/build/layout-test-results/http/tests/navigation/keyboard-events-during-provisional-navigation-actual.txt
@@ -9,9 +9,9 @@
 CONSOLE MESSAGE: line 52: Inserting text "c".
 CONSOLE MESSAGE: line 55: Pasting text "d".
 CONSOLE MESSAGE: line 58: Input element value after text input events: "".
-CONSOLE MESSAGE: line 20: Pressing "z" with access key modifiers should navigate to resources/keyboard-events-after-navigation.html.
 CONSOLE MESSAGE: line 18: keydownevent dispatched (isTrusted: true).
 CONSOLE MESSAGE: line 18: keyupevent dispatched (isTrusted: true).
+CONSOLE MESSAGE: line 20: Pressing "z" with access key modifiers should navigate to resources/keyboard-events-after-navigation.html.
 CONSOLE MESSAGE: line 6: Finished navigating to resources/keyboard-events-after-navigation.html.
 CONSOLE MESSAGE: line 7: Trusted events should be logged and the input element should have the value "acd".

[Chris Dumez]

The test does:
console.log("Pressing \"z\" with access key modifiers should navigate to resources/keyboard-events-after-navigation.html.");
eventSender.keyDown("z", internals.accessKeyModifiers());

The console logging does an async IPC to the UIProcess and the eventSender.keyDown() does a sync IPC to the UIProcess. As a result, the execution order of those 2 is not pre-determined.

[Chris Dumez]

I suspect this has something to do with the IPC::SendSyncOption::UseFullySynchronousModeForTesting IPC send option that is used by WK2 eventSender.

[Chris Dumez]

(In reply to Chris Dumez from comment #2)
> I suspect this has something to do with the
> IPC::SendSyncOption::UseFullySynchronousModeForTesting IPC send option that
> is used by WK2 eventSender.

When this flag is used for a Sync IPC A, every async IPC X that gets sent by the Sync IPC A reply handler becomes synchronous :S

So in this case:
Log(Pressing "z" with access key modi...) sends Async message to UIProcess
eventSender.keyDown() sends Sync IPC to UIProcess with IPC::SendSyncOption::UseFullySynchronousModeForTesting
As a result of the keydown, we do:
Log(keydownevent dispatched) which should send an Async message to the UIProcess, but this becomes synchronous due to SendSyncOption::UseFullySynchronousModeForTesting.

As a result, Log(keydownevent dispatched) may get processed by the UIProcess *before* Log(Pressing "z" with access key modi...) :(

[Chris Dumez]

Created attachment 351007 [details]
Patch

[Chris Dumez]

Created attachment 351011 [details]
Patch

[Chris Dumez]

Created attachment 351015 [details]
Patch

[EWS Watchlist]

Comment on attachment 351015 [details]
Patch

Attachment 351015 [details] did not pass mac-wk2-ews (mac-wk2):
Output: https://webkit-queues.webkit.org/results/9374319

New failing tests:
fast/css/pseudo-active-style-sharing-3.html
fast/events/inactive-window-no-mouse-event.html
loader/stateobjects/pushstate-size-iframe.html
fullscreen/video-controls-timeline.html
fast/css/pseudo-active-style-sharing-6.html
fast/forms/file/input-file-write-files-using-open-panel.html
fast/events/frame-detached-in-mousedown.html
fast/css/pseudo-active-style-sharing-1.html
fullscreen/full-screen-keyboard-enabled.html
media/modern-media-controls/slider/slider-value.html
fast/events/keydown-remove-frame.html
fast/forms/placeholder-crash-with-scrollbar-corner.html
loader/stateobjects/pushstate-size.html
fast/visual-viewport/client-coordinates-relative-to-layout-viewport.html
fast/events/can-click-element-on-page-with-active-pseudo-class-and-search-field.html
fast/css/pseudo-active-style-sharing-5.html
media/modern-media-controls/button/button-click-on-edges.html
fast/css/pseudo-active-style-sharing-2.html

[EWS Watchlist]

Created attachment 351030 [details]
Archive of layout-test-results from ews106 for mac-sierra-wk2

The attached test failures were seen while running run-webkit-tests on the mac-wk2-ews.
Bot: ews106  Port: mac-sierra-wk2  Platform: Mac OS X 10.12.6

[Chris Dumez]

Created attachment 351079 [details]
Patch

[Ryosuke Niwa]

Comment on attachment 351079 [details]
Patch

View in context: https://bugs.webkit.org/attachment.cgi?id=351079&action=review

> Source/WebKit/ChangeLog:7
> +

Add a comment about what we're adding here too?

[Chris Dumez]

Committed r236631: <https://trac.webkit.org/changeset/236631>

[Radar WebKit Bug Importer]

<rdar://problem/44880831>

[Simon Fraser (smfr)]

This caused various tests to not complete:

fast/css/pseudo-active-style-sharing-1.html
fast/css/pseudo-active-style-sharing-2.html
fast/css/pseudo-active-style-sharing-3.html
fast/css/pseudo-active-style-sharing-4.html
fast/css/pseudo-active-style-sharing-5.html
fast/css/pseudo-active-style-sharing-6.html
fast/events/can-click-element-on-page-with-active-pseudo-class-and-search-field.html
fast/events/frame-detached-in-mousedown.html
fast/events/inactive-window-no-mouse-event.html
fast/events/keydown-remove-frame.html
fast/forms/placeholder-crash-with-scrollbar-corner.html
fast/visual-viewport/client-coordinates-relative-to-layout-viewport.html
fullscreen/full-screen-keyboard-enabled.html
fullscreen/video-controls-timeline.html
loader/stateobjects/pushstate-size-iframe.html
loader/stateobjects/pushstate-size.html
media/modern-media-controls/button/button-click-on-edges.html
media/modern-media-controls/slider/slider-value.html
plugins/snapshotting/plugin-receives-click-event.html

I'll roll it out.

[Simon Fraser (smfr)]

For example: https://build.webkit.org/results/Apple%20High%20Sierra%20Debug%20WK2%20(Tests)/r236643%20(5030)/results.html

[WebKit Commit Bot]

Re-opened since this is blocked by bug 190112

[Chris Dumez]

(In reply to Simon Fraser (smfr) from comment #13)
> This caused various tests to not complete:
> 
> fast/css/pseudo-active-style-sharing-1.html
> fast/css/pseudo-active-style-sharing-2.html
> fast/css/pseudo-active-style-sharing-3.html
> fast/css/pseudo-active-style-sharing-4.html
> fast/css/pseudo-active-style-sharing-5.html
> fast/css/pseudo-active-style-sharing-6.html
> fast/events/can-click-element-on-page-with-active-pseudo-class-and-search-
> field.html
> fast/events/frame-detached-in-mousedown.html
> fast/events/inactive-window-no-mouse-event.html
> fast/events/keydown-remove-frame.html
> fast/forms/placeholder-crash-with-scrollbar-corner.html
> fast/visual-viewport/client-coordinates-relative-to-layout-viewport.html
> fullscreen/full-screen-keyboard-enabled.html
> fullscreen/video-controls-timeline.html
> loader/stateobjects/pushstate-size-iframe.html
> loader/stateobjects/pushstate-size.html
> media/modern-media-controls/button/button-click-on-edges.html
> media/modern-media-controls/slider/slider-value.html
> plugins/snapshotting/plugin-receives-click-event.html
> 
> I'll roll it out.

Weird. Ews was green. Thanks for rolling out, I will investigate on Monday.

[Chris Dumez]

(In reply to Simon Fraser (smfr) from comment #13)
> This caused various tests to not complete:
> 
> fast/css/pseudo-active-style-sharing-1.html
> fast/css/pseudo-active-style-sharing-2.html
> fast/css/pseudo-active-style-sharing-3.html
> fast/css/pseudo-active-style-sharing-4.html
> fast/css/pseudo-active-style-sharing-5.html
> fast/css/pseudo-active-style-sharing-6.html
> fast/events/can-click-element-on-page-with-active-pseudo-class-and-search-
> field.html
> fast/events/frame-detached-in-mousedown.html
> fast/events/inactive-window-no-mouse-event.html
> fast/events/keydown-remove-frame.html
> fast/forms/placeholder-crash-with-scrollbar-corner.html
> fast/visual-viewport/client-coordinates-relative-to-layout-viewport.html
> fullscreen/full-screen-keyboard-enabled.html
> fullscreen/video-controls-timeline.html
> loader/stateobjects/pushstate-size-iframe.html
> loader/stateobjects/pushstate-size.html
> media/modern-media-controls/button/button-click-on-edges.html
> media/modern-media-controls/slider/slider-value.html
> plugins/snapshotting/plugin-receives-click-event.html
> 
> I'll roll it out.

From what I see, it merely complained that those tests have no expected results, not that they were timing out or failing per say.

[Chris Dumez]

(In reply to Chris Dumez from comment #17)
> (In reply to Simon Fraser (smfr) from comment #13)
> > This caused various tests to not complete:
> > 
> > fast/css/pseudo-active-style-sharing-1.html
> > fast/css/pseudo-active-style-sharing-2.html
> > fast/css/pseudo-active-style-sharing-3.html
> > fast/css/pseudo-active-style-sharing-4.html
> > fast/css/pseudo-active-style-sharing-5.html
> > fast/css/pseudo-active-style-sharing-6.html
> > fast/events/can-click-element-on-page-with-active-pseudo-class-and-search-
> > field.html
> > fast/events/frame-detached-in-mousedown.html
> > fast/events/inactive-window-no-mouse-event.html
> > fast/events/keydown-remove-frame.html
> > fast/forms/placeholder-crash-with-scrollbar-corner.html
> > fast/visual-viewport/client-coordinates-relative-to-layout-viewport.html
> > fullscreen/full-screen-keyboard-enabled.html
> > fullscreen/video-controls-timeline.html
> > loader/stateobjects/pushstate-size-iframe.html
> > loader/stateobjects/pushstate-size.html
> > media/modern-media-controls/button/button-click-on-edges.html
> > media/modern-media-controls/slider/slider-value.html
> > plugins/snapshotting/plugin-receives-click-event.html
> > 
> > I'll roll it out.
> 
> From what I see, it merely complained that those tests have no expected
> results, not that they were timing out or failing per say.

Ok yes, there is something weird going on as these tests do seem to have expected tests results:
LayoutTests/fast/css/pseudo-active-style-sharing-1-expected.txt

[Chris Dumez]

Created attachment 351250 [details]
Patch

[Chris Dumez]

The issue was that the "NotifyDone" IPC would still become synchronous when the IPC connection was in synchronous mode, and therefore could be processed before the OutputText asynchronous IPC. The tests would sometimes complete with no output as a result.

[WebKit Commit Bot]

Comment on attachment 351250 [details]
Patch

Rejecting attachment 351250 [details] from commit-queue.

Failed to run "['/Volumes/Data/EWS/WebKit/Tools/Scripts/webkit-patch', '--status-host=webkit-queues.webkit.org', '--bot-id=webkit-cq-03', 'land-attachment', '--force-clean', '--non-interactive', '--parent-command=commit-queue', 351250, '--port=mac']" exit_code: 2 cwd: /Volumes/Data/EWS/WebKit

Logging in as [e-mail]...
Fetching: https://bugs.webkit.org/attachment.cgi?id=351250&action=edit
Fetching: https://bugs.webkit.org/show_bug.cgi?id=190052&ctype=xml&excludefield=attachmentdata
Processing 1 patch from 1 bug.
Updating working directory
Processing patch 351250 from bug 190052.
Fetching: https://bugs.webkit.org/attachment.cgi?id=351250
Failed to run "['git', 'svn', 'dcommit', '--rmdir']" exit_code: 1 cwd: /Volumes/Data/EWS/WebKit

Committing to http://svn.webkit.org/repository/webkit/trunk ...
	M	Source/WebKit/ChangeLog

ERROR from SVN:
Item is out of date: File '/trunk/Source/WebKit/ChangeLog' is out of date
W: 58feecd202116e40367278a1bfa436ff49358423 and refs/remotes/origin/master differ, using rebase:
:040000 040000 0fb40b159be9ec044e83f9b0a19815371ea0f068 f1e39de4dfb3a84f2125f3470accd9d338990f03 M	Source
:040000 040000 5f7163d142cbe02ea12ec3b913fe56304aec3c35 d78aa9b6cf6da2a632cd62cbfe6837473607de99 M	Tools
Current branch master is up to date.
ERROR: Not all changes have been committed into SVN, however the committed
ones (if any) seem to be successfully integrated into the working tree.
Please see the above messages for details.


Failed to run "['git', 'svn', 'dcommit', '--rmdir']" exit_code: 1 cwd: /Volumes/Data/EWS/WebKit

Committing to http://svn.webkit.org/repository/webkit/trunk ...
	M	Source/WebKit/ChangeLog

ERROR from SVN:
Item is out of date: File '/trunk/Source/WebKit/ChangeLog' is out of date
W: 58feecd202116e40367278a1bfa436ff49358423 and refs/remotes/origin/master differ, using rebase:
:040000 040000 0fb40b159be9ec044e83f9b0a19815371ea0f068 f1e39de4dfb3a84f2125f3470accd9d338990f03 M	Source
:040000 040000 5f7163d142cbe02ea12ec3b913fe56304aec3c35 d78aa9b6cf6da2a632cd62cbfe6837473607de99 M	Tools
Current branch master is up to date.
ERROR: Not all changes have been committed into SVN, however the committed
ones (if any) seem to be successfully integrated into the working tree.
Please see the above messages for details.


Failed to run "['git', 'svn', 'dcommit', '--rmdir']" exit_code: 1 cwd: /Volumes/Data/EWS/WebKit
Updating OpenSource
Current branch master is up to date.

Full output: https://webkit-queues.webkit.org/results/9411910

[Chris Dumez]

Comment on attachment 351250 [details]
Patch

Clearing flags on attachment: 351250

Committed r236680: <https://trac.webkit.org/changeset/236680>

[Chris Dumez]

All reviewed patches have been landed.  Closing bug.