Aborted XHR requests are reported as "CORS Same Origin Policy disallows" in web console

RESOLVED FIXED in Firefox 42

Status

()

defect
RESOLVED FIXED
4 years ago
a month ago

People

(Reporter: cpeterson, Assigned: ckerschb)

Tracking

(Blocks 2 bugs)

unspecified
mozilla42
x86
macOS
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox39 affected, firefox40 affected, firefox41 affected, firefox42 fixed)

Details

(URL)

Attachments

(2 attachments, 1 obsolete attachment)

(Reporter)

Description

4 years ago
STR:
1. Play the first video ("Sintel (Multilanguage & Subtitles) - SegmentTemplate") at http://www.dash-player.com/demo/streaming-server-and-encoder-support/
2. Watch the web console for the video player making XHR requests for MSE video segments.
3. Quickly seek ahead a few times in the video progress bar.

RESULT:
The video player will abort some of the XHR requests to bitcdn-global1.bitmovin.com before it seeks ahead. The aborted requests will "fail" with unexpected CORS Same-Origin errors, but subsequent XHR requests to bitcdn-global1.bitmovin.com succeed.


Cross-Origin Request Blocked: The Same Origin Policy disallows reading the remote resource at http://bitcdn-global1.bitmovin.com/content/sintel/audio/stereo/en/128kbit/segment_142.m4s. (Reason: CORS request failed). <unknown>
Cross-Origin Request Blocked: The Same Origin Policy disallows reading the remote resource at http://bitcdn-global1.bitmovin.com/content/sintel/video/800kbit/segment_134.m4s. (Reason: CORS request failed). <unknown>
GET 
XHR 
http://bitcdn-global1.bitmovin.com/content/sintel/audio/stereo/en/128kbit/segment_158.m4s [HTTP/1.1 200 OK 445ms]
GET 
XHR 
http://bitcdn-global1.bitmovin.com/content/sintel/video/250kbit/segment_156.m4s [HTTP/1.1 200 OK 516ms]
(Reporter)

Updated

4 years ago
Blocks: 1152587
Can this be reproduced with an ordinary XHR and a call to .abort()?  (That is, can the test be done without the video player aspect?)
(Reporter)

Comment 2

4 years ago
I don't have a simpler test case, but this looks like the same problem reported in bug 1094911.
See Also: → 1094911
(Reporter)

Comment 3

4 years ago
This issue makes debugging more confusing, but does not need to block Adobe EME MVP.
No longer blocks: 1032660
Yeah, this is slightly bogus.  In nsCORSListenerProxy::CheckRequestApproved, it seems like if there was a necko-level failure we should just silently return that error and not log anything to the console instead of logging a string with the CORSRequestFailed message.  Jonas, do you recall why we're doing this, exactly?
Flags: needinfo?(jonas)
Generally the CORS code wants to ensure that any network error or CORS errors just looks like a generic "something went wrong with the request" error to the calling page.

That means that the in theory, the CORS code might in some cases might hide some information from the webpage. In that case you could make an argument for exposing that hidden information in the error console.

However we don't expose particularly detailed error information through XHR anyway, so I doubt that we're actually hiding anything. So not putting anything in the console seems totally fine.

The network panel in the developer console is likely the best way to debug any problems here anyway.
Flags: needinfo?(jonas)
Can we get this issue cleaned up. It is a red herring for people who have playback issue.
Flags: needinfo?(jonas)
I think we know what needs to be done. We just need someone to do it. I don't really have time for writing patches these days so we'll need to find someone else.

What needs to be done here is to remove the two calls to LogBlockedRequest here:

http://mxr.mozilla.org/mozilla-central/source/dom/security/nsCORSListenerProxy.cpp#540
http://mxr.mozilla.org/mozilla-central/source/dom/security/nsCORSListenerProxy.cpp#544
Flags: needinfo?(jonas)
We should also remove that error message from the localization files, since that's the only place it is used.
(Reporter)

Updated

4 years ago
Blocks: 1160447
(Assignee)

Updated

4 years ago
Assignee: nobody → mozilla
Blocks: 1152119
Status: NEW → ASSIGNED
(Assignee)

Updated

4 years ago
No longer blocks: 1152119
Duplicate of this bug: 1152119
In fact the problem was introduced within Bug 1121824 which landed in 38. If that incorrect console messaging is bothering people a lot, we might consider uplifting since it's a trivial fix.
Attachment #8636222 - Flags: review?(jonas)
(Assignee)

Updated

4 years ago
Blocks: 1121824
Comment on attachment 8636222 [details] [diff] [review]
bug_1152574_xhr_cors.patch

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

Thanks!!
Attachment #8636222 - Flags: review?(jonas) → review+
(Assignee)

Updated

4 years ago
Keywords: checkin-needed
sorry had to back this out for causing memory leaks like https://treeherder.mozilla.org/logviewer.html#?job_id=11940396&repo=mozilla-inbound
Flags: needinfo?(mozilla)
(In reply to Carsten Book [:Tomcat] from comment #13)
> sorry had to back this out for causing memory leaks like
> https://treeherder.mozilla.org/logviewer.html#?job_id=11940396&repo=mozilla-
> inbound

Carsten, Ryan, are you sure that this patch is causing the problem? Looking at the patch that seems to be very unlikely, since we are just not logging a particular error to the console anymore. I am very willing to figure out what's going on but at the moment I can't see that this patch might cause the problem. Any suggestions?
Flags: needinfo?(ryanvm)
Flags: needinfo?(mozilla)
Flags: needinfo?(cbook)
I haven't seen any leaks on inbound since it was backed out.
Flags: needinfo?(ryanvm)
Flags: needinfo?(cbook)
Were there leaks on other platform too, or just mac 10.6?  Because I agree with comment 15; it's hard to see how this patch could cause leaks....
My guess would be that the removed error string somehow moved stuff around that we're triggering an existing bug. I can't think of any possible other ways that this could cause a leak.

So maybe we can try to land a change that simply doesn't remove that string?
Posted patch bug_1152574_xhr_cors_v2.patch (obsolete) — Splinter Review
(In reply to Jonas Sicking (:sicking) from comment #19)
> My guess would be that the removed error string somehow moved stuff around
> that we're triggering an existing bug. I can't think of any possible other
> ways that this could cause a leak.
> 
> So maybe we can try to land a change that simply doesn't remove that string?

Ryan, what do you think? Can we try that? If so, here is the patch without removing the error string in security.properties.
Flags: needinfo?(ryanvm)
Attachment #8636666 - Flags: review+
Sounds like something you could test on Try first. I have no opinion beyond "don't turn the tree orange" :)
Flags: needinfo?(ryanvm)
(In reply to Christoph Kerschbaumer [:ckerschb] from comment #22)
> https://treeherder.mozilla.org/#/jobs?repo=try&revision=a112fcb3d8b7

Not a clue what might go wrong here, but it's still perma-orange. Let's wait a few days and push to try again, unless someone has any other suggestions :-(
Is it orange on other platforms too?
(In reply to Boris Zbarsky [:bz] from comment #24)
> Is it orange on other platforms too?

Let's find out and let's try this once again, I can't imagine what might go wrong here:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=da17c1333278
(Reporter)

Comment 26

4 years ago
Christoph, this leak looks real. Your try push is orange on Linux, OS X, and Windows XP–8. Who is familiar with this code that might recognize this mystery leak?

 TEST-UNEXPECTED-FAIL | leakcheck | default process: 494518 bytes leaked (AsyncLatencyLogger, AsyncStatement, AtomImpl, BackstagePass, BodyRule, ...)
Flags: needinfo?(mozilla)
If it happens reliably on Linux get it in rr and debug it.
FWIW, that leak is reproducible on my machine if I run that test by itself without your patch.
My theory is that the console messages that you are no longer sending were evicting other messages from the console service that are the ones causing the leak.
Yeah, I was thinking that too.

Whatever the reason, I can with almost 100% certainty say that this patch is not the *cause* of the leak. Unfortunately that doesn't really change anything since we can't check in a patch which causes mochitest to permanently go orange.
At least we have a testcase that can reliably reproduce the problem:
http://mxr.mozilla.org/mozilla-central/source/dom/tests/mochitest/bugs/test_bug414291.html?force=1#21
you can even comment out the other two tests underneath.
Flags: needinfo?(mozilla)
Andrew, Nathan, when browsing through the logs I see you have worked on the console quite a bit, any ideas what might go wrong here?
Flags: needinfo?(nfroyd)
Flags: needinfo?(continuation)
Nathan and I don't really know anything about Console. baku might be able to provide some useful information. I do know about generic leak finding stuff.
Flags: needinfo?(nfroyd)
Flags: needinfo?(continuation)
Flags: needinfo?(amarchesini)
I have it under control.
Flags: needinfo?(amarchesini)
http://hg.mozilla.org/mozilla-central/rev/3e98575b1f9d is bogus, because ScriptErrorEvent is asynchronous.  We should do the clearing off of inner-window-destroyed instead.

ckerschb, want to try this with your patch?
Flags: needinfo?(mozilla)
Attachment #8641233 - Flags: review?(nfroyd)
(Assignee)

Updated

4 years ago
Attachment #8636666 - Attachment is obsolete: true
Flags: needinfo?(mozilla)
Works just (In reply to Kyle Huey [:khuey] (khuey@mozilla.com) from comment #35)
> ckerschb, want to try this with your patch?

No more leaks - hurray - thanks khuey!
Depends on: 814497
Comment on attachment 8641233 [details] [diff] [review]
0001-Bug-1152574-Fix-console-service-discarding-to-run-wh.patch

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

So the problem is that somebody was injecting console messages for a window between the point where we cleared them, and the point where the inner window actually went away?

::: dom/ipc/ContentParent.cpp
@@ +4301,5 @@
>      // just an nsIConsoleService). This allows us to call the non-idl function
>      // nsConsoleService::LogMessageWithMode.
>      NS_DEFINE_CID(consoleServiceCID, NS_CONSOLESERVICE_CID);
> +    nsCOMPtr<nsIConsoleService> consoleService(do_GetService(consoleServiceCID));
> +    mConsoleService = static_cast<nsConsoleService*>(consoleService.get());

Please file a followup for making this less lame.

::: xpcom/base/nsConsoleService.cpp
@@ +92,5 @@
>      NS_RELEASE(mMessages[i]);
>  
>      uint32_t j = i;
>      // Now shift all the following messages
> +    // XXXkhuey this is not an efficient way to iterate through an array ...

Can you file a followup bug to fix this?  I suck for OK'ing accidentally quadratic things here, and doing this on every window destruction isn't going to be particularly efficient.
Attachment #8641233 - Flags: review?(nfroyd) → review+
(In reply to Nathan Froyd [:froydnj][:nfroyd] from comment #37)
> Comment on attachment 8641233 [details] [diff] [review]
> 0001-Bug-1152574-Fix-console-service-discarding-to-run-wh.patch
> 
> Review of attachment 8641233 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> So the problem is that somebody was injecting console messages for a window
> between the point where we cleared them, and the point where the inner
> window actually went away?

Yes.
(In reply to Nathan Froyd [:froydnj][:nfroyd] from comment #37)
> Comment on attachment 8641233 [details] [diff] [review]
> 0001-Bug-1152574-Fix-console-service-discarding-to-run-wh.patch
> 
> Review of attachment 8641233 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> So the problem is that somebody was injecting console messages for a window
> between the point where we cleared them, and the point where the inner
> window actually went away?
> 
> ::: dom/ipc/ContentParent.cpp
> @@ +4301,5 @@
> >      // just an nsIConsoleService). This allows us to call the non-idl function
> >      // nsConsoleService::LogMessageWithMode.
> >      NS_DEFINE_CID(consoleServiceCID, NS_CONSOLESERVICE_CID);
> > +    nsCOMPtr<nsIConsoleService> consoleService(do_GetService(consoleServiceCID));
> > +    mConsoleService = static_cast<nsConsoleService*>(consoleService.get());
> 
> Please file a followup for making this less lame.

Bug 1189827.

> ::: xpcom/base/nsConsoleService.cpp
> @@ +92,5 @@
> >      NS_RELEASE(mMessages[i]);
> >  
> >      uint32_t j = i;
> >      // Now shift all the following messages
> > +    // XXXkhuey this is not an efficient way to iterate through an array ...
> 
> Can you file a followup bug to fix this?  I suck for OK'ing accidentally
> quadratic things here, and doing this on every window destruction isn't
> going to be particularly efficient.

Bug 1189829.
Keywords: leave-open
You should be able to land your stuff now.
Flags: needinfo?(mozilla)
Keywords: leave-open
url:        https://hg.mozilla.org/integration/mozilla-inbound/rev/0b05974fd3b0c351cdd93143d0de0652a99f626d
changeset:  0b05974fd3b0c351cdd93143d0de0652a99f626d
user:       Christoph Kerschbaumer <mozilla@christophkerschbaumer.com>
date:       Mon Jul 20 13:59:19 2015 -0700
description:
Bug 1152574 - Do not report aborted XHR requests in web console (r=sicking)
(In reply to Kyle Huey [:khuey] (khuey@mozilla.com) from comment #42)
> You should be able to land your stuff now.

Thanks Kyle!
Flags: needinfo?(mozilla)
https://hg.mozilla.org/mozilla-central/rev/0b05974fd3b0
Status: ASSIGNED → RESOLVED
Last Resolved: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla42
Component: DOM → DOM: Core & HTML
Product: Core → Core
You need to log in before you can comment on or make changes to this bug.