1464090 - [Firefox Screenshots] Save Full page functionality for large websites no longer works on latest Nightly builds

Status: VERIFIED FIXED

(Core :: Networking, defect, P1)

Description

[Cosmin Muntean [:cmuntean], Ecosystem QA]

Attachment: Full page.mp4

[Affected versions]:
- Nightly 62.0a1, Build ID: 20180524100118

[Affected Platforms]:
- All Windows
- All Mac
- All Linux

[Steps to reproduce]:
1. Open latest Nightly build and navigate to "https://www.imdb.com/" page.
2. From the "Page Actions" menu click the "Take a Screenshot" button.
3. Click the "Save full page" option from the top right corner of the page.
4. Click the "Save" button.
5. Observe the behavior.

[Expected result]:
- The shot is successfully saved.

[Actual results]:
- The shot is not saved and a "Out of order." notification error is displayed.
 
[Regression]:
Last good revision: 133a13c44abedac2e448d315a32068ce1a5568f4
First bad revision: 66f6b8d84e5d35d0de8d07d3e9de44a9cce913f2
Pushlog: https://goo.gl/KTWYh3

From the provided pushlog it seems that bug 1434553 introduced this issue.
 
[Notes]:
- Here is screenshot of the browser console errors: https://goo.gl/vyZbyu
- Attached a screen recording with the issue.

Comment 1

[Cosmin Muntean [:cmuntean], Ecosystem QA]

@Andrea can you please take a look at this issue?

Comment 2

[Andrea Marchesini [:baku]]

I'm not able to reproduce it. I just tested it with the latest nightly and it works.
Do you try a debug build? Maybe there is something useful in stderr/stdout. Thanks.

Comment 3

[Cosmin Muntean [:cmuntean], Ecosystem QA]

I have retested on 3 different machines (Mac 10.13, Windows 10 x64 and Windows 7 x64) using latest Nightly (62.0a1, Build ID: 20180525005138) with a new clean profile and the issue is still reproducible.
Can you please try to reproduce the issue on "https://www.imdb.com/" or "https://www.youtube.com/" page? It seems that the issue is also reproducible for the "Save visible" option.

Also, I am not sure how to debug the build in order to get the stderr/stdout logs, but I can try if you can provide more information regarding how to do it.

Comment 4

[Mike Taylor [:miketaylr]]

I'm able to reproduce. Here's what I see in the browser toolbox console:

Handler function threw an exception: [Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIHttpChannelInternal.remoteAddress]"  nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)"  location: "JS frame :: resource://devtools/shared/base-loader.js -> resource://devtools/shared/webconsole/network-monitor.js :: _onResponseHeader :: line 1382"  data: no]
Stack: _onResponseHeader@resource://devtools/shared/base-loader.js -> resource://devtools/shared/webconsole/network-monitor.js:1382:5
_dispatchActivity@resource://devtools/shared/base-loader.js -> resource://devtools/shared/webconsole/network-monitor.js:1024:9
NetworkMonitor.prototype.observeActivity<@resource://devtools/shared/base-loader.js -> resource://devtools/shared/webconsole/network-monitor.js:1086:7
exports.makeInfallible/<@resource://devtools/shared/base-loader.js -> resource://devtools/shared/ThreadSafeDevToolsUtils.js:109:14
Line: 1382, column: 0 ThreadSafeDevToolsUtils.js:88:5
------Error in promise: <unavailable> catcher.js:74:11
uploadShot/<@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/takeshot.js:216:21
promise callback*uploadShot@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/takeshot.js:186:12
@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/takeshot.js:64:14
promise callback*@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/takeshot.js:47:33
watchFunction/<@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/catcher.js:55:16
exports.onMessage<@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/communication.js:25:16
watchFunction/<@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/catcher.js:55:16
@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/startBackground.js:49:14
promise callback*@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/startBackground.js:48:5
catcher.js:75:11
Unhandled error: 
Object { fromMakeError: true, name: "Error", message: "Error: Response failed with status 400", stack: "uploadShot/<@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/takeshot.js:216:21\npromise callback*uploadShot@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/takeshot.js:186:12\n@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/takeshot.js:64:14\npromise callback*@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/takeshot.js:47:33\nwatchFunction/<@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/catcher.js:55:16\nexports.onMessage<@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/communication.js:25:16\nwatchFunction/<@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/catcher.js:55:16\n@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/startBackground.js:49:14\npromise callback*@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/startBackground.js:48:5\n", popupMessage: "REQUEST_ERROR" }
 undefined catcher.js:17:7
Promise error in takeShot: <unavailable> uploadShot/<@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/takeshot.js:216:21
promise callback*uploadShot@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/takeshot.js:186:12
@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/takeshot.js:64:14
promise callback*@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/takeshot.js:47:33
watchFunction/<@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/catcher.js:55:16
exports.onMessage<@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/communication.js:25:16
watchFunction/<@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/catcher.js:55:16
@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/startBackground.js:49:14
promise callback*@moz-extension://34dc2403-c2b8-fc40-b906-01c222ae03a2/background/startBackground.js:48:5
communication.js:36:9
Content Security Policy: Ignoring ‘x-frame-options’ because of ‘frame-ancestors’ directive.
Loading failed for the <script> with source “https://screenshotscdn.firefox.com/static/locales/en-US.js?rev=31.4.0-2-ga06bf6df”.

Comment 5

[Mike Taylor [:miketaylr]]

Attachment: imdb-screenshot (mac)

Comment 6

[Mike Taylor [:miketaylr]]

> Error: Response failed with status 400

Perhaps people working on the upload server backend could help verify if this is exploding due to a Content-Length mismatch.

Comment 7

[Markus Stange [:mstange]]

Attachment: geckoprofilerprofile.json.gz

I have different steps to reproduce for what's likely to be the same problem.

STR:
 1. Download the attached profile.
 2. Go to https://perf-html.io/
 3. Drag the file into it, or load it from the file input button.
 4. Attempt to share the profile using the green share button in the top right corner.

Before bug 1434553, the upload would progress and then succeed. After bug 1434553 the request fails. The network monitor shows no response, no response headers, and no status code.

This problem does not occur with very small profiles.

This is impacting the profiler in a serious way, maybe bug 1434553 should be backed out.

Comment 8

[Markus Stange [:mstange]]

The same STR work correctly in Chrome.

Comment 9

[Andrea Marchesini [:baku]]

> Before bug 1434553, the upload would progress and then succeed. After bug
> 1434553 the request fails. The network monitor shows no response, no
> response headers, and no status code.

Are you talking about the XHR failure? I'm debugging that.

Comment 10

[Markus Stange [:mstange]]

Yes.

Comment 12

[Andrea Marchesini [:baku]]

Attachment: part 1 - InputStreamLengthHelper must copy streams if nsIAsyncInputStream

This happens because in bug 1434553 I removed this chunk of code:

https://searchfox.org/mozilla-central/rev/4d342e4ebfd17a1519a576027717005108087869/netwerk/protocol/http/HttpChannelParent.cpp#605-662

That part is still needed because, when a stream is sent from child to parent, if the length is > 1mb, we send data in chunks using IPCStream:

https://searchfox.org/mozilla-central/rev/5a744713370ec47969595e369fd5125f123e6d24/ipc/glue/IPCStream.ipdlh

which creates a pipe on the destination side:

https://searchfox.org/mozilla-central/rev/5a744713370ec47969595e369fd5125f123e6d24/ipc/glue/IPCStreamDestination.cpp#287-291

The final stream is a nsIAsyncInputStream. InputStreamLengthHelper calls ::Available(), doing the wrong operation, because ::Available() returns what can be read at the moment, and not the full stream size.

Instead of reintroducing that chunk of code, I prefer to have a more generic solution and make InputStreamLengthHelper able to do the operation of duplicating the stream in memory.

This first patch does:

1. it introduces the copy-logic into GetAsyncLength(). This requires an extra 'replacementStream' parameter.

2. it enforces that the callback is nullified on the owning thread.

This patch fixes the issue. The next patches avoid the extra copy when IPCStream knows the length on the child side.

Comment 13

[Andrea Marchesini [:baku]]

Attachment: part 1 - InputStreamLengthWrapper

This patch has been already reviewed by froydnj in bug 1434553 comment 82.

Comment 14

[Andrea Marchesini [:baku]]

Attachment: part 2 - passing the length if known via IPCStream

Using InputStreamLengthWrapper in IPCStream if the length is known.

Comment 15

[Andrea Marchesini [:baku]]

Attachment: part 4 - gtest

Comment 16

[Andrea Marchesini [:baku]]

Having patch 2 and patch 3 avoids the dup of the stream in memory. The stream is an ArrayBuffer inputStream and its size is known. We don't need to duplicate the stream on the parent side, but just wrap it with InputStreamLengthWrapper.

Comment 17

[Honza Bambas (:mayhemer)]

Comment on attachment 8981768 [details] [diff] [review]
part 1 - InputStreamLengthHelper must copy streams if nsIAsyncInputStream

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

First of all I ask one thing: does the source of the stream (the code on the child process) know the size of the stream?  Could it be sent along as an argument somehow?  somehow I hoped that this work would exactly remove that piece of code _for good_.  and now it has to come back and waste memory, CPU, and delay processing that could potentially be streamed.

::: xpcom/io/InputStreamLengthHelper.cpp
@@ +304,5 @@
>  
>      // All good!
>      if (NS_SUCCEEDED(rv)) {
>        mCallback(length);
> +      mCallback = nullptr;

this prevents leaks?  or is it some kind of a reentrancy protection?  If the latter, than you should swap mCallback to a local and call from the local.

Comment 18

[Honza Bambas (:mayhemer)]

comment 17

Comment 19

[Andrea Marchesini [:baku]]

> First of all I ask one thing: does the source of the stream (the code on the

This is what patches 2 and 3 do. If you prefer, we can just land patch 2 and 3 and add a MOZ_DIAGNOSTIC_ASSERT() to detect when a nsIAsyncInputStream is passed to InputStreamLengthHelper. When we see crashes, we fix the callers. This was actually my first approach, and it works. The reason why I also proposed patch 1 is because I would like to have InputStreamLengthHelper able to work in any case, also with nsIAsyncInputStreams.

About mCallback set to null, yes, it's to avoid the releasing of mCallback in a non-owning thread. I'll replace that code with a swap().

Comment 20

[Nathan Froyd [:froydnj]]

Comment on attachment 8981770 [details] [diff] [review]
part 2 - passing the length if known via IPCStream

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

I think this makes sense.  I'd feel slightly better if Honza reviewed this too (perhaps he is looking at it as a result of reviewing patch 1).

::: ipc/glue/IPCStreamDestination.cpp
@@ +318,5 @@
> +
> +  if (aLength != -1) {
> +    nsCOMPtr<nsIInputStream> finalStream;
> +    finalStream = new InputStreamLengthWrapper(mReader.forget(), aLength);
> +    mReader = do_QueryInterface(finalStream);

Is it possible to just directly upcast here, rather than going through QI?

Comment 21

[Honza Bambas (:mayhemer)]

Comment on attachment 8981769 [details] [diff] [review]
part 1 - InputStreamLengthWrapper

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

::: xpcom/io/InputStreamLengthWrapper.cpp
@@ +120,5 @@
> +NS_IMETHODIMP
> +InputStreamLengthWrapper::ReadSegments(nsWriteSegmentFun aWriter, void* aClosure,
> +                                       uint32_t aCount, uint32_t *aResult)
> +{
> +  return NS_ERROR_NOT_IMPLEMENTED;

why can't this forward as well?  if the underlying stream is buffered and actually implements ReadSegments, we force the consumer to use Read() and copy the buffer unnecessarily.

@@ +138,5 @@
> +{
> +  NS_ENSURE_STATE(mInputStream);
> +  NS_ENSURE_STATE(mWeakCloneableInputStream);
> +  mWeakCloneableInputStream->GetCloneable(aCloneable);
> +  return NS_OK;

return mWeakCloneableInputStream->GetCloneable(aCloneable); ?

@@ +201,5 @@
> +
> +      // Abort current operation.
> +      callback = nullptr;
> +    }
> +  }

can we simplify as e.g. at https://searchfox.org/mozilla-central/rev/83a923ef7a3b95a516f240a6810c20664b1e0ac9/netwerk/base/nsBufferedStreams.cpp#698-707 ?

Comment 22

[Honza Bambas (:mayhemer)]

(In reply to Andrea Marchesini [:baku] from comment #19)
> > First of all I ask one thing: does the source of the stream (the code on the
> 
> This is what patches 2 and 3 do. If you prefer, we can just land patch 2 and
> 3 and add a MOZ_DIAGNOSTIC_ASSERT() to detect when a nsIAsyncInputStream is
> passed to InputStreamLengthHelper. When we see crashes, we fix the callers.
> This was actually my first approach, and it works. 

I'd really try to go that way first.  If it becomes too much pain, we can introduce the callback (patch 1).

> The reason why I also
> proposed patch 1 is because I would like to have InputStreamLengthHelper
> able to work in any case, also with nsIAsyncInputStreams.

Don't you want to rather say "with streams not implementing Length/AsyncLength" interfaces?

> 
> About mCallback set to null, yes, it's to avoid the releasing of mCallback
> in a non-owning thread. I'll replace that code with a swap().

Thanks.

Comment 23

[Honza Bambas (:mayhemer)]

Comment on attachment 8981771 [details] [diff] [review]
part 4 - gtest

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

errr... when we don't have the patch 1, this test is not valid, right?

Comment 24

[Honza Bambas (:mayhemer)]

(In reply to Honza Bambas (:mayhemer) from comment #23)
> Comment on attachment 8981771 [details] [diff] [review]
> part 4 - gtest
> 
> Review of attachment 8981771 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> errr... when we don't have the patch 1, this test is not valid, right?

BTW, the added argument that returns a new stream is IMO not a good API.  It's quite unexpected that a "const" function would create something new.

Comment 25

[Andrea Marchesini [:baku]]

Attachment: part 3 - swap callbacks

Comment 26

[Andrea Marchesini [:baku]]

Attachment: part 4 - assertion in GetAsyncLength

Note that GetSyncLength doesn't assert because the serialization from child-to-parent (or viceversa) is supported for nsIAsyncInputStream. We just don't want them to be used in HttpChannel. Only GetAsyncLength asserts.

Comment 27

[Honza Bambas (:mayhemer)]

Comment on attachment 8982228 [details] [diff] [review]
part 4 - assertion in GetAsyncLength

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

thanks!

Comment 28

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/c36cbbfd1033
Implement InputStreamLengthWrapper to make any stream nsIInputStreamLength and nsIAsyncInputStreamLength, r=froydnj
https://hg.mozilla.org/integration/mozilla-inbound/rev/ab037c88ae18
Passing the length if known via IPCStream and use InputStreamLengthWrapper when deserialized, r=froydnj, r=mayhemer
https://hg.mozilla.org/integration/mozilla-inbound/rev/a1ce34b0b183
InputStreamLengthHelper must swap the callback in order to release them on the owning thread, r=mayhemer
https://hg.mozilla.org/integration/mozilla-inbound/rev/833f1e224c88
Assertion in InputStreamLengthHelper::GetAsyncLength to avoid dealing with nsIAsyncInputStream, r=mayhemer

Comment 29

[Noemi Erli[:noemi_erli]]

https://hg.mozilla.org/mozilla-central/rev/c36cbbfd1033
https://hg.mozilla.org/mozilla-central/rev/ab037c88ae18
https://hg.mozilla.org/mozilla-central/rev/a1ce34b0b183
https://hg.mozilla.org/mozilla-central/rev/833f1e224c88

Comment 31

[Cosmin Muntean [:cmuntean], Ecosystem QA]

I have verified this issue on latest Nightly (62.0a1 Build ID: 20180604161157) and the issue is no longer reproducible. Tested on Windows 7 x64, Windows 10 x64, Arch Linux and Mac 10.13.