Bug 175076 - Multiple Layout tests from web-platform-tests/beacon/ are timing out.
Summary: Multiple Layout tests from web-platform-tests/beacon/ are timing out.
Status: RESOLVED FIXED
Alias: None
Product: WebKit
Classification: Unclassified
Component: New Bugs (show other bugs)
Version: WebKit Nightly Build
Hardware: Unspecified Unspecified
: P2 Normal
Assignee: Chris Dumez
URL:
Keywords: InRadar
Depends on:
Blocks: 147885 175061
  Show dependency treegraph
 
Reported: 2017-08-02 10:14 PDT by Matt Lewis
Modified: 2017-08-04 14:50 PDT (History)
11 users (show)

See Also:


Attachments
Patch (4.09 KB, patch)
2017-08-03 11:32 PDT, Chris Dumez
no flags Details | Formatted Diff | Diff
Archive of layout-test-results from ews125 for ios-simulator-wk2 (1.26 MB, application/zip)
2017-08-03 14:30 PDT, Build Bot
no flags Details
Patch (29.33 KB, patch)
2017-08-03 15:02 PDT, Chris Dumez
no flags Details | Formatted Diff | Diff
Patch (29.33 KB, patch)
2017-08-03 15:13 PDT, Chris Dumez
no flags Details | Formatted Diff | Diff
Patch (29.02 KB, patch)
2017-08-03 16:09 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 Matt Lewis 2017-08-02 10:14:48 PDT
Multiple Layout tests from web-platform-tests/beacon/ are timing out on Sierra and iOS 10 Simulators according to the dashboard:
  imported/w3c/web-platform-tests/beacon/headers/header-referrer-no-referrer-when-downgrade.https.html [ Timeout ]
  imported/w3c/web-platform-tests/beacon/headers/header-referrer-strict-origin-when-cross-origin.https.html [ Timeout ]
  imported/w3c/web-platform-tests/beacon/headers/header-referrer-strict-origin.https.html [ Timeout ]
  imported/w3c/web-platform-tests/beacon/headers/header-referrer-unsafe-url.https.html [ Timeout ]

They have been timing out since being added in: https://trac.webkit.org/changeset/220121/webkit

https://webkit-test-results.webkit.org/dashboards/flakiness_dashboard.html#showAllRuns=true&tests=imported%2Fw3c%2Fweb-platform-tests%2Fbeacon%2Fheaders%2Fheader-referrer-strict-origin-when-cross-origin.https.html

History example:
https://webkit-test-results.webkit.org/dashboards/flakiness_dashboard.html#showAllRuns=true&tests=imported%2Fw3c%2Fweb-platform-tests%2Fbeacon%2Fheaders%2Fheader-referrer-strict-origin-when-cross-origin.https.html

Build and results:
https://build.webkit.org/builders/Apple%20Sierra%20Release%20WK2%20%28Tests%29/builds/3307
https://build.webkit.org/results/Apple%20Sierra%20Release%20WK2%20(Tests)/r220121%20(3307)/results.html

Sample Diff:
--- /Volumes/Data/slave/sierra-release-tests-wk2/build/layout-test-results/imported/w3c/web-platform-tests/beacon/headers/header-referrer-strict-origin-when-cross-origin.https-expected.txt
+++ /Volumes/Data/slave/sierra-release-tests-wk2/build/layout-test-results/imported/w3c/web-platform-tests/beacon/headers/header-referrer-strict-origin-when-cross-origin.https-actual.txt
@@ -1,5 +1,7 @@
 CONSOLE MESSAGE: line 8: Failed to set referrer policy: The value 'strict-origin' is not one of 'no-referrer', 'origin', 'no-referrer-when-downgrade', or 'unsafe-url'. Defaulting to 'no-referrer'.
+CONSOLE MESSAGE: Unhandled Promise Rejection: TypeError: Type error
+#PID UNRESPONSIVE - com.apple.WebKit.WebContent.Development (pid 85515)
+FAIL: Timed out waiting for notifyDone to be called
 
-FAIL Test referer header https://localhost:9443/beacon/resources/ assert_equals: Correct referrer header result expected "https://localhost:9443/" but got ""
-PASS Test referer header http://localhost:8800/beacon/resources/ 
-
+#EOF
+#EOF
Comment 1 Chris Dumez 2017-08-02 10:19:06 PDT
It is interesting that it is only the HTTPS ones. They were timing out for me locally until Youenn's fix in bug 174992.
Comment 2 Chris Dumez 2017-08-02 10:46:27 PDT
Temporarily skipped in <http://trac.webkit.org/changeset/220137>.
Comment 3 Chris Dumez 2017-08-02 10:48:28 PDT
They pass locally but time out on the bots. The stderr output shows the following error:
22:29:17.380 81095   2017-08-01 22:29:17.352 com.apple.WebKit.Networking.Development[82010:100058563] NSURLSession/NSURLConnection HTTP load failed (kCFStreamErrorDomainSSL, -9814)
2
Comment 4 Chris Dumez 2017-08-02 11:55:18 PDT
I see DRT / WKTR do:
    [NSURLRequest setAllowsAnyHTTPSCertificate:YES forHost:@"localhost"];
    [NSURLRequest setAllowsAnyHTTPSCertificate:YES forHost:@"127.0.0.1"];

Maybe we need to whitelist another host of web-platform-tests?
Comment 5 Chris Dumez 2017-08-02 12:09:41 PDT
(In reply to Chris Dumez from comment #4)
> I see DRT / WKTR do:
>     [NSURLRequest setAllowsAnyHTTPSCertificate:YES forHost:@"localhost"];
>     [NSURLRequest setAllowsAnyHTTPSCertificate:YES forHost:@"127.0.0.1"];
> 
> Maybe we need to whitelist another host of web-platform-tests?

Nah, looks like WPT uses localhost:
Starting web-platform-tests server on <http://localhost:8800/> and <https://localhost:9443/>
No handlers could be found for logger "webkitpy.layout_tests.servers.web_platform_test_server"
Comment 6 Chris Dumez 2017-08-02 12:23:28 PDT
Interestingly, the tests only seem to time out on WK2, not WK1.

I am wondering if this really does the right thing for WKTR:
    [NSURLRequest setAllowsAnyHTTPSCertificate:YES forHost:@"localhost"];
    [NSURLRequest setAllowsAnyHTTPSCertificate:YES forHost:@"127.0.0.1"];

This is in the injected bundle, therefore in the WebProcess. Will this really impact our NetworkProcess loads?
Comment 7 Chris Dumez 2017-08-02 12:26:24 PDT
Hmm, interestingly, the ElCapitan WK2 but seems fine:
https://build.webkit.org/results/Apple%20El%20Capitan%20Release%20WK2%20(Tests)/r220121%20(3446)/results.html

The Sierra WK2 one experiences the error though.
Comment 8 Chris Dumez 2017-08-02 12:27:52 PDT
(In reply to Chris Dumez from comment #7)
> Hmm, interestingly, the ElCapitan WK2 but seems fine:
> https://build.webkit.org/results/
> Apple%20El%20Capitan%20Release%20WK2%20(Tests)/r220121%20(3446)/results.html
> 
> The Sierra WK2 one experiences the error though.

One difference I think between ElCapitan and Sierra is that Sierra is using the newer NETWORK_SESSION code path. So maybe the [NSURLRequest setAllowsAnyHTTPSCertificate:YES forHost:@"localhost"] is not working properly with NetworkSession?
Comment 9 Chris Dumez 2017-08-02 12:43:17 PDT
(In reply to Chris Dumez from comment #3)
> They pass locally but time out on the bots. The stderr output shows the
> following error:
> 22:29:17.380 81095   2017-08-01 22:29:17.352
> com.apple.WebKit.Networking.Development[82010:100058563]
> NSURLSession/NSURLConnection HTTP load failed (kCFStreamErrorDomainSSL,
> -9814)
> 2

This error is:
NSOSStatusErrorDomain errSSLCertExpired -9814

So the certificate used by WPT tests seems to have expired?
Comment 10 Chris Dumez 2017-08-02 12:46:01 PDT
(In reply to Chris Dumez from comment #9)
> (In reply to Chris Dumez from comment #3)
> > They pass locally but time out on the bots. The stderr output shows the
> > following error:
> > 22:29:17.380 81095   2017-08-01 22:29:17.352
> > com.apple.WebKit.Networking.Development[82010:100058563]
> > NSURLSession/NSURLConnection HTTP load failed (kCFStreamErrorDomainSSL,
> > -9814)
> > 2
> 
> This error is:
> NSOSStatusErrorDomain errSSLCertExpired -9814
> 
> So the certificate used by WPT tests seems to have expired?

If I launch the wpt server locally:
$ Tools/Scripts/run-webkit-httpd

and go to https://localhost:9443 in Safari

I indeed get a certificate error. However, what I see locally is not that the certificate has expired, but rather that it is signed by an unknown authority.
Comment 11 Chris Dumez 2017-08-02 12:56:26 PDT
(In reply to Chris Dumez from comment #10)
> (In reply to Chris Dumez from comment #9)
> > (In reply to Chris Dumez from comment #3)
> > > They pass locally but time out on the bots. The stderr output shows the
> > > following error:
> > > 22:29:17.380 81095   2017-08-01 22:29:17.352
> > > com.apple.WebKit.Networking.Development[82010:100058563]
> > > NSURLSession/NSURLConnection HTTP load failed (kCFStreamErrorDomainSSL,
> > > -9814)
> > > 2
> > 
> > This error is:
> > NSOSStatusErrorDomain errSSLCertExpired -9814
> > 
> > So the certificate used by WPT tests seems to have expired?
> 
> If I launch the wpt server locally:
> $ Tools/Scripts/run-webkit-httpd
> 
> and go to https://localhost:9443 in Safari
> 
> I indeed get a certificate error. However, what I see locally is not that
> the certificate has expired, but rather that it is signed by an unknown
> authority.

I looked at another bot (iOS) and the error was different:
NSOSStatusErrorDomain errSSLNoRootCert -9813

So it looks like WKTR is not correctly ignoring invalid certificates for localhost / 127.0.0.1 when using NETWORK_SESSION code path.
Comment 12 Chris Dumez 2017-08-02 12:59:34 PDT
Tests skipped on WK2 only via <http://trac.webkit.org/changeset/220149>.
Comment 13 Alexey Proskuryakov 2017-08-02 16:41:52 PDT
> I am wondering if this really does the right thing for WKTR:
>    [NSURLRequest setAllowsAnyHTTPSCertificate:YES forHost:@"localhost"];
>    [NSURLRequest setAllowsAnyHTTPSCertificate:YES forHost:@"127.0.0.1"];

This code is for in-process loading (such as media). What should work in the general case is the code in TestController::canAuthenticateAgainstProtectionSpace(). We override server trust evaluation.
Comment 14 Chris Dumez 2017-08-03 09:06:28 PDT
(In reply to Alexey Proskuryakov from comment #13)
> > I am wondering if this really does the right thing for WKTR:
> >    [NSURLRequest setAllowsAnyHTTPSCertificate:YES forHost:@"localhost"];
> >    [NSURLRequest setAllowsAnyHTTPSCertificate:YES forHost:@"127.0.0.1"];
> 
> This code is for in-process loading (such as media). What should work in the
> general case is the code in
> TestController::canAuthenticateAgainstProtectionSpace(). We override server
> trust evaluation.

Thanks for the info. It is odd, I added logging and I see canAuthenticateAgainstProtectionSpace(localhost) getting called. I see us returning true, as expected. However, I then get a:
2017-08-03 09:02:31.055 com.apple.WebKit.Networking.Development[25431:3791340] NSURLSession/NSURLConnection HTTP load failed (kCFStreamErrorDomainSSL, -9813)
Comment 15 Chris Dumez 2017-08-03 10:20:39 PDT
If I tweak NetworkLoad::didReceiveChallenge() to completionHandler(AuthenticationChallengeDisposition::UseCredential, serverTrustCredential(challenge)); whenever challenge.protectionSpace().authenticationScheme() == ProtectionSpaceAuthenticationSchemeServerTrustEvaluationRequested, then the tests no longer time out.
Comment 16 Chris Dumez 2017-08-03 10:45:51 PDT
(In reply to Chris Dumez from comment #15)
> If I tweak NetworkLoad::didReceiveChallenge() to
> completionHandler(AuthenticationChallengeDisposition::UseCredential,
> serverTrustCredential(challenge)); whenever
> challenge.protectionSpace().authenticationScheme() ==
> ProtectionSpaceAuthenticationSchemeServerTrustEvaluationRequested, then the
> tests no longer time out.

The problem seems to be happen when NetworkLoad::completeAuthenticationChallenge() is called and m_parameters.clientCredentialPolicy == ClientCredentialPolicy::CannotAskClientForCredentials.

In such case, we call:
completionHandler(AuthenticationChallengeDisposition::UseCredential, { });

If I replace with:
completionHandler(AuthenticationChallengeDisposition::UseCredential, serverTrustCredential(*m_challenge));

Then the tests no longer time out.
Comment 17 Chris Dumez 2017-08-03 11:05:25 PDT
(In reply to Chris Dumez from comment #16)
> (In reply to Chris Dumez from comment #15)
> > If I tweak NetworkLoad::didReceiveChallenge() to
> > completionHandler(AuthenticationChallengeDisposition::UseCredential,
> > serverTrustCredential(challenge)); whenever
> > challenge.protectionSpace().authenticationScheme() ==
> > ProtectionSpaceAuthenticationSchemeServerTrustEvaluationRequested, then the
> > tests no longer time out.
> 
> The problem seems to be happen when
> NetworkLoad::completeAuthenticationChallenge() is called and
> m_parameters.clientCredentialPolicy ==
> ClientCredentialPolicy::CannotAskClientForCredentials.
> 
> In such case, we call:
> completionHandler(AuthenticationChallengeDisposition::UseCredential, { });
> 
> If I replace with:
> completionHandler(AuthenticationChallengeDisposition::UseCredential,
> serverTrustCredential(*m_challenge));
> 
> Then the tests no longer time out.

So the problem is that some requests like CORS preflight use CannotAskClientForCredentials policy. As a result, the WebKitTestRunner is not asked about server trust evaluation for those and we end up doing the default behavior (which fails because certificate is not trusted).
Comment 18 Chris Dumez 2017-08-03 11:32:57 PDT
Created attachment 317133 [details]
Patch
Comment 19 Radar WebKit Bug Importer 2017-08-03 11:34:56 PDT
<rdar://problem/33704752>
Comment 20 Alexey Proskuryakov 2017-08-03 12:24:23 PDT
Comment on attachment 317133 [details]
Patch

Amazing.

Please let EWS settle down before landing.
Comment 21 Build Bot 2017-08-03 14:30:48 PDT
Comment on attachment 317133 [details]
Patch

Attachment 317133 [details] did not pass ios-sim-ews (ios-simulator-wk2):
Output: http://webkit-queues.webkit.org/results/4248260

New failing tests:
imported/w3c/web-platform-tests/fetch/api/cors/cors-no-preflight.any.worker.html
imported/w3c/web-platform-tests/fetch/api/cors/cors-basic.any.html
imported/w3c/web-platform-tests/fetch/api/cors/cors-basic.any.worker.html
imported/w3c/web-platform-tests/fetch/api/basic/mode-no-cors-worker.html
imported/w3c/web-platform-tests/fetch/api/cors/cors-origin.any.worker.html
imported/w3c/web-platform-tests/fetch/api/basic/mode-no-cors.html
imported/w3c/web-platform-tests/fetch/api/cors/cors-origin.any.html
imported/w3c/web-platform-tests/fetch/api/cors/cors-no-preflight.any.html
Comment 22 Build Bot 2017-08-03 14:30:50 PDT
Created attachment 317153 [details]
Archive of layout-test-results from ews125 for ios-simulator-wk2

The attached test failures were seen while running run-webkit-tests on the ios-sim-ews.
Bot: ews125  Port: ios-simulator-wk2  Platform: Mac OS X 10.12.5
Comment 23 youenn fablet 2017-08-03 14:37:32 PDT
(In reply to Build Bot from comment #21)
> Comment on attachment 317133 [details]
> Patch
> 
> Attachment 317133 [details] did not pass ios-sim-ews (ios-simulator-wk2):
> Output: http://webkit-queues.webkit.org/results/4248260
> 
> New failing tests:
> imported/w3c/web-platform-tests/fetch/api/cors/cors-no-preflight.any.worker.
> html
> imported/w3c/web-platform-tests/fetch/api/cors/cors-basic.any.html
> imported/w3c/web-platform-tests/fetch/api/cors/cors-basic.any.worker.html
> imported/w3c/web-platform-tests/fetch/api/basic/mode-no-cors-worker.html
> imported/w3c/web-platform-tests/fetch/api/cors/cors-origin.any.worker.html
> imported/w3c/web-platform-tests/fetch/api/basic/mode-no-cors.html
> imported/w3c/web-platform-tests/fetch/api/cors/cors-origin.any.html
> imported/w3c/web-platform-tests/fetch/api/cors/cors-no-preflight.any.html

This patch fixes issues with all these tests that now need to be rebased.
Comment 24 Chris Dumez 2017-08-03 14:53:10 PDT
(In reply to youenn fablet from comment #23)
> (In reply to Build Bot from comment #21)
> > Comment on attachment 317133 [details]
> > Patch
> > 
> > Attachment 317133 [details] did not pass ios-sim-ews (ios-simulator-wk2):
> > Output: http://webkit-queues.webkit.org/results/4248260
> > 
> > New failing tests:
> > imported/w3c/web-platform-tests/fetch/api/cors/cors-no-preflight.any.worker.
> > html
> > imported/w3c/web-platform-tests/fetch/api/cors/cors-basic.any.html
> > imported/w3c/web-platform-tests/fetch/api/cors/cors-basic.any.worker.html
> > imported/w3c/web-platform-tests/fetch/api/basic/mode-no-cors-worker.html
> > imported/w3c/web-platform-tests/fetch/api/cors/cors-origin.any.worker.html
> > imported/w3c/web-platform-tests/fetch/api/basic/mode-no-cors.html
> > imported/w3c/web-platform-tests/fetch/api/cors/cors-origin.any.html
> > imported/w3c/web-platform-tests/fetch/api/cors/cors-no-preflight.any.html
> 
> This patch fixes issues with all these tests that now need to be rebased.

Will rebaseline them and unsnap them on Mac.
Comment 25 Chris Dumez 2017-08-03 15:02:08 PDT
Created attachment 317162 [details]
Patch
Comment 26 Chris Dumez 2017-08-03 15:13:32 PDT
Created attachment 317164 [details]
Patch
Comment 27 Chris Dumez 2017-08-03 16:09:40 PDT
Created attachment 317176 [details]
Patch
Comment 28 WebKit Commit Bot 2017-08-03 18:07:27 PDT
Comment on attachment 317176 [details]
Patch

Clearing flags on attachment: 317176

Committed r220245: <http://trac.webkit.org/changeset/220245>
Comment 29 WebKit Commit Bot 2017-08-03 18:07:29 PDT
All reviewed patches have been landed.  Closing bug.