1060767 - Multiple requests for CORS-fetched @font-face declared fonts

Status: RESOLVED WORKSFORME

(Core :: DOM: Security, defect)

Description

[Šime Vidas]

User Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:31.0) Gecko/20100101 Firefox/31.0 (Beta/Release)
Build ID: 20140716183446

Steps to reproduce:

Open http://gionkunz.github.io/chartist-js/ and in DevTools Network panel, notice how
font requests have Access-Control-Allow-Origin: "*" in their responses.


Actual results:

The DevTools console displays several CORS error messages, e.g. 

“Cross-Origin Request Blocked: The Same Origin Policy disallows reading the remote resource at http://fonts.gstatic.com/s/oxygen/v4/yVHpdQrmTj9Kax1tmFSx2j8E0i7KZn-EPnyo3HZu7kw.woff. This can be fixed by moving the resource to the same domain or enabling CORS.”


Expected results:

Those CORS error messages shouldn't be displayed. The fonts appear to be successfully rendered on the page.

Comment 1

[:Gijs (he/him)]

Looks to me like a bunch of fonts load correctly, but others don't - the ones that don't send CORS headers. Such as: http://fonts.gstatic.com/s/oxygen/v4/yVHpdQrmTj9Kax1tmFSx2rO3LdcAZYWl9Si6vvxL-qU.woff . Firefox correctly warns about this. What am I missing?

Comment 2

[:Gijs (he/him)]

Hrm, it seems like there are a lot of duplicate requests, in fact? And some display CORS headers (and load) and some don't (and don't load, and cause errors instead).

Comment 3

[Šime Vidas]

I don’t see that request in my Network panel. I’ve attached a screenshot of the font requests I see. I’ve checked an all of them have Access-Control-Allow-Origin: "*" in their responses.

Comment 4

[Šime Vidas]

Attachment: The font requests that I see in my Network panel.

Comment 5

[alex_mayorga]

¡Hola Gijs!

Are you confirming this bug on comment 2?

If so, could you please mark it NEW?

Else, resolve it to a fitting resolution, please.

¡Gracias!

Comment 6

[Šime Vidas]

There seems to be a new bug with Firefox's font loading system. I've started encountering duplicate font loads on any website that used Google web fonts. I've attached a screenshot of this happening on css-tricks.com.

Comment 7

[Šime Vidas]

Attachment: Firefox loads Google fonts twice on css-tricks.com

Comment 8

[:Gijs (he/him)]

Attachment: Duplicate requests, some with errors and some without

(In reply to alex_mayorga from comment #5)
> ¡Hola Gijs!
> 
> Are you confirming this bug on comment 2?

Hmm, there's definitely something strange happening, but it could as well be the fault of the web app... it's difficult to say for sure.

I've attached a screenshot of what I see in Firefox 32, and I'm moving this to Core::Untriaged instead, because I don't think the fault here is with the web console... but a reduced testcase would be great. I don't know what Google Fonts is doing and if it's just broken itself, or if it's a server issue on their side, or if we're sending requests in a silly way. A proper network trace with wireshark or similar would also be helpful.

Comment 9

[Matt S]

Adding, potentially, a little bit to this.

The warnings only occur when the fonts are loaded by @font-face directives in CSS files. Tested all of the following combinations:

* <link> including google hosted css file, eg: https://fonts.googleapis.com/css?family=Roboto:400,300,400italic,500,700,700italic
* <link> Copying CSS file to one hosted containing @font-face directives to fonts hosted on fonts.gstatic.com
* <style> block with an @import to the externally hosted css file (as in step 1)

All of these fail, it's odd in that all of the individual font files attempting to be loaded have 2 failed requests before finally actually loading. The two failed requests don't show RESPONSE headers in the network panel, merely request headers, this is the same behaviour that :Gijs reported with his screenshot.

What *DOES* work, is using the web font loader javascript library:

<script src="//ajax.googleapis.com/ajax/libs/webfont/1.4.7/webfont.js"></script>
<script>
    WebFont.load({
        google: {
            families: ['Roboto:400,300,400italic,500,700,700italic']
        }
    });
</script>

works 100% of the time without fail thus far.

Firefox 32.0.3
OS: Apple Mac OS X 10.9.5
UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:32.0) Gecko/20100101 Firefox/32.0

Firefox 33.0.1
UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:33.0) Gecko/20100101 Firefox/33.0

Comment 10

[Matt S]

> works 100% of the time without fail thus far.

This has stopped working with 33 reliably, behaviour is now identical to that of the css based injections.

Comment 11

[:Gijs (he/him)]

(In reply to Matt S from comment #9)
> Adding, potentially, a little bit to this.
> 
> The warnings only occur when the fonts are loaded by @font-face directives
> in CSS files. Tested all of the following combinations:
> 
> * <link> including google hosted css file, eg:
> https://fonts.googleapis.com/css?family=Roboto:400,300,400italic,500,700,
> 700italic
> * <link> Copying CSS file to one hosted containing @font-face directives to
> fonts hosted on fonts.gstatic.com
> * <style> block with an @import to the externally hosted css file (as in
> step 1)
> 
> All of these fail, it's odd in that all of the individual font files
> attempting to be loaded have 2 failed requests before finally actually
> loading. The two failed requests don't show RESPONSE headers in the network
> panel, merely request headers, this is the same behaviour that :Gijs
> reported with his screenshot.

In the local <link> case, do you see the requests on the local access log and/or wireshark?

Comment 12

[Matt S]

Attachment: Firefox33-2014-10-27.jpg

Screenshot showing request headers for both google and locally hosted css files containing @font-face directives to fonts.gstatic.com hosted fonts.

Comment 13

[Matt S]

Attachment: google-fonts-capture.pcapng

Oh bugzilla and not letting me edit, additional information to follow:

The behaviour I'm seeing today is a little different than last night, same FF version different computer (same OS). In the screenshot just supplied, you'll notice a successful request for the font far before the first failed request and then the second subsequent successful request, unsure why tho sis happening. On both of the successful requests the CORS header is present.

The failed (grey dot requests) have, I suspect is obvious, just the request headers specified no response headers.

Additionally, watching packet data with Wireshark: There are 3 GET requests for the CrY.. font and 2 for the d-6I font. I've included the log as well, I disabled gzip in firefox prior to taking this log, hope that helps.

Comment 14

[:Gijs (he/him)]

Jonathan, do you have ideas what's going on here, or who might?

Comment 15

[Matt S]

I also happened to have a copy of FF25 and noticed that it didn't exhibit this behaviour. I had a bit of time and bandwidth to spare so went backwards through the FF official releases.

FF31.0 was the first official version to report CORS issues with fonts.
FF30.0 loads all fonts without complaint.

I had yet a little more time and checked the 31.0 betas, the behaviour starts with the first beta 31.0b1.

Comment 16

[:Gijs (he/him)]

(In reply to Matt S from comment #15)
> I also happened to have a copy of FF25 and noticed that it didn't exhibit
> this behaviour. I had a bit of time and bandwidth to spare so went backwards
> through the FF official releases.
> 
> FF31.0 was the first official version to report CORS issues with fonts.
> FF30.0 loads all fonts without complaint.
> 
> I had yet a little more time and checked the 31.0 betas, the behaviour
> starts with the first beta 31.0b1.

This is awesome, thanks! Could you use mozregression ( http://mozilla.github.io/mozregression/ ) to narrow this down to a single day's commits? On the assumption that whatever broke this was not uplifted specifically to beta, but just landed on mozilla-central somewhere in the 31 cycle, the following should work:

mozregression --good 2014-03-16 --bad 2014-04-29

Comment 17

[Matt S]

Report from your interesting tool:

Last good revision: 5405d6f4e3c6 (2014-04-18)
First bad revision: 582b2d81ebe1 (2014-04-19)
Pushlog:
https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=5405d6f4e3c6&tochange=582b2d81ebe1

... attempting to bisect inbound builds (starting from previous week, to make sure no inbound revision is missed)
Getting http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2014/04/2014-04-11-03-02-01-mozilla-central/firefox-31.0a1.en-US.mac.txt
Getting inbound builds between d8c1b10c3a3d and 582b2d81ebe1
Oh noes, no (more) inbound revisions :(

Comment 18

[:Gijs (he/him)]

Hm. Nothing mentions cors in there, but there's bug 769194 which implemented src:local font-face things... maybe it's that? jfk? (can't needinfo you again...)

Comment 19

[Matt S]

Disregard previous comment, I did something that caused the script to break and always run the same nightly (which was good) until half way through when I did something else to fix it. Rerunning.

Comment 20

[Matt S]

More trustworthy report (though I'll rerun again just to be sure)

Got as far as we can go bisecting nightlies...
Ensuring we have enough metadata to get a pushlog...
Last good revision: e71ed4135461 (2014-04-17)
First bad revision: 7fe3ee0cf8be (2014-04-18)
Pushlog:
https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=e71ed4135461&tochange=7fe3ee0cf8be

... attempting to bisect inbound builds (starting from previous week, to make sure no inbound revision is missed)
Getting http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2014/04/2014-04-10-03-02-00-mozilla-central/firefox-31.0a1.en-US.mac.txt
Getting inbound builds between 690c810c8e3e and 7fe3ee0cf8be
Oh noes, no (more) inbound revisions :(

Comment 21

[Matt S]

I'd like to help out more and do the incremental build checking but FF is refusing to build with mozregression due to CLOBBER issues (I'm just using a bunch of terms I don't really get). Clobber is complaining that a full build is required, not sure where to go from here.

Comment 22

[:Gijs (he/him)]

(In reply to Matt S from comment #21)
> I'd like to help out more and do the incremental build checking but FF is
> refusing to build with mozregression due to CLOBBER issues (I'm just using a
> bunch of terms I don't really get). Clobber is complaining that a full build
> is required, not sure where to go from here.

This is great to hear! Thank you for your continued efforts to help figure this out.

Some background: mozregression can download builds, but it can actually build Firefox, too.

Generally, when building Firefox, then updating a bit of code, and then rebuilding, it uses the build files from the last build. In some cases, because of byzantine reasons which are not really relevant here, we /know/ that won't work, and so the commit will include a change in a file named "CLOBBER". The build system detects this and tells you "you need to CLOBBER" which is jargon for "you should get rid of all the intermediate build files and have the build start 'fresh'" (which will take longer).

I'm not sure if mozregression can cope well with this situation (ie, can be told when/how to clobber).

Assuming you're familiar with version control, it might make more sense to do bits of this "manually". That loses you some automation, but it gains you some control and it'd actually work. You'd basically want to get a copy of mozilla-inbound ( https://hg.mozilla.org/integration/mozilla-inbound/ ) via hg (mercurial, version control system). You then update to a specific revision with:

hg up -r d849022d8633

(this rev should not have the bug)

and then build with:

./mach build

(from the root of mozilla-inbound)

after which you can update to later revisions from this URL: https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=e71ed4135461&tochange=7fe3ee0cf8be ) to figure out when things started breaking...

Note that because we merge repositories around, history isn't strictly linear, and so figuring out the next revision to test might be difficult. I *think* the two relevant chunks will be https://hg.mozilla.org/mozilla-central/pushloghtml?changeset=a64bdaed44e3 and https://hg.mozilla.org/mozilla-central/pushloghtml?changeset=7fe3ee0cf8be (excluding the 'merge' changesets). So try with revisions in there (the second one is the "later" one).

Comment 23

[:Gijs (he/him)]

Oh, I almost forgot the most important bit: if "./mach build" tells you you need to clobber, "./mach clobber" can do that for you.

Comment 24

[Jonathan Kew [:jfkthame]]

(In reply to :Gijs Kruitbosch from comment #18)
> Hm. Nothing mentions cors in there, but there's bug 769194 which implemented
> src:local font-face things... maybe it's that? jfk? (can't needinfo you
> again...)

That was a platform-specific (Android/B2G-only) patch, so can't be relevant here.

(In reply to :Gijs Kruitbosch from comment #14)
> Jonathan, do you have ideas what's going on here, or who might?

No immediate ideas, but let's check with jdaggett, who generally knows more about font resource fetching and related issues, and has been doing some @font-face-related stuff lately. Possibly related to bug 964613, if the pushlog from comment 20 is accurate?

Comment 25

[:Gijs (he/him)]

(In reply to Jonathan Kew (:jfkthame) from comment #24)
> (In reply to :Gijs Kruitbosch from comment #18)
> > Hm. Nothing mentions cors in there, but there's bug 769194 which implemented
> > src:local font-face things... maybe it's that? jfk? (can't needinfo you
> > again...)
> 
> That was a platform-specific (Android/B2G-only) patch, so can't be relevant
> here.
> 
> (In reply to :Gijs Kruitbosch from comment #14)
> > Jonathan, do you have ideas what's going on here, or who might?
> 
> No immediate ideas, but let's check with jdaggett, who generally knows more
> about font resource fetching and related issues, and has been doing some
> @font-face-related stuff lately. Possibly related to bug 964613, if the
> pushlog from comment 20 is accurate?

Egh, missed that. Yes, that looks more likely (also because bug 769194 wasn't in the second pushlog)

Comment 26

[Matt S]

Ok, I'll do a few builds and try and track it down or at least generate a little more info to point to the potential culprit. I have decided I need a more powerful mac to make this build not so painful.

Note, had to add the following extra commits to my checkouts to get them to build:
  https://hg.mozilla.org/mozilla-central/raw-rev/72dd2867fda3
  https://hg.mozilla.org/mozilla-central/raw-rev/2b1da8de6a91

890b26ee9940 - Good revision
d9c61e48f276 - Good revision
fdfb11f2cf9c - Required clobber - Broken

a93e17835a75 - Good revision
ff84ce7e5f85 - (finally clued into jkthame's comment) - Broken
21043f348d65 - ("previous" to ff84) - Good revision

It seems that jfkthame is likely right, bug 964613 with associated revision did indeed introduce the behaviour.

Comment 27

[John Daggett (:jtd)]

Not quite sure what the precise issue is here. Could someone write a minimal testcase with clear steps? Is the problem here that the console is displaying error messages that are incorrect? Or that there are additional fetches that should not occur?

Comment 28

[Matt S]

I'm not sure if you want to call them the problems or the symptoms. Basically the browser is making multiple requests for the same font files failing on, what appears to be, all but the very last request. I don't know how FF decides when to "request" a font file, are the @font-face entries 'cached' and then loaded when they're used in decorations? Does this mean that the very last use of the font is the one that actually invokes the final request which loads correctly?

On many of my app's pages there'll be 2 or 3 CORS errors for *each* font file (load up to 6 different ones at times). Each of these errors is associated with a request in my NETWORK log though where FF reports that no data was received sometimes Wireshark reports that full data was downloaded for reach request (turning what should have been 6 requests into maybe 24).

I apologize as I don't commonly report bugs so I'm unsure of exactly what you're looking for in the way test cases. The simplest example of the "issue" can be seen directly on any of google fonts page's. with the inspector open https://www.google.com/fonts#UsePlace:use/Collection:Open+Sans produces the referred to error messages. If you don't see the errors try doing a force-reload (or whatever the appropriate term is for shift + reload).

Comment 29

[:Gijs (he/him)]

(In reply to Matt S from comment #28)
> I'm not sure if you want to call them the problems or the symptoms.
> Basically the browser is making multiple requests for the same font files
> failing on, what appears to be, all but the very last request. I don't know
> how FF decides when to "request" a font file, are the @font-face entries
> 'cached' and then loaded when they're used in decorations? Does this mean
> that the very last use of the font is the one that actually invokes the
> final request which loads correctly?
> 
> On many of my app's pages there'll be 2 or 3 CORS errors for *each* font
> file (load up to 6 different ones at times). Each of these errors is
> associated with a request in my NETWORK log though where FF reports that no
> data was received sometimes Wireshark reports that full data was downloaded
> for reach request (turning what should have been 6 requests into maybe 24).
> 
> I apologize as I don't commonly report bugs so I'm unsure of exactly what
> you're looking for in the way test cases. The simplest example of the
> "issue" can be seen directly on any of google fonts page's. with the
> inspector open
> https://www.google.com/fonts#UsePlace:use/Collection:Open+Sans produces the
> referred to error messages. If you don't see the errors try doing a
> force-reload (or whatever the appropriate term is for shift + reload).

To be clear, the pcapng file from wireshark that's attached shows that these requests are also actually happening, not just in the devtools imagination or something. So to answer very directly:

(In reply to John Daggett (:jtd) from comment #27)
> Not quite sure what the precise issue is here. Could someone write a minimal
> testcase with clear steps?

0. Clean profile
1. Open https://www.google.com/fonts#UsePlace:use/Collection:Open+Sans

Actual results:

Multiple (N) requests for each of the font files, and CORS errors reported in the devtools console for N-1 of each of the fonts.

Expected result:
1 request and no errors

(as noted by Matt, you can force-reload the page as well)

> Is the problem here that the console is
> displaying error messages that are incorrect? 

The error messages are caused by requests that shouldn't be happening. The requests are corroborated outside of the devtools (server logs, the pcapng trace attached), so it's not the devtools' fault, I expect.

> Or that there are additional
> fetches that should not occur?

So, this.

Comment 30

[John Daggett (:jtd)]

(In reply to :Gijs Kruitbosch from comment #29)
> > Not quite sure what the precise issue is here. Could someone write a minimal
> > testcase with clear steps?
> 
> 0. Clean profile
> 1. Open https://www.google.com/fonts#UsePlace:use/Collection:Open+Sans
> 
> Actual results:
> 
> Multiple (N) requests for each of the font files, and CORS errors reported
> in the devtools console for N-1 of each of the fonts.
> 
> Expected result:
> 1 request and no errors

Thanks! But strangely I can reproduce this, either with a trunk debug build or latest Nightly (OSX 10.8).

I enabled userfont logging and didn't see anything failing.

Hmm, maybe this was a Google bug associated with their WOFF2 handling?

The @font-face rules used define these sources:

src: local("Open Sans Bold Italic"), 
     local("OpenSans-BoldItalic"), 
     url("https://fonts.gstatic.com/l/font?kit=PRmiXeptR36kaC0GEAetxn5F8UOT71WbtQNamM9kDs-jHNs90nnCeJiD-HCYdCRyJQ1bcFog1oYkqbWHV6BMa-kzLtLfhNju3rhJKcSaIUztsNCfmr6nFAoVVLxpI8IZ") format("woff2"), 
     url("https://fonts.gstatic.com/l/font?kit=PRmiXeptR36kaC0GEAetxpa5fxEPGq1ruRrAKgX9aN6jHNs90nnCeJiD-HCYdCRyJQ1bcFog1oYkqbWHV6BMa-kzLtLfhNju3rhJKcSaIUztsNCfmr6nFAoVVLxpI8IZ") format("woff");

Maybe this was failing on the woff2 source and loading the woff source?

Please use userfont logging if you can reproduce this, that would be a huge help in tracking this down:

  export NSPR_LOG_MODULES=userfonts:5,fontdownloader:5
  export NSPR_LOG_FILE=/path/to/userfonts.out

In my trunk build the WOFF2 loads by default.

Comment 31

[Matt S]

It does indeed appear that the latest nightly does not have this issue (I'm assuming you meant to say ".. I can't reproduce ..").

For self interest I might back track through the builds until I find the change that resolved the behaviour.

Thank you for all of your help with this one!

Comment 32

[John Daggett (:jtd)]

(In reply to Matt S from comment #31)
> It does indeed appear that the latest nightly does not have this issue (I'm
> assuming you meant to say ".. I can't reproduce ..").
> 
> For self interest I might back track through the builds until I find the
> change that resolved the behaviour.
> 
> Thank you for all of your help with this one!

One thing to note is that those messages may reflect a bug on Google's part. If they weren't including the CORS headers correctly for the WOFF2 content but were for WOFF content that would cause precisely the sorts of error messages and behavior described here.

It would be interesting to test with the specific nightlies (or other channel builds) where this behavior was originally seen.

Comment 33

[Christoph Kerschbaumer [:ckerschb]]

This one is quite old. I suppose converting the fontLoader to use ::AsyncOpen2() [Bug 1195172] fixed that problem, but we should verify before closing. Matt, Kamil? Thanks

Comment 34

[Matt Wobensmith [:mwobensmith][:matt:]]

Unable to reproduce in Fx45.0.1.