1319744 - First progress event of XHR request is fired at wrong time

Status: RESOLVED FIXED

(Core :: DOM: Core & HTML, defect)

Description

[floobleflam]

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:50.0) Gecko/20100101 Firefox/50.0
Build ID: 20161104212021

Steps to reproduce:

In JavaScript, created an XMLHttpRequest and used it to make a GET request, with handlers for the readystatechange and progress events that report the time at which they're called.


Actual results:

Once the readystatechange event signalling the change from the HEADERS_RECEIVED to the LOADING state has fired, the first progress event is fired some time (up to 118ms, in my tests) later, and typically after several other readystatechange events have been fired.


Expected results:

According to the section 4.5.6 of the XHR standard (https://xhr.spec.whatwg.org/#the-send()-method), a progress event should be fired immediately after the HEADERS_RECEIVED->LOADING readystatechange event. This is the behaviour implemented by Chrome, Opera and IE.

Comment 1

[Loic]

Could you attach a testcase, please.

Comment 2

[Hsin-Yi Tsai (she/her) [:hsinyi]]

NI floobleflam for comment 1. Thanks!

Comment 3

[floobleflam]

Attachment: Print XHR event timings to console

If you open the JS console and click the button, the timings of the XHR events for a GET request will be printed to the console.

If you compare the timings on Firefox to other browsers, you'll see that in contrast to other browsers Firefox fires the first progress event some time after the first "readystatechange - state:3" event, and typically there'll be a number of "readystatechange - state:3" events before the first progress event is fired.

Comment 4

[Shawn Huang [:shawnjohnjr][:shuang] (as a happy gecko contributor)]

I will try to investigate this bug a bit more. If anyone knows the solution, feel free to take it.

Comment 5

[Thomas Wisniewski]

I'll try to get a patch together over the next few days. This part of the spec has been in flux recently, and the web platform tests may not be covering this case properly.

Comment 6

[Thomas Wisniewski]

Attachment: 1319744-ensure_XHR_progress_events_and_loading_events_are_fired_per_spec.diff

The basic fix for this is just what one would expect; making sure to fire the first progress event when the readystate first changes over to LOADING, and then firing all the other instances just before each timer-triggered progress event (per spec).

Unfortunately, this seems to cause the test for bug 1063538 to fail, but looking at it, I'm not sure how that test ever did what it was supposed to. Not only is it 404'ing trying to XHR for needed data (because it's missing a line in its mochitest.ini), but also it aborts the XHR before it gets the progress it wants. I think I fixed the test, but it would be good to have a second pair of eyes confirm that.

On the plus side, a Samsung-contributed web platform test started passing, though only intermittently. A little investigation revealed why we've been failing it: we've been setting the total size of progress events, even when aProgressMax never told us the total size. That's not what the spec dictates.

This is easy to fix, though, because it's due to us setting mLoadTotal=mLoadTransferred in a bunch of places, when we really don't have to. We only use mLoadTotal for the purpose of knowing the total size to use for progress events anyway (aside from a couple of easy-to-change lines in CreatePartialBlob). As such I removed all that excess code, and now we're passing the test consistently.

Finally, I also fixed a support script for the XHR web platform tests which I contributed a while ago. It was busted in that it wasn't testing the sanity of multiple progress events properly, and it also wasn't checking that they were preceded by LOADING readystatechanges (a recent spec-addition).

Try seems fine with all of this (despite it running oddly broken valgrind tests for me lately, and I still don't know why): https://treeherder.mozilla.org/#/jobs?repo=try&revision=c0865d141f2d9f462b5067d9c722ac76c7e7782b

I've also run the progress tests a bunch of times locally to see if any intermittent issues are still present, but things seem fine.

baku, do you think you'll have a chance to review this anytime soon?

Comment 7

[Andrea Marchesini [:baku]]

Comment on attachment 8814750 [details] [diff] [review]
1319744-ensure_XHR_progress_events_and_loading_events_are_fired_per_spec.diff

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

Looks good to me, but tell me more about this GetSize(). Probably you just forgot to remove them (I hope so).
Send me a new version, or write a comment about it. If you just forgot, it's a r+.

::: dom/xhr/XMLHttpRequestMainThread.cpp
@@ +2114,5 @@
>      if (mDOMBlob) {
>        mResponseBlob = mDOMBlob;
>        mDOMBlob = nullptr;
>  
> +      mResponseBlob->GetSize(rv);

why do we care of calling GetSize() without taking the returned value?
Probably you want to remove this and the rv.Failed() check.

@@ +2149,5 @@
>            return rv.StealNSResult();
>          }
>  
>          mResponseBlob = Blob::Create(GetOwner(), blobImpl);
> +        mResponseBlob->GetSize(rv);

same here...

@@ +3401,2 @@
>      mLoadTransferred = aProgress;
>    

can you remove this extra space?

@@ +3793,5 @@
>    mResponseBlob = aBlob;
>    mBlobStorage = nullptr;
>  
>    ErrorResult rv;
> +  mResponseBlob->GetSize(rv);

we don't need to retrieve the size, right?

Comment 8

[Thomas Wisniewski]

Attachment: 1319744-ensure_XHR_progress_events_and_loading_events_are_fired_per_spec.diff

I only left the GetSizes() in because I wasn't certain if they were still useful as sanity checks. I'm alright with removing them, and a fresh try run also isn't complaining, so I'll carry over your r+ and request check-in: https://treeherder.mozilla.org/#/jobs?repo=try&revision=5085d22c7629ffa56dc63a632682a6b7871424be

Comment 9

[Carsten Book [:Tomcat]]

needs rebasing

Comment 10

[Carsten Book [:Tomcat]]

never mind fixed it :) my bad :)

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/b16d8bed26b4
Ensure that progress events and corresponding LOADING readystatechanges fire as per spec. r=baku

Comment 12

[Carsten Book [:Tomcat]]

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

Comment 13

[Thomas Wisniewski]

Thanks tomcat! Thanks baku!

Comment 14

[Ryan VanderMeulen [:RyanVM]]

Thomas, this bug was recently discovered to have fixed an e10s hang bug over in bug 1317730. I've confirmed locally that the patch applies cleanly to Beta as well. Can you please request Beta approval on the patch unless there's a strong reason against doing so? Thanks!

Comment 15

[Thomas Wisniewski]

Comment on attachment 8818361 [details] [diff] [review]
1319744-ensure_XHR_progress_events_and_loading_events_are_fired_per_spec.diff

Approval Request Comment

[Feature/Bug causing the regression]:

[User impact if declined]: XMLHttpRequest spec-compliance flaw which has been found to cause lock-ups on at least one XHR-heavy site in E10S mode (see bug 1317730). Essentially, some events are fired a bit earlier, to match the spec. The actual number and order of events remains the same.

[Is this code covered by automated tests?]: yes

[Has the fix been verified in Nightly?]: yes

[Needs manual test from QE? If yes, steps to reproduce]: no

[List of other uplifts needed for the feature/fix]: none

[Is the change risky?]: medium risk

[Why is the change risky/not risky?]: risky in that the change affects XMLHttpRequests in general. However the patch is restricted to just the timing of event firing, makes Firefox better-match other UAs, and has ridden to Aurora without known issues so far.

[String changes made/needed]: none

Comment 16

[Julien Cristau [:jcristau]]

Comment on attachment 8818361 [details] [diff] [review]
1319744-ensure_XHR_progress_events_and_loading_events_are_fired_per_spec.diff

send xhr progress events at the right time, beta52+

Comment 17

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-beta/rev/462a50df3d93