The default bug view has changed. See this FAQ.

Mochitest failure: test_access_control.html

RESOLVED FIXED in mozilla1.9.3a1

Status

()

Core
Audio/Video
RESOLVED FIXED
8 years ago
4 years ago

People

(Reporter: Ehsan, Assigned: roc)

Tracking

({intermittent-failure})

Trunk
mozilla1.9.3a1
intermittent-failure
Points:
---
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(5 attachments)

(Reporter)

Description

8 years ago
WINNT 5.2 mozilla-central test debug mochitests-1/5 on 2009/11/03 12:25:45
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257279945.1257282103.27276.gz

39698 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_access_control.html | Can load when redirected to different domain with allow-origin - got "error", expected "loaded"
39699 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_access_control.html | Won't load when redirected to subdomain - got "loaded", expected "error"
39700 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_access_control.html | Can load when redirected to subdomain with allow-origin - got "error", expected "loaded"
39703 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_access_control.html | Won't load from differnet port on same domain - got "loaded", expected "error"
39707 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_access_control.html | Can load from subdomain with allow-origin - got "error", expected "loaded"

This is from http://hg.mozilla.org/mozilla-central/rev/8857ad3785a3, and I'm not sure if it's intermittent or not.  Roc said on IRC that he's investigating it, and I'm just filing the bug to make sure that it doesn't fall off-track.
Whiteboard: [orange]
It's definitely intermittent. Applying record/replay airstrike.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257287895.1257289945.18052.gz
WINNT 5.2 mozilla-central test debug mochitests-1/5 on 2009/11/03 14:38:15
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257295771.1257297790.9592.gz
WINNT 5.2 mozilla-central test debug mochitests-1/5 on 2009/11/03 16:49:31
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257305876.1257307035.14392.gz
WINNT 5.2 mozilla-central test debug mochitests-1/5 on 2009/11/03 19:37:56
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257312083.1257313096.16604.gz
WINNT 5.2 mozilla-central test debug mochitests-1/5 on 2009/11/03 21:21:23
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257320544.1257321595.12566.gz
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257351115.1257352271.11257.gz
WINNT 5.2 mozilla-central test debug mochitests-1/5 on 2009/11/04 08:11:55
WINNT 5.2 mozilla-central test debug mochitests-1/5 [testfailed] Started 12:12, finished 12:41
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257361928.1257363661.14929.gz&fulltext=1
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257389260.1257390809.24068.gz
WINNT 5.2 mozilla-central test debug mochitests-1/5 on 2009/11/04 18:47:40
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257419189.1257420366.24720.gz
Blocks: 438871
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257490066.1257491610.19738.gz
We captured a failure of this test in a VMWare recording. I'll look into it on Monday.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257530923.1257531903.25558.gz
WINNT 5.2 mozilla-central debug test mochitests-1/5 on 2009/11/06 10:08:43
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257539460.1257540496.26881.gz
WINNT 5.2 mozilla-central debug test mochitests-1/5 on 2009/11/06 12:31:00
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257541441.1257542605.17809.gz
WINNT 5.2 mozilla-central debug test mochitests-1/5 on 2009/11/06 13:04:01

This failure has happened in 6 out of the last 7 cycles in the Windows debug test mochitests-1/5 column.

Given that roc's got data to debug this (comment 12), perhaps we should temporarily disable this test for now, to stop the almost-permanent-orange that it's causing?
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257551623.1257552796.2087.gz
WINNT 5.2 mozilla-central debug test mochitests-1/5 on 2009/11/06 15:53:43

Given that this test is failing the majority of the time, it's just adding noise to the tinderbox page at this point.  I'm going to disable it for now.
I disabled this specifically on windows for now -- conveniently, there was already a section of the Makefile for doing that. :)
  http://hg.mozilla.org/mozilla-central/rev/5480861605ad
Whiteboard: [orange] → [orange] [test disabled on windows]
With some intense debugging and a great deal of VMWare replay, I've figured out what caused this in the test run that we recorded.

* Test 7 loads http://example.org:8000/tests/content/media/test/320x240.allow-origin.ogv cross-origin and tries to verify that it loads correctly.
* The resource does load correctly, but there was a suspend event during the load.
* Because of that, when we get an OnStopRequest, we think maybe the server just timed us out while we were suspended. So we try to read more data from the end of the resource.
* The server returns 416 Range Request Not Satisfiable.
* nsMediaChannelStream::OnStartRequest knows that that's not fatal and does not report it an as an error. However nsCrossSiteListenerProxy *does* treat it as fatal and Cancels the channel with NS_ERROR_DOM_BAD_URI. So in nsMediaChannelStream::OnStopRequest we see that there was an error and we report a NetworkError to the element.
* HOWEVER by this time loadeddata has already fired on the element, so we've reported Test 7 as passing and moved on to the next test!
* Test 8 is expecting an error. So Test 8 kicks off a cross-domain load that's supposed to fail, and then gets an error: the spurious error generated by Test 7. So we move on to Test 9.
* Test 9 gets is not expecting an error, but it gets one: the error generated by Test 8. So Test 9 fails.
So there are two things we should do here:
1) fix test_access_control so that we associate video events with the correct test. If a subtest generates an extra unexpected event, we should report a failure associated with that subtest, not a failure associated with some later subtest.
2) When we get a 416 error, mark the nsMediaChannelStream so that if/when we later get an NS_ERROR_DOM_BAD_URI in OnStopRequest we ignore it.
Created attachment 412157 [details] [diff] [review]
Part 1: Make nsCrossSiteListenerProxy support treating certain HTTP response codes as non-errors
Assignee: nobody → roc
Status: NEW → ASSIGNED
Attachment #412157 - Flags: review?(jonas)
Created attachment 412158 [details] [diff] [review]
Part 2: fix the bug by having nsCrossSiteListenerProxy treat 416 responses as non-errors for media loads
Attachment #412158 - Flags: review?(chris.double)
Created attachment 412160 [details] [diff] [review]
Part 3: fix test and reenable
Attachment #412160 - Flags: review?(chris)

Updated

8 years ago
Attachment #412158 - Flags: review?(chris.double) → review+
Attachment #412160 - Flags: review+
These patches won't actually fix the problem, I think, because the 416 send by the server doesn't include Access-Control-Allow-Origin:*, so nsCrossSiteListenerProxy will still reject the request.

But we can't just have nsCrossSiteListenerProxy return OK for an HTTP error that we've flagged as benign. There could be an information leak. For example we could determine the size of a resource by triggering seek requests to different offsets of a cross-site resource and seeing which ones lead to an error and which ones don't.

I think we should have the server return Access-Control-Allow-Origin:*, or more generally the resource ^headers^, when it returns a 416. Waldo, how do you feel about that?
Created attachment 412501 [details] [diff] [review]
Part 4: serve headers with 416 responses
Attachment #412501 - Flags: review?(jwalden+bmo)
Attachment #412160 - Flags: review?(chris)
(In reply to comment #24)
> Created an attachment (id=412501) [details]
> Part 4: serve headers with 416 responses

Not quite there yet, not sending access-controls header on 416:

(With mochitest server running)
$ curl -I -r 28942- http://127.0.0.1:8888/tests/content/media/test/320x240.allow-origin.ogv
HTTP/1.1 416 Requested Range Not Satisfiable
content-type: text/html
connection: close
server: httpd.js
date: Sun, 15 Nov 2009 22:23:44 GMT
content-length: 379



$ curl -I http://127.0.0.1:8888/tests/content/media/test/320x240.allow-origin.ogv
HTTP/1.1 200 OK
last-modified: Wed, 21 Oct 2009 21:27:14 GMT
content-type: video/ogg
access-control-allow-origin: *
content-length: 28942
connection: close
server: httpd.js
date: Sun, 15 Nov 2009 22:24:32 GMT
Created attachment 412505 [details] [diff] [review]
v2

Ooops. This works.
Attachment #412505 - Flags: review?(jwalden+bmo)
I have been running test_access_controls in a loop with these patches for the past two hours, and not seen it fail, so I think we're good to go with these patches.
Comment on attachment 412505 [details] [diff] [review]
v2

The current error-response-generation system is more inflexible than it should be; this is a reasonable stopgap until I get around to thinking of something better.


>diff --git a/netwerk/test/httpserver/httpd.js b/netwerk/test/httpserver/httpd.js
>@@ -2053,16 +2052,18 @@ function maybeAddHeaders(file, metadata,
>     }
> 
>     // headers
>     while (more || line.value != "")
>     {
>       var header = line.value;
>       var colon = header.indexOf(":");
> 
>+      dump("### Set header " + header.substring(0, colon) +
>+           " to " + header.substring(colon + 1, header.length) + "\n");

Use dumpn here so you can get rid of the + "\n" at the end, also to avoid debug-spew outside of server uses where debug output is enabled.


>@@ -2222,16 +2223,19 @@ ServerHandler.prototype =
>       {
>         if (!(e instanceof HttpError))
>           throw e;
> 
>         errorCode = e.code;
>         dumpn("*** errorCode == " + errorCode);
> 
>         response = new Response(connection);
>+        if (e.customErrorHandling) {
>+          e.customErrorHandling(response);
>+        }

No braces around a single-line if.


>-      if (start !== undefined && start >= file.fileSize)
>+      if (start !== undefined && start >= file.fileSize) {
>+        var HTTP_416 = new HttpError(416, "Requested Range Not Satisfiable");
>+        HTTP_416.customErrorHandling = function(errorResponse) {
>+          maybeAddHeaders(file, metadata, errorResponse);
>+        };
>         throw HTTP_416;
>+      }

if (...)
{
  ...
  HTTP_416.customErrorHandling = function(errorResponse)
  {
    maybeAddHeaders(file, metadata, errorResponse);
  };
}


I rely heavily on the xpcshell server tests when making changes to httpd.js, and if this functionality is only tested in a single Mochitest under esoteric timing circumstances, it's much more likely I'll unknowingly break it and only find out when I've "finished" the patch.  r=me if you add netwerk/test/httpserver/test/data/ranges/headers.txt with some sort of contents in it, netwerk/test/httpserver/test/data/ranges/headers.txt^headers^ with this in it:

X-SJS-Header: customized

and something like this stuff to netwerk/test/httpserver/test/test_byte_range.js in the right places:

  new Test(PREFIX + "/headers.txt",
           init_byterange13, start_byterange13, null),


function init_byterange13(ch)
{
  ch.setRequestHeader("Range", "bytes=9999999-", false);
}

function start_byterange13(ch, cx)
{
  do_check_eq(ch.responseStatus, 416);
  do_check_eq(ch.getResponseHeader("X-SJS-Header"), "customized");
}
Attachment #412505 - Flags: review?(jwalden+bmo) → review+
Attachment #412501 - Flags: review?(jwalden+bmo)
> >+      dump("### Set header " + header.substring(0, colon) +
> >+           " to " + header.substring(colon + 1, header.length) + "\n");
> 
> Use dumpn here so you can get rid of the + "\n" at the end, also to avoid
> debug-spew outside of server uses where debug output is enabled.

I'll take it out, I didn't mean to get that checked in.

> No braces around a single-line if.

OK.

> if (...)
> {
>   ...
>   HTTP_416.customErrorHandling = function(errorResponse)
>   {
>     maybeAddHeaders(file, metadata, errorResponse);
>   };
> }

Isn't this quite dangerous? If we could ever have multiple 416-error-objects in flight at the same time, this would break. What's wrong with my way?

> I rely heavily on the xpcshell server tests when making changes to httpd.js,
> and if this functionality is only tested in a single Mochitest under esoteric
> timing circumstances, it's much more likely I'll unknowingly break it and only
> find out when I've "finished" the patch.  r=me if you add
> netwerk/test/httpserver/test/data/ranges/headers.txt with some sort of contents
> in it, netwerk/test/httpserver/test/data/ranges/headers.txt^headers^ with this
> in it:
> 
> X-SJS-Header: customized
> 
> and something like this stuff to
> netwerk/test/httpserver/test/test_byte_range.js in the right places:
> 
>   new Test(PREFIX + "/headers.txt",
>            init_byterange13, start_byterange13, null),
> 
> 
> function init_byterange13(ch)
> {
>   ch.setRequestHeader("Range", "bytes=9999999-", false);
> }
> 
> function start_byterange13(ch, cx)
> {
>   do_check_eq(ch.responseStatus, 416);
>   do_check_eq(ch.getResponseHeader("X-SJS-Header"), "customized");
> }

Sure, thanks.
Whiteboard: [orange] [test disabled on windows] → [orange] [test disabled on windows] [needs landing]
On the general topic of error responses not including A-C-A-O:*, this seems like a wrinkle that's worth raising on some W3C mailing list, that error responses to CORS requests that aren't simply complete failures but that are intended to transmit information may need to be careful to enable cross-origin access.  Maybe a cautionary note is worth adding somewhere in the CORS spec or something.

This is something a service like S3 would need to worry about (or so I gather if our relatively-correct implementation is generating these spurious requests).  I would imagine the add-specific-headers logic on content hosting services might not always have been written to apply to server-generated specific-information-communicating errors.  Broader dissemination of this information to web authors seems like a good idea.
(In reply to comment #29)
> > if (...)
> > {
> >   ...
> >   HTTP_416.customErrorHandling = function(errorResponse)
> >   {
> >     maybeAddHeaders(file, metadata, errorResponse);
> >   };
> > }
> 
> Isn't this quite dangerous? If we could ever have multiple 416-error-objects
> in flight at the same time, this would break. What's wrong with my way?

Just the placement of the brace after if (...) and after function(errorResponse), nothing more.  My intent was to say both braces should be on new lines, without laboriously spelling it out -- I guess the way I said it was just confusing, sorry about that.
ah ok
Attachment #412157 - Flags: review?(jonas) → review+
I saw that you raised this issue with the webapps WG. Was the result that any returned response with the appropriate headers should be accepted, no matter what the status code was? Or was it something else?
Yes, Anne says that headers can be sent with any response code, including any errors. I didn't want to change too much here though, which is why I'm only adding support to whitelist a particular set of response codes.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259110580.1259111725.25201.gz
OS X 10.5.2 mozilla-central opt test mochitests-1/5 on 2009/11/24 16:56:20
s: moz2-darwin9-slave07
OS: Windows Server 2003 → All
Hardware: x86 → All
http://hg.mozilla.org/mozilla-central/rev/61a17fedca4a
http://hg.mozilla.org/mozilla-central/rev/f99d0f439d59
http://hg.mozilla.org/mozilla-central/rev/7a048955e22b
http://hg.mozilla.org/mozilla-central/rev/c1b429b5eb99
Status: ASSIGNED → RESOLVED
Last Resolved: 7 years ago
Resolution: --- → FIXED
Whiteboard: [orange] [test disabled on windows] [needs landing] → [orange]
Flags: in-testsuite+
Target Milestone: --- → mozilla1.9.3a1
Comment hidden (Treeherder Robot)
Keywords: intermittent-failure
Whiteboard: [orange]
You need to log in before you can comment on or make changes to this bug.