Serviceworker hangs on respondWith a clone of a cache entry

RESOLVED FIXED in Firefox 53

Status

()

defect
P2
normal
RESOLVED FIXED
3 years ago
3 years ago

People

(Reporter: andrew, Assigned: bkelly)

Tracking

53 Branch
mozilla53
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox53 fixed)

Details

Attachments

(2 attachments, 1 obsolete attachment)

Posted file debug-sw-clone.zip
User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/54.0.2840.98 Safari/537.36

Steps to reproduce:

Fails:

```
return event.respondWith(caches.match(event.request).then(res => res.clone()));
```

Works:

```
return event.respondWith(caches.match(event.request));
```


Actual results:

The tab spins forever, never receiving a response


Expected results:

Cloning the response object from the cache should not make a difference.

There appears to be a correlation with the size of the response.  I couldn't repro this with test content that just read "Hello world", but the 80KB page that I've included in the attached test case does trigger the failure reliably.

This bug was discovered by my colleague Ryo Yasuda at Nikkei Shimbun (www.nikkei.com) and I'm reporting it on his behalf.
Component: Untriaged → DOM: Service Workers
Product: Firefox → Core
Summary: Serviceworker hangs on respondwith a clone of a cache entry → Serviceworker hangs on respondWith a clone of a cache entry
Version: 50 Branch → 53 Branch
In today's Linux64 nightly (built from https://hg.mozilla.org/mozilla-central/rev/05328d3102efd4d5fc0696489734d7771d24459f) I see:

Debug SW

    Cache:
    Done: 3ms

    Cloned Cache:
    Running...

    Clone Response Before Return Cache:
    Done: 5014ms

    Fetch:
    Done: 12ms

    Cloned Fetch:
    Done: 12ms


Whereas in Chromium 53, I see:

Debug SW

    Cache:
    Done: 31ms

    Cloned Cache:
    Done: 32ms

    Clone Response Before Return Cache:
    Done: 31ms

    Fetch:
    Done: 49ms

    Cloned Fetch:
    Done: 38ms

Note that the "Cloned Cache" one never finishes (which I presume is the bug), and the "Clone Response Before Return Cache" one is massively slower.
Status: UNCONFIRMED → NEW
Ever confirmed: true
This is almost certainly bug 1134372.
Depends on: 1134372
Priority: -- → P2
Assignee: nobody → bkelly
Status: NEW → ASSIGNED
My colleague Ryo and I both tried this and found it would not open, my Mac says the application is damaged.  I would just check that it shows the same output as Chrome for our test case.

I'd attach the OSX error here but I'm not sure if I can do attachments on comments...
Sorry, I missed that you included a test in comment 0.  I ran it locally with the patches from bug 1134372.  It seems to fix the issue:

    Cache:                                 Done: 2ms
    Cloned Cache:                          Done: 3ms
    Clone Response Before Return Cache:    Done: 2ms
    Fetch:                                 Done: 7ms
    Cloned Fetch:                          Done: 9ms
Flags: needinfo?(andrew)
(In reply to David Baron :dbaron: ⌚️UTC-8 from comment #1)
>     Cloned Cache:
>     Running...
> 
>     Clone Response Before Return Cache:
>     Done: 5014ms

> Note that the "Cloned Cache" one never finishes (which I presume is the
> bug), and the "Clone Response Before Return Cache" one is massively slower.

The slow result is due to waiting for GC to collect the cloned Response which in turn closes its pipe input stream.  This unblocks the writer and allows the returned Response to become unstalled.

It seems like this should happen for "Cloned Cache" as well, but we must keep the original Response alive for some reason.  I'm not going to investigate this, though, since the correct solution is not to stall cloned Responses at all.
Note, I'm going to keep this bug open until I can land a Cache API specific test for cloned Responses.  While the other bug fixes the pipes we should really test at the Cache API level.  In the future the underlying mechanism will change when ReadableStream is integrated.
While this is a FF-only bug at the moment, it seems we might as well include the test in wpt to get cross-browser coverage for the case.

This deadlocks on current gecko and passes with bug 1134372 applied.
Attachment #8815855 - Flags: review?(bugmail)
Comment on attachment 8815855 [details] [diff] [review]
Add a wpt test verifying Cache API Response objects can be cloned and read. r=asuth

Review of attachment 8815855 [details] [diff] [review]:
-----------------------------------------------------------------

r=asuth with requested change or code comment explaining why it's not a concern.

::: testing/web-platform/tests/service-workers/cache-storage/script-tests/cache-match.js
@@ +203,5 @@
> +        })
> +      .then(function(response) {
> +          // Return only the clone.  We purposefully test that the other
> +          // half of the clone does not need to be read here.
> +          return response.clone().text();

It seems like you should save off the non-clone response in a variable held alive by the test closure at least until the text() promise is resolved.  As this stands, it seems like you could get a (pre-fix) timeline sorta like you mention in bug 1134372:
1. text() invoked, stalls due to writer back-pressure/buffer size limits.
2. garbage collection to the rescue, collects non-clone response, its stream gets closed letting the writer finish writing everything it has.
3. text() completes
Attachment #8815855 - Flags: review?(bugmail) → review+
Pushed by bkelly@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/e132c0d60a69
Add a wpt test verifying Cache API Response objects can be cloned and read. r=asuth
https://hg.mozilla.org/mozilla-central/rev/e132c0d60a69
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla53
You need to log in before you can comment on or make changes to this bug.