1648355 - Significant delay on page loading (with "no response" on window title)

Status: RESOLVED FIXED

(Core :: Layout: Text and Fonts, defect)

Description

[atlanto]

Steps to reproduce:

1. Start nightly
2. Open https://gyao.yahoo.co.jp/ct/anime/

Expected result:
The page starts rendered immediatery.

Actual result:
Tab shows the title of the page, but the page doesn't start rendering.
Window title indicates "no response".
And then the page rendered/loaded.

mozregression found
Bug 1533462 - Enable the cross-process shared font list by default on Nightly builds. r=jwatt

This issue doesn't happen when gfx.e10s.font-list.shared=false.

Comment 1

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

Set release status flags based on info from the regressing bug 1533462

Comment 3

[Jonathan Kew [:jfkthame]]

I'm not seeing this on my Windows 10 system; I wonder if it depends on what fonts are installed, in some way. Once the page has loaded, if you go to Tools / Web Developer / Inspector, and look at the Fonts panel (may not be visible by default; choose it from the options for the rightmost panel of the inspector), and then expand the "All Fonts on Page" section at the bottom, what fonts are used?

Could you use the Firefox profiler to capture a profile when this happens? That would be helpful to confirm where the problem lies. Thanks!

Comment 4

[atlanto]

All Fonts on Page
Meiryo, Meiryo, system
Meiryo, Meiryo Bold, system
Segoe UI, Segoe UI, system
Segoe UI, Segoe UI Bold, system
Meiryo, Meiryo, system

Profiler data
https://share.firefox.dev/3dxdFZk

(addendum)
"no response" didn't appear on window title this time.
This issue happens on first loading.

Comment 5

[Jonathan Kew [:jfkthame]]

OK, thanks. That confirms the delay is the result of DirectWrite access happening in the main process, but I'm not sure why it's so bad in this example. Do you happen to have a particularly large number of fonts installed?

Comment 6

[atlanto]

I have 277 fonts(2488 files) in C:\Windows\Fonts. (I'm using Intel Core i3-4010U machine, btw)
There are Google Noto fonts(all), 1992 noto*.* files...
(and a lot of duplicated files such as Noto...Bold.ttf, Noto...Bold_0.ttf, Noto...Bold_1.ttf, ...
I'll organize them later. Though they don't seem to be related to this issue)

Comment 7

[atlanto]

After removing all Noto fonts and repairing some apps such as LibreOffice, currently 148 fonts(544 files) in C:\Windows\Fonts.
No delay now!
Maybe too many fonts (and low-spec machine) can cause this problem.
Thanks for your help!

Comment 8

[blinky]

I can reproduce this bug.

Steps to reproduce:

1. Download and install all Google Noto Fonts.
2. Download Font Loader.
3. Download Franklin Gothic Book Regular.ttf.
4. Open the Font Loader, Click on the Add Fonts button, Select the font file Franklin Gothic Book Regular.ttf then click Open.
5. Click on the Load button.
6. Open attachment 9159611 [details].

See https://youtu.be/Mdhfba9mdUw

Profiler data https://share.firefox.dev/3f9hPZ1

Comment 9

[Jonathan Kew [:jfkthame]]

Hmm, it looks like most of the issue here may be a result of the content-process sandbox. Can you try reducing security.sandbox.content.level to 1 (requires browser restart to take effect, I assume) and see if that makes any difference? Thanks!

Comment 10

[blinky]

Reduce the sandbox level security.sandbox.content.level to 1 does not fix the bug.

Comment 11

[blinky]

This also happens on startup.

Steps to reproduce 2:

1. Download and install all Google Noto Fonts.
2. Open Firefox.
3. Open attachment 9159611 [details].

Profiler data https://share.firefox.dev/3gvoZaa

Comment 12

[Alice0775 White]

I can reproduce the delay to loading On Nightly80.0a1(20200708094217) with new profile.

Nightly80.0a1: it takes about 3 sec.
Chrome : Almost instant.

Profiler log: https://share.firefox.dev/2ZK72xO

Comment 13

[Jonathan Kew [:jfkthame]]

Re-opening, as there are clearly issues here we should investigate further.

Comment 14

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

The severity field is not set for this bug.
:TYLin, could you have a look please?

For more information, please visit auto_nag documentation.

Comment 15

[blinky]

The browser hang for several seconds with attachment 9100780 [details] with the steps in comment 8 and comment 11.

Profiler data https://share.firefox.dev/3fr8HiB

Comment 16

[Jonathan Kew [:jfkthame]]

The particularly bad examples here are happening when the page (e.g. attachment 9159611 [details]) contains characters that are not supported by any available font; in this case we end up doing an exhaustive search of all the installed fonts, loading their character maps. When there are a very large number of fonts (such as the entire collection of Noto faces), this gets expensive -- especially because all DirectWrite filesystem access from the content process is getting intercepted by the sandbox, and proxied via IPC.

See for example https://profiler.firefox.com/public/e9t58yhm4vbfgcvya4p007f514k3xfwntv5cpyg/calltree/?globalTrackOrder=7-8-9-0-1-2-3-4-5-6&hiddenGlobalTracks=1-2&hiddenLocalTracksByPid=9964-1&invertCallstack&localTrackOrderByPid=3180-1-2-0~1884-0~5480-0~6576-0~9908-0~7480-0-1~9964-2-0-1~&thread=6&v=4 where over 20 seconds is being spent under sandbox::TargetNtCreateFile called via DirectWrite.

We can substantially improve things here by adding a flag aLoadCmaps to the InitializeFamily IPC message that the content process uses (from Family::SearchAllFontsForChar) to initialize each family during global font fallback, and having the parent process load the character maps for each face at the same time as initializing the list of Face records in the Family. It's much cheaper for the parent to do this than to leave it for the child to do on-demand, because the parent doesn't have all the DirectWrite filesystem access intercepted by the sandbox.

In my local testing with all the Noto fonts installed, this reduces a pathological-case reflow from around 12 seconds to 2 seconds. Still not as fast as we'd like, but much improved. (And once all the character maps have been loaded, on the first such pathological reflow in any process, any subsequent reflows are fast -- even in new content processes, thanks to the shared list.)

Comment 17

[Jonathan Kew [:jfkthame]]

Attachment: Bug 1648355 - When doing a global font fallback search, load cmaps eagerly in the parent process. r=jwatt

This reduces IPC traffic, and avoids the (severe) impact of file access interception
and proxying by the sandbox on DirectWrite in content processes.

Comment 18

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/faaad5ec1b0f
When doing a global font fallback search, load cmaps eagerly in the parent process. r=jwatt

Comment 19

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/mozilla-central/rev/faaad5ec1b0f

Comment 20

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

Since the status are different for nightly and release, what's the status for beta?
For more information, please visit auto_nag documentation.

Comment 21

[Jonathan Kew [:jfkthame]]

This was related to gfx.e10s.font-list.shared, which is disabled.