Bug 205286 - REGRESSION: [ Mac wk2 ] imported/w3c/web-platform-tests/service-workers/service-worker/update-no-cache-request-headers.https.html is a flaky failure
Summary: REGRESSION: [ Mac wk2 ] imported/w3c/web-platform-tests/service-workers/servi...
Status: RESOLVED FIXED
Alias: None
Product: WebKit
Classification: Unclassified
Component: Service Workers (show other bugs)
Version: WebKit Nightly Build
Hardware: Unspecified Unspecified
: P2 Normal
Assignee: Chris Dumez
URL: https://github.com/web-platform-tests...
Keywords: InRadar
Depends on:
Blocks:
 
Reported: 2019-12-16 10:42 PST by Truitt Savell
Modified: 2019-12-16 15:33 PST (History)
8 users (show)

See Also:


Attachments
Patch (3.47 KB, patch)
2019-12-16 13:43 PST, 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 Truitt Savell 2019-12-16 10:42:45 PST
imported/w3c/web-platform-tests/service-workers/service-worker/update-no-cache-request-headers.https.html

This test is a flakey failure on Mac WK2. It began failing around r253457

History:
https://results.webkit.org/?suite=layout-tests&test=imported%2Fw3c%2Fweb-platform-tests%2Fservice-workers%2Fservice-worker%2Fupdate-no-cache-request-headers.https.html

Diff:
--- /Volumes/Data/slave/highsierra-release-tests-wk2/build/layout-test-results/imported/w3c/web-platform-tests/service-workers/service-worker/update-no-cache-request-headers.https-expected.txt
+++ /Volumes/Data/slave/highsierra-release-tests-wk2/build/layout-test-results/imported/w3c/web-platform-tests/service-workers/service-worker/update-no-cache-request-headers.https-actual.txt
@@ -1,3 +1,3 @@
 
-PASS headers in no-cache mode 
+FAIL headers in no-cache mode promise_test: Unhandled rejection with value: object "TypeError: null is not an object (evaluating 'newWorker.postMessage')"
 

I am able to reproduced this failure by simply running the test, but I could not find a regression point due to the test continuing to fail locally on any revision.
Comment 1 Radar WebKit Bug Importer 2019-12-16 10:43:36 PST
<rdar://problem/57976344>
Comment 2 Chris Dumez 2019-12-16 12:36:56 PST
This particular test was not updated in r253457.
Comment 3 Chris Dumez 2019-12-16 12:40:38 PST
The test seems to do:
  await registration.update();
  const newWorker = registration.installing;

And sometimes, newWorker is null. This may indicate the service worker is already done installing and is now activating or activated.
Comment 4 Chris Dumez 2019-12-16 12:47:07 PST
(In reply to Chris Dumez from comment #2)
> This particular test was not updated in r253457.

test-request-headers-worker.js & test-request-headers-worker.py were however updated in r253457 and are both used by update-no-cache-request-headers.https.html.
Comment 5 Chris Dumez 2019-12-16 12:59:45 PST
Looks like I can reproduce like so:
run-webkit-tests --repeat-each=100 imported/w3c/web-platform-tests/service-workers/service-worker/update-no-cache-request-headers.https.html -f
Comment 6 Chris Dumez 2019-12-16 13:11:21 PST
(In reply to Chris Dumez from comment #5)
> Looks like I can reproduce like so:
> run-webkit-tests --repeat-each=100
> imported/w3c/web-platform-tests/service-workers/service-worker/update-no-
> cache-request-headers.https.html -f

When it fails, the registration has no installing or waiting worker. It only an an active worker, which is the same one as before the update.
Comment 7 Chris Dumez 2019-12-16 13:16:20 PST
We fail because of this check:
    // If newestWorker is not null, newestWorker's script url equals job's script url with the exclude fragments
    // flag set, and script's source text is a byte-for-byte match with newestWorker's script resource's source
    // text, then:
    if (newestWorker && equalIgnoringFragmentIdentifier(newestWorker->scriptURL(), job.scriptURL) && result.script == newestWorker->script()) {

in SWServerJobQueue::scriptFetchFinished(const ServiceWorkerFetchResult&).

test-request-headers-worker.js is supposed to include a timestamp to make it unique. Maybe the initial install and the update happen so quickly after one another that the timestamp does not have time to change.
Comment 8 Chris Dumez 2019-12-16 13:29:58 PST
Indeed, it seems that if I replace the timestamp in the script with a uuid, the test is no longer flaky:
diff --git a/LayoutTests/imported/w3c/web-platform-tests/service-workers/service-worker/resources/test-request-headers-worker.py b/LayoutTests/imported/w3c/web-platform-tests/service-workers/service-worker/resources/test-request-headers-worker.py
index d3057057763..e7bdea368dd 100644
--- a/LayoutTests/imported/w3c/web-platform-tests/service-workers/service-worker/resources/test-request-headers-worker.py
+++ b/LayoutTests/imported/w3c/web-platform-tests/service-workers/service-worker/resources/test-request-headers-worker.py
@@ -1,6 +1,7 @@
 import json
 import os
 import time
+import uuid
 
 def main(request, response):
   path = os.path.join(os.path.dirname(__file__),
@@ -9,7 +10,7 @@ def main(request, response):
 
   data = {key:request.headers[key] for key,value in request.headers.iteritems()}
   body = body.replace("%HEADERS%", json.dumps(data))
-  body = body.replace("%TIMESTAMP%", str(time.time()))
+  body = body.replace("%TIMESTAMP%", str(uuid.uuid4()))
 
   headers = []
   headers.append(("ETag", "etag"))
Comment 9 Chris Dumez 2019-12-16 13:43:48 PST
Created attachment 385807 [details]
Patch
Comment 10 WebKit Commit Bot 2019-12-16 15:33:27 PST
Comment on attachment 385807 [details]
Patch

Clearing flags on attachment: 385807

Committed r253592: <https://trac.webkit.org/changeset/253592>
Comment 11 WebKit Commit Bot 2019-12-16 15:33:29 PST
All reviewed patches have been landed.  Closing bug.