491283 - large number of installed fonts causes slowdown

Status: RESOLVED WORKSFORME

(Core :: Graphics, defect)

Description

[Daniel Marschall]

User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 5.1; de; rv:1.9.0.10) Gecko/2009042316 Firefox/3.0.10 (.NET CLR 3.5.30729)
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.1; de; rv:1.9.0.10) Gecko/2009042316 Firefox/3.0.10 (.NET CLR 3.5.30729)

I had the same problem descriped at http://jdempcy.blogspot.com/2006/08/firefox-csrssexe-99-cpu-problem-solved.html . At my PC with Adobe Type Manager I had VERY much fonts installed (about 3000). But everything works fine except FireFox. When I start FireFox, CSRSS.EXE get about 55% CPU usage and the pageload and the text edits are processing very slowly. With Internet Explorer I had no problem. Probably, FireFox processes all installed+activated system fonts in background while rendering the page - it would be better if that could be improved.

Reproducible: Always

Steps to Reproduce:
1. Install many fonts
2. Visit any website
3.
Actual Results:  
The system becomes slow

Expected Results:  
The website should render as fast as Internet Explorer and not freeze

Comment 1

[John Daggett (:jtd)]

After startup we load the cmap's of all fonts for use in system font fallback.  This happens in small spurts but if you immediately load a page that contains a character outside both the list of fonts specified on the page and the default font, the cmaps of all fonts will get loaded looking for a glyph for that character.

Daniel, I think you mean Adobe Font Folio, not Adobe Type Manager.  In general, with 3000 fonts installed, most apps are going to get bogged down by this.  Start Photoshop and observe how long it takes to create the font menu, it's not quick.  In general, it's better for system-wide performance to only keep around the fonts you might use, rather than the full set of fonts contained in Font Folio.

If this is really a problem for lots of users, one solution would be to cache the cmap's in the profile, check the font file for a modification date greater than the last run and only update when the cmap hasn't been cached or the modification date doesn't match.

Comment 3

[John Daggett (:jtd)]

Using this as a catch-all for situations where large numbers of fonts cause a slowdown at startup.

Comment 4

[David Tenser [:djst]]

If I understand correctly, it doesn't take more than one character falling back to the system font in order for Firefox to load the cmaps of all fonts installed. This seems like a very likely scenario for anyone starting Firefox with more than 5-10 tabs open (the default behavior of Firefox is to save the open tabs and restore them when restarting or closing the browser, so this is probably a _very_ common).

(In reply to comment #1)
> If this is really a problem for lots of users, one solution would be to cache
> the cmap's in the profile, check the font file for a modification date greater
> than the last run and only update when the cmap hasn't been cached or the
> modification date doesn't match.

Sounds like a neat solution to the problem. As has been reported, other browsers don't seem to suffer from this problem (and I wouldn't compare a browser with Photoshop), so this should definitely be worth fixing -- especially since browser speed is such a hot topic these days. :)

Comment 5

[Dietrich Ayala (:dietrich)]

Confirming, per comment #1. Removing [dupeme] since bug 502821 was duped against this bug.

I'd like to see someone answer John's question here, so we can get definitive numbers: https://bugzilla.mozilla.org/show_bug.cgi?id=502821#c5.

John - Assuming that the numbers show a conclusive hit at startup from this, would it be possible for you to spend time on fixing it? When, and how big of a project would it be?

Comment 6

[Vladimir Vukicevic [:vlad] [:vladv] (needinfo me, slow to respond)]

Random note: we already have to enumerate all the installed fonts just to get their names, ideally we'd have some other data we can pull out at the same time to avoid looking up timestamps or checksums or anything, given that fonts don't really change.  Maybe filename + file size if that's easily available while enumerating?

Comment 7

[[:Cww]]

Adding common-issue? to get support to look for user reports.

Comment 8

[[:Cww]]

No reports directly attributable to fonts.

Comment 9

[David Dahl :ddahl]

I have managed to build firefox on windows with the startup timeline bug 480735. I think I am trying to time the correct functions:

gfxWindowsPlatform::RunLoader()

gfxWindowsPlatform::gfxWindowsPlatform()

gfxWindowsPlatform::UpdateFontList()

but this one seems to be the only function returning any timings:

FontFamily::FindStyleVariations()

I will attach my log

Comment 10

[David Dahl :ddahl]

Attachment: startup log grepped for "windows"

Comment 11

[John Daggett (:jtd)]

(In reply to comment #10)
> Created an attachment (id=398283) [details]
> startup log grepped for "windows"

Not quite sure what this log indicates, does it show that these functions are taking up a huge amount of time?  Or just that they get hit at startup?  The RunLoader only gets called *after* startup.  It's run roughly 8 seconds after InitFontList is called after which 10 font families at a time are processed with 150ms delay in between.  See constants here:

http://mxr.mozilla.org/mozilla-central/source/gfx/thebes/src/gfxWindowsPlatform.cpp#87

The font enumeration function on Windows is gfxWindowsPlatform::UpdateFontList:

http://mxr.mozilla.org/mozilla-central/source/gfx/thebes/src/gfxWindowsPlatform.cpp#370

Further enumeration and cmap loading is done using the mix-in class gfxFontInfoLoader:

http://mxr.mozilla.org/mozilla-central/source/gfx/thebes/src/gfxWindowsPlatform.cpp#931

Within the UpdateFontList call the StartLoader initiates the delayed loading of cmaps and other font info.

Comment 12

[David Dahl :ddahl]

Thanks for the info, the log I posted is incomplete. I am wrestling with the timeline patch ( bug 480735 ) on windows. Once I get a stable build I will re-post the log.

Comment 13

[David Dahl :ddahl]

AHA! Got a stable build, here are the numbers for the Font loading on windows 7 without additional fonts added:

$ cat ~/logs/startup.txt
0[14ac040]: > gfxWindowsPlatform::UpdateFontList (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:3
75)
0[14ac040]: > gfxWindowsPlatform::InitLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:938)
0[14ac040]: <     1 ms (    1 ms total) - gfxWindowsPlatform::InitLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/
gfxWindowsPlatform.cpp:938)
0[14ac040]: <     3 ms (    3 ms total) - gfxWindowsPlatform::UpdateFontList (c:/moz/mozilla-central/mozilla/gfx/thebes/
src/gfxWindowsPlatform.cpp:375)
0[14ac040]: > gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:948)
0[14ac040]: <   199 ms (  199 ms total) - gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/g
fxWindowsPlatform.cpp:948)
0[14ac040]: > gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:948)
0[14ac040]: <   142 ms (  142 ms total) - gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/g
fxWindowsPlatform.cpp:948)
0[14ac040]: > gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:948)
0[14ac040]: <   278 ms (  278 ms total) - gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/g
fxWindowsPlatform.cpp:948)
0[14ac040]: > gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:948)
0[14ac040]: <   421 ms (  421 ms total) - gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/g
fxWindowsPlatform.cpp:948)
0[14ac040]: > gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:948)
0[14ac040]: <   323 ms (  323 ms total) - gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/g
fxWindowsPlatform.cpp:948)
0[14ac040]: > gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:948)
0[14ac040]: <   220 ms (  220 ms total) - gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/g
fxWindowsPlatform.cpp:948)
0[14ac040]: > gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:948)
0[14ac040]: <   284 ms (  284 ms total) - gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/g
fxWindowsPlatform.cpp:948)
0[14ac040]: > gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:948)
0[14ac040]: <   267 ms (  267 ms total) - gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/g
fxWindowsPlatform.cpp:948)
0[14ac040]: > gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:948)
0[14ac040]: <   187 ms (  187 ms total) - gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/g
fxWindowsPlatform.cpp:948)
0[14ac040]: > gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:948)
0[14ac040]: <   274 ms (  274 ms total) - gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/g
fxWindowsPlatform.cpp:948)
0[14ac040]: > gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:948)
0[14ac040]: <   384 ms (  384 ms total) - gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/g
fxWindowsPlatform.cpp:948)
0[14ac040]: > gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:948)
0[14ac040]: <   204 ms (  204 ms total) - gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/g
fxWindowsPlatform.cpp:948)
0[14ac040]: > gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:948)
0[14ac040]: <   136 ms (  136 ms total) - gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/g
fxWindowsPlatform.cpp:948)
0[14ac040]: > gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:948)
0[14ac040]: <   219 ms (  219 ms total) - gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/g
fxWindowsPlatform.cpp:948)
0[14ac040]: > gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/gfxWindowsPlatform.cpp:948)
0[14ac040]: <    17 ms (   17 ms total) - gfxWindowsPlatform::RunLoader (c:/moz/mozilla-central/mozilla/gfx/thebes/src/g
fxWindowsPlatform.cpp:948)

Comment 14

[David Dahl :ddahl]

John:

Is all of this font loading done on a background thread?

Comment 15

[Dietrich Ayala (:dietrich)]

so lots of time, but 8 seconds after startup. if this doesn't block UI, then it's not really a problem. if it does, then we should add [tsnap] to the whiteboard.

Comment 16

[Dietrich Ayala (:dietrich)]

related: joel confirmed font init is in the startup path on mac, and filed bug 517045 for it.

john: can you answer comment #14?

Comment 17

[John Daggett (:jtd)]

(In reply to comment #14)

> Is all of this font loading done on a background thread?

No, it's done on the main event thread.  

Are the numbers in comment 13 from an actual machine running Windows 7 or a VM?  421ms to read the cmaps of 10 fonts sounds really high.  Is startup on these machines taking more than 8 seconds?

You can bump up the time after startup when the reading begins (i.e. 15 secs instead of 8 secs) but if system font fallback occurs for a page (i.e. we need to search for all fonts containing character x) we effectively block to pull in all font cmaps.

Comment 18

[David Dahl :ddahl]

John: That was a real ThinkPad T500 core2duo laptop running Windows 7.

Comment 19

[Vladimir Vukicevic [:vlad] [:vladv] (needinfo me, slow to respond)]

We really, really, really need to cache font cmaps.  Fonts very rarely change!

Comment 21

[Dietrich Ayala (:dietrich)]

John, is there a bug for cmap caching already?

Comment 22

[Tomasz Sałaciński]

As I see from the User-Agent mr. Daniel Marschall uses Firefox 3.0. I remember similiar bug on Linux which have lots of fonts installed by default and Firefox 3.0 was very slow. Right now with Firefox 3.5 and 3.6 the problem doesn't exist at all. You may have to retest with Firefox 3.6.

Comment 23

[(no longer active)]

I measured the amount of I/O we do on the main thread, and on a recent installation of Win7 x64 which doesn't have any custom fonts installed, 40% of our I/O is just loading the fonts.  We seem to be the entire set of the font files in \Windows\Fonts, as well as \Windows\Fonts\StaticCache.dat.  And we do it *from the main thread*.

Here are the exact numbers:

We have 655 page faults reading from files inside C:\Program Files (x86)\Minefield, and 694 page faults reading files from C:\Windows\Fonts.  The total number of page faults in my test for firefox.exe was 1741.

Comment 24

[(no longer active)]

[7:32pm] ehsan: ok, I created a new profile
[7:32pm] ehsan: this is a cold startup
[7:32pm] ehsan: and things are worse this time
[7:32pm] ehsan: I got 832 page faults coming from the main thread
[7:33pm] ehsan: (judging by comparing the thread ID with the ID of the thread loading xul.dll)
[7:33pm] ehsan: and my startup page was a blank page
[7:34pm] ehsan: i.e., the only text that was displaying on the screen was the UI itself

Comment 25

[(no longer active)]

Chrome doesn't touch the \Windows\Fonts directory at all when starting up, so there's clearly a way to work around this issue.

Comment 26

[Ali Juma [:ajuma]]

Comment 22 suggests this in no longer a problem, but Ehsan's comments suggest there's still work to be done here. Should we keep this open?

Comment 27

[(no longer active)]

jdaggett would know better if this is still an issue or not.

Comment 28

[Marooned]

Few months later with the brand new Firefox 11 this still an issue. Is there a plan to removing this font checking? It's handing FF on startup for 1..2 minutes. And because Firefox is the worst browser regarding memory leaks, I have to restart it few times a day so it releases 600MB of RAM and then I have to wait to read the fonts again...

Comment 29

[Robert O'Callahan (:roc) (email my personal email if necessary)]

Try using a Nightly build with the fix for bug 705594 in it. Things should have improved.

Comment 30

[Marco Castelluccio [:marco]]

That memory usage is not normal, could you open a new bug and describe better the situation? (write also what addons you are using)

Comment 31

[Marooned]

Robert: thanks for the info. I'll wait till official update on that.

Marco: I don't think it make sense to file this as a bug. I'm using FF since at least 3.x and it was always so hungry for the memory, no matter of extensions used. And it has such label among others webdevelopers I was working with.

Comment 32

[Marco Castelluccio [:marco]]

Marooned, with the MemShrink project Firefox has improved a lot. According to many tests it isn't the "worst browser regarding memory leaks". Anyway the situation you've described isn't normal, we should investigate it.
If you want to help us, you could open a new bug and describe your experience.

Comment 33

[Marooned]

OK, I'll try to do that later. Thanks.

Comment 34

[Brendan]

Is this really what is slowing Firefox down for me?  It's pretty sad that in this day and age just having fonts installed can cause this.

For me, this doesn't seem to be an issue just at startup.  Using Process Explorer I can see many calls to GetFontAt and the browser is sluggish as reported in the original bug report: slow text edits, etc.  And that bug report was over 3 years ago!

Comment 35

[Marco Castelluccio [:marco]]

There's work going on with font related issues. See bug 734308 and bug 705594.

Comment 36

[Wayne Mery (:wsmwk)]

(In reply to Robert O'Callahan (:roc) (Mozilla Corporation) from comment #29)
> Try using a Nightly build with the fix for bug 705594 in it. Things should
> have improved.

(In reply to Marco Castelluccio [:marco] from comment #32)
> Marooned, with the MemShrink project Firefox has improved a lot. According
> to many tests it isn't the "worst browser regarding memory leaks". Anyway
> the situation you've described isn't normal, we should investigate it.
> If you want to help us, you could open a new bug and describe your
> experience.

(In reply to Marooned from comment #33)
> OK, I'll try to do that later. Thanks.

Marooned writes "I'm affraid I can't deliver any data. ... That's true that I wanted to deliver some data back then and failed. Currently I'm using much faster PC so it's hard to compare if FF got better or just my hardware.... I think there is no issue with fonts anymore ..."

bug 734308 (regarding startup?) is not fixed. But bug 705594 is fixed, however I think Daniel the reporter is no longer here to give an update.  Is there anything here that suggests this bug should stay open?

Comment 37

[Marco Castelluccio [:marco]]

Clearing needinfo as I don't have any information about this.

Comment 38

[John Daggett (:jtd)]

Most, but not all of font operations that happen on all fonts have been moved off-main-thread, so they won't cause chrome hangs as before. System font fallback issues only affect folks with GDI (XP or Win7 with old drivers), with DirectWrite we rely on the system for fallback fonts and don't "read all fonts" on the main thread ever.

Comment 39

[Wayne Mery (:wsmwk)]

(In reply to John Daggett (:jtd) from comment #38)
> Most, but not all of font operations that happen on all fonts have been
> moved off-main-thread, 

So this should no longer significantly impact startup.  And perhaps can be closed WFM?

Comment 40

[BugBot [:suhaib / :marco/ :calixte]]

The severity field for this bug is relatively low, S3. However, the bug has 16 votes.
:bhood, could you consider increasing the bug severity?

For more information, please visit auto_nag documentation.

Comment 41

[BugBot (nomail) [:suhaib / :marco/ :calixte]]

The last needinfo from me was triggered in error by recent activity on the bug. I'm clearing the needinfo since this is a very old bug and I don't know if it's still relevant.

Comment 42

[Gregory Pappas [:gregp]]

Closing per comment 39