Last Comment Bug 404857 - firefox reloads every font.cache for every page loaded
: firefox reloads every font.cache for every page loaded
Status: RESOLVED FIXED
: perf
Product: Core
Classification: Components
Component: Graphics (show other bugs)
: Trunk
: x86 Linux
: -- major with 2 votes (vote)
: mozilla1.9.1b1
Assigned To: Karl Tomlinson (ni?:karlt)
:
Mentors:
http://google.com
Depends on: 401988 414692
Blocks: 448298 449356
  Show dependency treegraph
 
Reported: 2007-11-21 13:30 PST by Paul Brannan
Modified: 2008-10-12 14:13 PDT (History)
16 users (show)
vladimir: blocking1.9-
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
use FcInitBringUptoDate() (5.21 KB, patch)
2008-09-14 21:06 PDT, Karl Tomlinson (ni?:karlt)
pavlov: review+
Details | Diff | Review

Description Paul Brannan 2007-11-21 13:30:07 PST
User-Agent:       Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9b1) Gecko/2007110903 Firefox/3.0b1
Build Identifier: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9b1) Gecko/2007110903 Firefox/3.0b1

I noticed today when trying out firefox 3.0b1 that it was unusably slow.  An strace revealed that pressing reload on google.com caused firefox to search through the font path and read each font.cache-1 files.  Pressing reload again causes the files to be read again.

This does not appear to happen on firefox 2.0.

Reproducible: Always

Steps to Reproduce:
1. Start firefox
2. Visit google.com
3. Run strace -p <pid>, where <pid> is the pid of firefox-bin
4. Press the reload button
5. Kill strace - you will see many open() calls for font files
Comment 1 Paul Brannan 2007-11-21 13:38:01 PST
Here's the strace output:

http://rubystuff.org/google.reload.txt

Note the number of font cache files read:

[pbrannan@zaphod pbrannan]$ grep ^open /tmp/google.reload.txt | grep fonts.cache-1 | wc -l
324

And the total number of font cache files on the machine:

[pbrannan@zaphod pbrannan]$ locate fonts.cache-1 | wc -l
25

I should also mention that I'm running on SuSE 9.1.  I have not tested this on a newer revision of the OS.
Comment 2 Sylvain Pasche 2007-11-23 14:06:34 PST
I tried running with "strace -e trace=file" to show only the i/o system calls on Ubuntu 7.10 x86_64. I'm not seeing lots of fonts.cache accesses, however I can see that every time I reload a page the fontconfig fonts directories are scanned. Which shows me something like:

[...]
[pid 30867] stat("/usr/share/fonts/X11/misc", {st_mode=S_IFDIR|0755, st_size=20480, ...}) = 0
[pid 30867] stat("/usr/share/fonts/X11/util", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 30867] stat("/usr/share/fonts/truetype/arphic", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 30867] stat("/usr/share/fonts/truetype/freefont", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 30867] stat("/usr/share/fonts/truetype/kochi", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 30867] stat("/usr/share/fonts/truetype/msttcorefonts", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 30867] stat("/usr/share/fonts/truetype/openoffice", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 30867] stat("/usr/share/fonts/truetype/thai", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[...]

Those access() calls should be rather cheap, but there may be something wrong happening here.
Comment 3 Peter Weilbacher 2007-11-24 12:42:28 PST
The function that would do that is in gfxFontconfigUtils::UpdateFontListInternal. There it calls Fontconfig to do FcConfigUptoDate which according to the man-page (or http://www.fontconfig.org/fontconfig-devel/r1768.html) does a stat on every one of its config and probably cache files. Bug unless you have a daemon running on your system that updates the timestamps on those files all the time, it should not re-open them, and so it should be really fast.

Perhaps Fontconfig on SuSE 9.1 was broken in some way? Btw, I noticed no open() calls at all during the experiment (just tons of stat calls) when attaching strace to the running program and reloading Google a couple of times (Gentoo Linux with Fontconfig 2.4.2).
Comment 4 Paul Brannan 2007-12-17 08:25:07 PST
Upgraded from fontconfig 2.2.92.20040221 (which came with SuSE 9.1)  to 2.2.99.20050218 (which came with SuSE 9.3).  This seems to have corrected the problem with open(); it is not called at all during a reload anymore.  Reloading a webpage is significantly faster now.

However, it still seems silly to re-stat all the font directories multiple times when reloading a webpage:

[pbrannan@zaphod pbrannan]$ grep stat64 /tmp/asdf | grep fonts.conf
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
stat64("/etc/fonts/fonts.conf", {st_mode=S_IFREG|0644, st_size=13675, ...}) = 0
[pbrannan@zaphod pbrannan]$ grep stat64 /tmp/asdf | grep fonts.conf | wc -l
20
Comment 5 Mike Schroepfer 2008-01-21 18:15:53 PST
Given the upgrade fixed the issue moving off our 1.9 blocker list
Comment 6 Karl Tomlinson (ni?:karlt) 2008-01-21 18:22:31 PST
We still shouldn't need to re-stat multiple files in each page load.
But I don't know the effect on performance, so we haven't got enough data yet to suggest that this should be a blocker.
Comment 7 Karl Tomlinson (ni?:karlt) 2008-01-30 01:37:33 PST
(In reply to comment #3)
> The function that would do that is in
> gfxFontconfigUtils::UpdateFontListInternal. There it calls Fontconfig to do
> FcConfigUptoDate which according to the man-page (or
> http://www.fontconfig.org/fontconfig-devel/r1768.html) does a stat on every
> one of its config and probably cache files. 

The changes in bug 401988 mean that this code path is now not being hit for general text rendering, and avoiding this may have contributed to much of the 6% Tp2 improvement.

The code path is still used in MathML font selection for operators.
Comment 8 Marco Pesenti Gritti 2008-01-30 03:53:16 PST
We have been seeing this issue with fontconfig 2.4.2. I suspect it might have been fixed for Paul just because upgrading the rpm regenerated the caches.

For reference:
http://dev.laptop.org/ticket/6046
Comment 9 Vladimir Vukicevic [:vlad] [:vladv] 2008-02-01 13:26:12 PST
Marking blocking- based on comments; if there is new data to shows that this is an issue, please renominate.
Comment 10 Sayamindu Dasgupta 2008-02-02 00:33:59 PST
We found it to be caused by fontconfig being unable to handle future timestamps properly. Some of the font dirs had their timestamps in the future, causing FcConfigUptoDate() to return FcFalse each and every time (http://dev.laptop.org/ticket/6046#comment:27). 
We have a patch against fontconfig, and the initial results suggests that it fixes the issue.
Comment 11 timeless 2008-04-08 02:20:47 PDT
the upstream bug is https://bugs.freedesktop.org/show_bug.cgi?id=14424 and has no traction
Comment 12 Sayamindu Dasgupta 2008-06-03 09:27:57 PDT
The patch has been applied upstream, and is in fontconfig-2.6.0.
Comment 13 Karl Tomlinson (ni?:karlt) 2008-09-14 21:06:52 PDT
Created attachment 338579 [details] [diff] [review]
use FcInitBringUptoDate()

This resolves the remaining issue (comment 4).

FcInitBringUptoDate() only rescans at intervals determined by the <rescan>
fontconfig setting.  The interval may be configured by the user but is
typically 30 seconds.

Also, fontconfig may update its current config in a call to FcFontSetList,
which would mean that FcConfigUptoDate would not know that the change has
happened.  The best way to detect an update seems to be to compare the results
of FcConfigGetCurrent().  FcInitReinitialize() creates a new config before
destroying the old config, so the only way that we'd miss an update is if
fontconfig did more than one update and the memory for the most recent config
happened to be at the same location as the original config.  (FcConfigs are
not reference counted so we can't force the original config to stay alive).

UpdateFontListInternal is called at all public access points to the
gfxFontconfigUtils object so there is no need to call it from the constructor.
Comment 14 Robert O'Callahan (:roc) (Exited; email my personal email if necessary) 2008-09-15 23:44:27 PDT
Does gfxGtkPlatform::UpdateFontList ever actually get called? I can't see how. If not, then we don't need this aForce parameter.
Comment 15 Karl Tomlinson (ni?:karlt) 2008-09-15 23:51:11 PDT
(In reply to comment #14)
I don't think there are any current callers, but there is a public API:

http://hg.mozilla.org/mozilla-central/annotate/19030b97ca13/gfx/idl/nsIFontEnumerator.idl#l81

The return value will be wrong though:

http://hg.mozilla.org/mozilla-central/annotate/1aecd2a9914d/gfx/src/thebes/nsThebesFontEnumerator.cpp#l128
Comment 16 Robert O'Callahan (:roc) (Exited; email my personal email if necessary) 2008-09-16 01:32:36 PDT
I think we should seriously consider removing that method. But anyway, I think probably Stuart or Vlad should review this.
Comment 17 Karl Tomlinson (ni?:karlt) 2008-09-21 14:04:04 PDT
http://hg.mozilla.org/mozilla-central/rev/6b38ceafa9ad

Note You need to log in before you can comment on or make changes to this bug.