1752764 - shop.nestle.jp shows slower than Chrome

Status: RESOLVED WONTFIX

(Core :: Networking: HTTP, defect, P3)

Description

[Alice0775 White]

Steps to reproduce:

1. Open https://shop.nestle.jp/

Actual Results:
It will take about 5 seconds for the first page to appear.
Profiler log: https://share.firefox.dev/3ISImrE
And the network monitor shows a lot of NS_BINDING_ABORTED errors.

Expected Results:
It takes about 3 sec in Chrome.

Comment 1

[:Gijs (he/him)]

Not really sure what is going on here, but the busted network connections are definitely weird. It looks like for some reason we abort the initial load and then load a second time from https://shop.nestle.jp/ssosid_router.php?destination=%2F or something, which apparently is an oracle thing (though cloudflare is also involved). Moving to networking component for investigation (not sure why this was in Fx::Preferences).

Comment 2

[Valentin Gosu [:valentin] (he/him) {{ AFK in July }}]

I'm seeing a lot of OCSP requests in the profile.
Could you check if setting security.OCSP.require to false improves the performance somewhat?
Thanks!

Comment 3

[Alice0775 White]

(In reply to Valentin Gosu [:valentin] (he/him) from comment #2)

I'm seeing a lot of OCSP requests in the profile.
Could you check if setting security.OCSP.require to false improves the performance somewhat?
Thanks!

security.OCSP.require is false in default in Nightly98 as well as Firefox96.
You mean set security.OCSP.enabled to 0? Even so, the results seem almost the same.

Comment 4

[Alice0775 White]

I think that this is not a severe problem. :-)

Comment 5

[Kershaw Chang [:kershaw]]

Note that NS_BINDING_ABORTED usually means that http requests are cancelled for some reason.
Maybe a http log can help us debug this issue, but the log is not able to tell us why a request is cancelled.

Comment 6

[Markus Stange [:mstange]]

Interestingly, the page stays totally blank for about 8 seconds. Then it reveals itself from a load event.
I'm not sure which network request triggers this load event. We fire the event from a DeprioritizedLoadRunner: https://share.firefox.dev/33qg7Sm

Comment 7

[Markus Stange [:mstange]]

Actually, it's not the load event which triggers the reveal - the reveal happens a little earlier, it just took a little time to get to the compositor, which was confusing me.

The reveal is done by a timeout handler from a Google Tag Manager script.

• At 6.86s, we execute "<script> inline at line 100 of https://shop.nestle.jp/", which starts the network request for https://www.googletagmanager.com/gtm.js?id=GTM-T3888T .
• At 8.27s, the network request completes and we start off-thread compiling the script.
• At 8.42s, the off-thread compile is done.
• At 8.89s, we execute the script. It calls setTimeout(..., 0). This timeout is deferred.
• At 10.83s, the timeout fires. GTM changes a class name somewhere.
• At 11.05s, the refresh tick to process that class name change fires, and we then paint.
• At 11.60s, we composite the result of that paint.

I'm not sure why we only execute the "<script> inline at line 100" so late. Maybe its execution waits for other <script>s to be loaded first.

Comment 8

[Olli Pettay [:smaug][[e-mail]] (vacation-ish -> Aug 1)]

What is the parent process doing around 11.35 - 11.70?
...aha, it thinks there is idle time (and there is) and calls LoadFontInfo. That seems to take lots of time, way longer than maximum idle period.
Parent process is possibly blocking anything else to happen around that time.

Comment 9

[Valentin Gosu [:valentin] (he/him) {{ AFK in July }}]

Thank you for tracking that down Markus. I think I know what's going on here.
This seems to be caused by the network.http.tailing.enabled pref. It's supposed to tail (de-prioritize) requests such as trackers. I assume googletagmanager is such a domain, so we end up tailing that request. Unfortunately the page is designed in such a way that it's waiting for that tracking request. I haven't dug into it much further than this. Hopefully this is an isolated web-page pattern.

Comment 10

[Olli Pettay [:smaug][[e-mail]] (vacation-ish -> Aug 1)]

Oh, there is also some accessibility stuff running in the parent process. And that looks surprisingly slow.
I guess I'll file a separate bug about that.

Comment 11

[Olli Pettay [:smaug][[e-mail]] (vacation-ish -> Aug 1)]

(This has Performance: P* set, so removing [qf])

Comment 12

[James Teh [:Jamie]]

Ug, sorry for the spam. Wrong bug.

Comment 13

[Randell Jesup [:jesup] (needinfo me)]

Given comment 9, this is an unfortunate case where a page interacts poorly with the system we have in place to make most pages faster by deprioritizing trackers. Some pages like this could end up slower.