Bug 190052

Summary: Regression(r236512): http/tests/navigation/keyboard-events-during-provisional-navigation.html is flaky
Product: WebKit Reporter: Chris Dumez <cdumez>
Component: WebKit2Assignee: Chris Dumez <cdumez>
Status: RESOLVED FIXED    
Severity: Normal CC: achristensen, commit-queue, dbates, ews-watchlist, ggaren, rniwa, simon.fraser, tsavell, webkit-bug-importer
Priority: P1 Keywords: InRadar, Regression
Version: WebKit Nightly Build   
Hardware: Unspecified   
OS: Unspecified   
Bug Depends on: 190112    
Bug Blocks: 189927    
Attachments:
Description Flags
Patch
none
Patch
none
Patch
none
Archive of layout-test-results from ews106 for mac-sierra-wk2
none
Patch
none
Patch none

Description Chris Dumez 2018-09-27 13:38:16 PDT
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".
Comment 1 Chris Dumez 2018-09-27 13:39:49 PDT
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.
Comment 2 Chris Dumez 2018-09-27 14:03:11 PDT
I suspect this has something to do with the IPC::SendSyncOption::UseFullySynchronousModeForTesting IPC send option that is used by WK2 eventSender.
Comment 3 Chris Dumez 2018-09-27 14:08:57 PDT
(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...) :(
Comment 4 Chris Dumez 2018-09-27 14:50:12 PDT
Created attachment 351007 [details]
Patch
Comment 5 Chris Dumez 2018-09-27 15:18:16 PDT
Created attachment 351011 [details]
Patch
Comment 6 Chris Dumez 2018-09-27 15:46:48 PDT
Created attachment 351015 [details]
Patch
Comment 7 EWS Watchlist 2018-09-27 17:45:59 PDT
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
Comment 8 EWS Watchlist 2018-09-27 17:46:01 PDT
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
Comment 9 Chris Dumez 2018-09-28 09:01:02 PDT
Created attachment 351079 [details]
Patch
Comment 10 Ryosuke Niwa 2018-09-28 17:00:42 PDT
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?
Comment 11 Chris Dumez 2018-09-28 18:38:33 PDT
Committed r236631: <https://trac.webkit.org/changeset/236631>
Comment 12 Radar WebKit Bug Importer 2018-09-28 18:39:32 PDT
<rdar://problem/44880831>
Comment 13 Simon Fraser (smfr) 2018-09-29 10:35:51 PDT
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.
Comment 15 WebKit Commit Bot 2018-09-29 10:37:35 PDT
Re-opened since this is blocked by bug 190112
Comment 16 Chris Dumez 2018-09-29 10:51:41 PDT
(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.
Comment 17 Chris Dumez 2018-10-01 08:59:41 PDT
(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.
Comment 18 Chris Dumez 2018-10-01 09:01:19 PDT
(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
Comment 19 Chris Dumez 2018-10-01 09:07:08 PDT
Created attachment 351250 [details]
Patch
Comment 20 Chris Dumez 2018-10-01 09:08:29 PDT
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.
Comment 21 WebKit Commit Bot 2018-10-01 10:16:59 PDT
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 commit-queue@webkit.org...
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
Comment 22 Chris Dumez 2018-10-01 11:57:07 PDT
Comment on attachment 351250 [details]
Patch

Clearing flags on attachment: 351250

Committed r236680: <https://trac.webkit.org/changeset/236680>
Comment 23 Chris Dumez 2018-10-01 11:57:09 PDT
All reviewed patches have been landed.  Closing bug.