1320871 - Serviceworker hangs on respondWith a clone of a cache entry

Status: RESOLVED FIXED

(Core :: DOM: Service Workers, defect, P2)

Description

[Andrew Betts]

Attachment: 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.

Comment 1

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

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.

Comment 2

[Ben Kelly [:bkelly, not reviewing]]

This is almost certainly bug 1134372.

Comment 3

[Ben Kelly [:bkelly, not reviewing]]

Andrew, does this build fix the issue for you?

https://archive.mozilla.org/pub/firefox/try-builds/[e-mail]-d205899a034e7d4e344df51082b050547ed9afd8/try-macosx64/firefox-53.0a1.en-US.mac.dmg

Thanks.

Comment 4

[Andrew Betts]

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...

Comment 5

[Ben Kelly [:bkelly, not reviewing]]

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

Comment 6

[Ben Kelly [:bkelly, not reviewing]]

(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.

Comment 7

[Ben Kelly [:bkelly, not reviewing]]

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.

Comment 8

[Ben Kelly [:bkelly, not reviewing]]

Attachment: Add a wpt test verifying Cache API Response objects can be cloned and read. r=asuth

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.

Comment 9

[Andrew Sutherland [:asuth] (he/him)]

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

Comment 10

[Ben Kelly [:bkelly, not reviewing]]

Attachment: Add a wpt test verifying Cache API Response objects can be cloned and read. r=asuth

Comment 11

[Pulsebot]

Pushed by [e-mail]:
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

Comment 12

[Phil Ringnalda (:philor)]

https://hg.mozilla.org/mozilla-central/rev/e132c0d60a69