494130 - log downloadable font errors to console

Status: RESOLVED FIXED

(Core :: Graphics, defect)

Description

[John Daggett (:jtd)]

Followup bug from bug 483459

So that authors can diagnose the reason a font doesn't load, nsFontDownloader should log font load errors to console via nsIConsoleService mechanism with details of load failure (font error, invalid cross-domain access, network error, etc.).  This also means that gfx code needs to return error codes for load failures.

Comment 1

[John Daggett (:jtd)]

Probably should also include OTS errors.

Comment 2

[Jonathan Kew [:jfkthame]]

Attachment: patch v1 - log @font-face errors to console

Here's a first cut at a console-logging patch for @font-face errors. Nothing very sophisticated, but at least it gives people some chance of figuring out what's happening.

This does not support localization of the log messages; I'm not sure if that's something we want to do eventually, but in any case we surely don't want to try it before FF4.0.

Comment 4

[Jonathan Kew [:jfkthame]]

Attachment: patch, v2 - log @font-face errors to console - unbitrotted & improved

This redirects a bunch of error/warning logging from attempted @font-face loads to the web console, so that it's accessible to web developers and users.

Further work we might want to do includes getting specific errors from OTS, instead of just the generic "rejected by sanitizer".

Should console logging like this be localized, or does it make more sense to keep it English-only on the grounds that it's so closely linked to HTML/CSS/JS source that is not localized anyway?

Comment 5

[John Daggett (:jtd)]

Comment on attachment 544507 [details] [diff] [review]
patch, v2 - log @font-face errors to console - unbitrotted & improved

> -#ifdef PR_LOGGING
> -    if (LOG_ENABLED()) {
> -      nsCAutoString fontURI, referrerURI;
> -      aFontFaceSrc->mURI->GetSpec(fontURI);
> -      if (aFontFaceSrc->mReferrer)
> -        aFontFaceSrc->mReferrer->GetSpec(referrerURI);
> -      LOG(("fontdownloader download blocked - font uri: (%s) "
> -           "referrer uri: (%s) err: %8.8x\n", 
> -          fontURI.get(), referrerURI.get(), rv));
> -    }
> -#endif    
> +    LogMessage(aProxy, "download not allowed", nsIScriptError::errorFlag, rv);

I think it's a good idea to consolidate logging code like this but I
don't think we should eliminate the use of PR_LOG, console logging
should be in addition to PR_LOG usage.  It's an easy way to for us to
track down problems reported by users when we can't access a given
environment (e.g. access-restricted).  Please add the PR_LOG code back into
LogMessage.

> +  NS_ConvertUTF16toUTF8 familyName(aProxy->FamilyName());
> +  nsCAutoString fontURI;
> +  aProxy->mSrcList[aProxy->mSrcIndex].mURI->GetSpec(fontURI);
> +  nsCAutoString msg;
> +  msg.SetLength(100 + familyName.Length() + strlen(aMessage));
> +  if (!msg.Length()) {
> +    // not enough memory? just return silently
> +    return NS_ERROR_OUT_OF_MEMORY;
> +  }
> +  int len = sprintf(msg.BeginWriting(),
> +                    "font-family: \"%s\" [src index %d]: %s",
> +                    familyName.get(), aProxy->mSrcIndex, aMessage);

I think it would make sense to include the weight/width/style here,
since that will make it easier to track down the specific @font-face
rule.  Without that, one would need to search using the URL which may or
may not be easy to do (e.g. a problem with Typekit fonts where the URL's
are huge base64 data URLs).

Comment 6

[Jonathan Kew [:jfkthame]]

Attachment: patch, v2.1 - log @font-face errors to console - also keep PR_LOG output

Updated to address suggestions in comment #5.

Comment 7

[Axel Hecht [:Pike]]

Re l10n, I have a hard time to follow the code, what would be an example message or two here?

Comment 8

[Jonathan Kew [:jfkthame]]

(In reply to comment #7)
> Re l10n, I have a hard time to follow the code, what would be an example
> message or two here?

A couple of examples copied from the Web Console window:

[17:49:32.850] font-family: "Rockwell W01 Bold" italic:0 weight:400 stretch:0 [src 0]: format not supported
source: http://fast.fonts.com/d/864373f8-943b-449d-a730-462eb66d7058.eot?d44f19a684109620e4841570a490e8187e28861e0645eb3bbd1aa6ac964086c3128bf96eefd30a09173c28f942dcce3dfa737c74bbb92f7af219776e6c583b5c80135a94d6dfdecc88bbf43d7b3c8ec3c9d4389846f712f131de24409280c2071df4dcbe18569640dd9420886d41fa4ef1cd4d70acafb33c77cabff348fdf7b7fc1d553b8753e18ba9f91a465211680b84d71596110c9ef7b4e40b5a29031994803fcaac4b723be7d54f172127ea635d4a5ce49d0cd9c0427a1f0c959dea51e835&projectId=74f39a9d-a5dc-405f-9690-1c1fd4590ae4 @ http://fast10.fonts.com/min/site.min.css

[17:50:40.446] font-family: "font-001e" italic:0 weight:400 stretch:0 [src 0]: rejected by sanitizer
source: http://fonts.philip.html5.org/indexfonts/004632d97b4c67ef31f5fa4cf7018810.ttf
[17:50:40.489] font-family: "font-001e" italic:0 weight:400 stretch:0 [src 1]: format not supported
source: http://fonts.philip.html5.org/indexfonts/004632d97b4c67ef31f5fa4cf7018810.eot

(I see these as being comparable to messages like "Image corrupt or truncated: <URL>" from the image decoder, which doesn't look like it's intended to be localized - see http://mxr.mozilla.org/mozilla-central/source/modules/libpr0n/src/Decoder.cpp#128.)

Comment 9

[Axel Hecht [:Pike]]

For web standards, I usually recommend to localizers to only translate them if there are documents around those message in their language. There's probably not much documentation around the messages here anyway, and they're hard to get right.

Let's not expose these messages to l10n at this point.

Comment 10

[Jonathan Kew [:jfkthame]]

Attachment: part 2 - also log OTS error/warning messages, to help authors diagnose bad fonts

This modifies OTS slightly so as to use callback functions to report errors and warnings, so that we can log these along with our other user-fonts messages. To minimize the impact on the rest of the OTS code, it uses a global variable to hold the callback info during ots::Process(); this means that it would not be safe to use OTS concurrently from multiple threads.

This is adequate for our needs at the moment, but we should discuss this with the upstream OTS developers and see if they're interested in creating a better design for error-message callbacks, or some other equivalent mechanism.

Comment 11

[Jonathan Kew [:jfkthame]]

Attachment: part 2 - also log OTS error/warning messages, to help authors diagnose bad fonts

Sorry, failed to qrefresh before attaching the patch ... here's a version that actually builds. :)

Comment 12

[Jonathan Kew [:jfkthame]]

Attachment: part 2 - also log OTS error/warning messages, to help authors diagnose bad fonts

Fixed build problems shown up by tryserver on other platforms.

Comment 13

[John Daggett (:jtd)]

Comment on attachment 544818 [details] [diff] [review]
patch, v2.1 - log @font-face errors to console - also keep PR_LOG output

> +    sprintf(msg.BeginWriting(),
> +            // if adding to this message, check that the SetLength() above
> +            // is still large enough to avoid risk of overrunning the string
> +            "font-family: \"%s\" italic:%d weight:%d stretch:%d [src %d]: %s",
> +            familyName.get(),
> +            aProxy->IsItalic(), aProxy->Weight(), aProxy->Stretch(),
> +            aProxy->mSrcIndex, aMessage);

This ends up spitting out a message like:

Error: font-family: "test2" italic:0 weight:400 stretch:0 [src 0]: rejected by sanitizer

This is a bit cryptic I think, it would be better to structure it so the error description preceded the details and the message should include an explicit mention of "downloadable font".  The weight/width/style values should be mapped to the keyword values  where possible (e.g. 400 = normal, 700 = bold) and always in the case of stretch values.

Something like:

Error: downloadable font rejected by sanitizer (font-family: "test2" style: normal weight: normal stretch: normal src index: 0)

Comment 14

[John Daggett (:jtd)]

In testing this, I notice that the downloader code isn't handling 404 errors properly, it's not setting an error but instead relies on the font loader code to reject the data (in the default case, the sanitizer).  If possible, it would be nice to fix this while we're looking at this but if it's tricky we can push it out to another bug.

Comment 15

[John Daggett (:jtd)]

(In reply to comment #14)
Example testpage:
http://people.mozilla.org/~jdaggett/font-face/src-list-local-fallback.html

Comment 16

[John Daggett (:jtd)]

Comment on attachment 545168 [details] [diff] [review]
part 2 - also log OTS error/warning messages, to help authors diagnose bad fonts

I don't think this is the right approach, having a callback that spits out a message like the one below is pretty much useless, it's a meaningless error to anyone not familiar with OTS source (which is what, 10 people in the world?!?):

Error: font-family: "test2" italic:0 weight:400 stretch:0 [src 0]: ERROR at ots.cc:177 (ProcessTTF)

I think we should probably skip this for now.  It would be much more useful to go through all the places in the OTS code where failures/warnings occur and identify them with a unique error code, then create a set of strings to match.  In the end the error would be something like:

Error: downloadable font rejected by sanitizer (font-family: "test2" style: normal weight: normal stretch: normal src index: 0), offset in name table extends beyond name table boundary

The other thing we should enable is the ability to run OTS as a command-line tool so that authors could use this as part of their workflow to guarantee that their fonts wouldn't get tripped up by sanitizer problems in Chrome/Firefox.

Comment 17

[Jonathan Kew [:jfkthame]]

(In reply to comment #16)
> I don't think this is the right approach, having a callback that spits out a
> message like the one below is pretty much useless, it's a meaningless error
> to anyone not familiar with OTS source (which is what, 10 people in the
> world?!?):
> 
> Error: font-family: "test2" italic:0 weight:400 stretch:0 [src 0]: ERROR at
> ots.cc:177 (ProcessTTF)

Well, by itself _this_ message is not very helpful, but it would normally be preceded by a couple of lower-level errors that at least serve to identify the problematic table. To figure out the actual error, I assume the font developer would need to look at the OTS source file indicated to see what it's checking at the point where the failure first occurs.

> I think we should probably skip this for now.  It would be much more useful
> to go through all the places in the OTS code where failures/warnings occur
> and identify them with a unique error code, then create a set of strings to
> match.  In the end the error would be something like:
> 
> Error: downloadable font rejected by sanitizer (font-family: "test2" style:
> normal weight: normal stretch: normal src index: 0), offset in name table
> extends beyond name table boundary

Yes, I agree this would be much better, but I think this is something that should be worked on within the upstream OTS project rather than as a patch we add in mozilla. At this point, I was aiming for a low-effort interim solution that would at least provide a trail that engineers could follow, without the need to patch extensively throughout the OTS codebase.

> It would be much more useful
> to go through all the places in the OTS code where failures/warnings occur
> and identify them with a unique error code, then create a set of strings to
> match.

Yes, it would be more useful, and we should work on it, but this will inevitably be a longer-term project....

> I think we should probably skip this for now. 

....and therefore I think there's value in doing this as an immediate fix. It moves us significantly forward from the bare "font rejected by sanitizer" message, which is all we have otherwise.

Comment 18

[John Daggett (:jtd)]

(In reply to comment #17)
> (In reply to comment #16)
> > I don't think this is the right approach, having a callback that spits out a
> > message like the one below is pretty much useless, it's a meaningless error
> > to anyone not familiar with OTS source (which is what, 10 people in the
> > world?!?):
> > 
> > Error: font-family: "test2" italic:0 weight:400 stretch:0 [src 0]: ERROR at
> > ots.cc:177 (ProcessTTF)
> 
> Well, by itself _this_ message is not very helpful, but it would normally be
> preceded by a couple of lower-level errors that at least serve to identify
> the problematic table. To figure out the actual error, I assume the font
> developer would need to look at the OTS source file indicated to see what
> it's checking at the point where the failure first occurs.

No, in this case, using the reftest in comment 15, that's the only error message that results.

> > I think we should probably skip this for now. 
> 
> ....and therefore I think there's value in doing this as an immediate fix.
> It moves us significantly forward from the bare "font rejected by sanitizer"
> message, which is all we have otherwise.

Sorry but I just don't think producing more error messages that contain
references to source files is an improvement, it adds a lot of not very
helpful messages to the console log.  Frankly, I think lots of folks
will see it as debug spew which I would argue we should be trying to
eliminate in the error console (e.g. GL layer context spew).

At a bare minimum, error messages should at least include pointers to
the specific tables with problems e.g. "font validation failed for the
'glyf' table".  And for each font there should only be *one* message,
not multiple messages at different call levels.

Comment 19

[Jonathan Kew [:jfkthame]]

Attachment: patch, v2.2 - log @font-face errors to console - addressed review comments

Carrying forward r=jdaggett. This restructures the log messages along the lines suggested in comment #13.

Comment 20

[Jonathan Kew [:jfkthame]]

And landed on m-c:
http://hg.mozilla.org/mozilla-central/rev/8e5995957233

Resolving this bug; I'll file followups regarding OTS failure reporting, as doing that "right" will involve an extensive patch to the actual OTS source, and also regarding comment #14, which is a separate issue from the actual logging here.

Comment 21

[Jonathan Kew [:jfkthame]]

Followups: bug 670900 and bug 670901.