Bug 201440 - REGRESSION: http/tests/adClickAttribution/second-attribution-converted-with-higher-priority.html and http/tests/adClickAttribution/second-attribution-converted-with-lower-priority.html are flaky timeouts
Summary: REGRESSION: http/tests/adClickAttribution/second-attribution-converted-with-h...
Status: RESOLVED FIXED
Alias: None
Product: WebKit
Classification: Unclassified
Component: Tools / Tests (show other bugs)
Version: Other
Hardware: Unspecified Unspecified
: P2 Normal
Assignee: Chris Dumez
URL:
Keywords: InRadar
Depends on:
Blocks: 201344
  Show dependency treegraph
 
Reported: 2019-09-03 17:04 PDT by Ryan Haddad
Modified: 2019-09-05 18:07 PDT (History)
9 users (show)

See Also:


Attachments
Patch (5.00 KB, patch)
2019-09-05 13:03 PDT, Chris Dumez
no flags Details | Formatted Diff | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Ryan Haddad 2019-09-03 17:04:59 PDT
http/tests/adClickAttribution/second-attribution-converted-with-higher-priority.html and http/tests/adClickAttribution/second-attribution-converted-with-lower-priority.html have recently become flaky timeouts on macOS WK2 queues.

https://webkit-test-results.webkit.org/dashboards/flakiness_dashboard.html#showAllRuns=true&tests=http%2Ftests%2FadClickAttribution%2Fsecond-attribution-converted-with-higher-priority.html%20http%2Ftests%2FadClickAttribution%2Fsecond-attribution-converted-with-lower-priority.html

The earliest blamed revision range is https://trac.webkit.org/log/webkit/?verbose=on&rev=249350&stop_rev=249349
Comment 1 Radar WebKit Bug Importer 2019-09-03 17:05:27 PDT
<rdar://problem/54998427>
Comment 2 Russell Epstein 2019-09-05 10:28:36 PDT
I was able to reproduce this timeout starting with r249350 using the following command:

run-webkit-tests --iter 1000 -f --no-sample-on-timeout --no-retry http/tests/adClickAttribution/second-attribution-converted-with-higher-priority.html
Comment 3 Chris Dumez 2019-09-05 12:17:43 PDT
It is weird, when it times out, I actually see the test running to completion and calling testRunner.notifyDone(). This seems like a potential issue with WebKitTestRunner where it fails to stop even though notifyDone() was called.
Comment 4 Chris Dumez 2019-09-05 12:25:17 PDT
(In reply to Chris Dumez from comment #3)
> It is weird, when it times out, I actually see the test running to
> completion and calling testRunner.notifyDone(). This seems like a potential
> issue with WebKitTestRunner where it fails to stop even though notifyDone()
> was called.

It seems the InjectedBundle in the WebContent process is sending the "Done" IPC to the UIProcess but this IPC is not getting received in the UIProcess.
Comment 5 Chris Dumez 2019-09-05 12:34:09 PDT
(In reply to Chris Dumez from comment #4)
> (In reply to Chris Dumez from comment #3)
> > It is weird, when it times out, I actually see the test running to
> > completion and calling testRunner.notifyDone(). This seems like a potential
> > issue with WebKitTestRunner where it fails to stop even though notifyDone()
> > was called.
> 
> It seems the InjectedBundle in the WebContent process is sending the "Done"
> IPC to the UIProcess but this IPC is not getting received in the UIProcess.

I have confirmed that the WebProcessProxy is dropping this IPC message on the floor (likely because there is not WebPageProxy listening anymore for this identifier). I am investigating to find out why.
Comment 6 Chris Dumez 2019-09-05 12:43:42 PDT
(In reply to Chris Dumez from comment #5)
> (In reply to Chris Dumez from comment #4)
> > (In reply to Chris Dumez from comment #3)
> > > It is weird, when it times out, I actually see the test running to
> > > completion and calling testRunner.notifyDone(). This seems like a potential
> > > issue with WebKitTestRunner where it fails to stop even though notifyDone()
> > > was called.
> > 
> > It seems the InjectedBundle in the WebContent process is sending the "Done"
> > IPC to the UIProcess but this IPC is not getting received in the UIProcess.
> 
> I have confirmed that the WebProcessProxy is dropping this IPC message on
> the floor (likely because there is not WebPageProxy listening anymore for
> this identifier). I am investigating to find out why.

It looks like the WebKitTestRunner's injected bundle gets confused when we use a process for a new load that already had a WKTR injected bundle. It still tries to talk to the previous page in that process (which is now suspended).
Comment 7 Chris Dumez 2019-09-05 12:44:51 PDT
(In reply to Chris Dumez from comment #6)
> (In reply to Chris Dumez from comment #5)
> > (In reply to Chris Dumez from comment #4)
> > > (In reply to Chris Dumez from comment #3)
> > > > It is weird, when it times out, I actually see the test running to
> > > > completion and calling testRunner.notifyDone(). This seems like a potential
> > > > issue with WebKitTestRunner where it fails to stop even though notifyDone()
> > > > was called.
> > > 
> > > It seems the InjectedBundle in the WebContent process is sending the "Done"
> > > IPC to the UIProcess but this IPC is not getting received in the UIProcess.
> > 
> > I have confirmed that the WebProcessProxy is dropping this IPC message on
> > the floor (likely because there is not WebPageProxy listening anymore for
> > this identifier). I am investigating to find out why.
> 
> It looks like the WebKitTestRunner's injected bundle gets confused when we
> use a process for a new load that already had a WKTR injected bundle. It
> still tries to talk to the previous page in that process (which is now
> suspended).

I think the issue lies here:
InjectedBundlePage* InjectedBundle::page() const
{
    // It might be better to have the UI process send over a reference to the main
    // page instead of just assuming it's the first one.
    return m_pages[0].get();
}

We always assume the *first* page that was created in the process is the one we want to talk to.
Comment 8 Chris Dumez 2019-09-05 13:03:27 PDT
Created attachment 378106 [details]
Patch
Comment 9 WebKit Commit Bot 2019-09-05 18:07:07 PDT
Comment on attachment 378106 [details]
Patch

Clearing flags on attachment: 378106

Committed r249557: <https://trac.webkit.org/changeset/249557>
Comment 10 WebKit Commit Bot 2019-09-05 18:07:09 PDT
All reviewed patches have been landed.  Closing bug.