1363421 - UserAgentOverrides.jsm is visible on startup profiles

Status: RESOLVED FIXED

(Core :: Networking: HTTP, defect)

Description

[Florian Quèze [:florian]]

See this profile captured on the quantum reference hardware: https://perfht.ml/2qNRVEc

93% of that time is spent getting the default user agent on the root scope at http://searchfox.org/mozilla-central/rev/224cc663d54085994a4871ef464b7662e0721e83/netwerk/protocol/http/UserAgentOverrides.jsm#17

I think this should be a lazy getter.

But nsHttpHandler will need to be initialized at some point anyway, so I think it's worth also looking at how it's spending time. mozilla::net::nsHttpHandler::SetFastOpenOSSupport() is 70% of the time.

The expensive part is getting the system-info service at http://searchfox.org/mozilla-central/rev/224cc663d54085994a4871ef464b7662e0721e83/netwerk/protocol/http/nsHttpHandler.cpp#273 to get the OS version number. There may be more efficient ways to do that.

Comment 1

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

Yeah making DEFAULT_UA to be a lazy getter should be the way to fix it.

Frome this profile, the most expensive part of is the system-info constructor itself, and is spent on |GetGeoInfoW| and |GetCountryCode|. Those are the information sideloaded but we don't care in the nsHttpHandler use case. It'll be hard to optimize |SetFastOpenOSSupport| unless we can make system-info lazy loading the information on request.

Comment 2

[(no longer active)]

Bug 1188435 added this code.

I also filed bug 1363586 on the system info service being so expensive to create.

Comment 3

[(no longer active)]

(In reply to Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz) from comment #1)
> Frome this profile, the most expensive part of is the system-info
> constructor itself, and is spent on |GetGeoInfoW| and |GetCountryCode|.
> Those are the information sideloaded but we don't care in the nsHttpHandler
> use case. It'll be hard to optimize |SetFastOpenOSSupport| unless we can
> make system-info lazy loading the information on request.

Sorry I mid-aired you.

The system info constructor computes the world, but SetFastOpenOSSupport() doesn't care about any of the slow stuff that it's computing, it only wants the OS version, right?  Can we just use a Windows specific code path here to query the Windows version to not pay the excessive XPCOM tax on this platform?

Comment 4

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

(In reply to :Ehsan Akhgari (super long backlog, slow to respond) from comment #3)
> (In reply to Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz) from comment
> #1)
> > Frome this profile, the most expensive part of is the system-info
> > constructor itself, and is spent on |GetGeoInfoW| and |GetCountryCode|.
> > Those are the information sideloaded but we don't care in the nsHttpHandler
> > use case. It'll be hard to optimize |SetFastOpenOSSupport| unless we can
> > make system-info lazy loading the information on request.
> 
> Sorry I mid-aired you.
> 
> The system info constructor computes the world, but SetFastOpenOSSupport()
> doesn't care about any of the slow stuff that it's computing, it only wants
> the OS version, right?  Can we just use a Windows specific code path here to
> query the Windows version to not pay the excessive XPCOM tax on this
> platform?

I'm writing a patch that lazy load nsHttpHandler in UserAgentOverrides.jsm, should be able to move the expensive computation out of the start-up procedure for desktop.

For fennec it might not be helpful because the DEFAULT_UA will be used during the init procedure if there is any UA string template loaded from the UA update mechanism.

However, we'll need to profile again because there might be other code that construct nsHttpHandler or system-info during start-up.

Comment 5

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

Attachment: Bug 1363421 - Part 1, lazy load HTTP protocol handler to improve start-up performance.

system-info might need to be construct while creating nsHttpHandler and it might take up to 30ms.
Lazy loading the DEFAULT_UA can delay the creation of nsHttpHandler after start-up.

Review commit: https://reviewboard.mozilla.org/r/137764/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/137764/

Comment 6

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

I don't have a windows reference device in hand so it'll take me a while to verify this patch by myself.

@florian, can you help compare the performance difference of my patch? Two builds are prepared on try:
before: https://treeherder.mozilla.org/#/jobs?repo=try&revision=feb335b9f863580eb18a732016c056e6b455328d
after: https://treeherder.mozilla.org/#/jobs?repo=try&revision=15be2b16abcd30a81d54152aa3a7f9a4eb04477a

Comment 7

[Patrick McManus [:mcmanus]]

Comment on attachment 8866164 [details]
Bug 1363421 - Part 1, lazy load HTTP protocol handler to improve start-up performance.

https://reviewboard.mozilla.org/r/137764/#review141062

this patch is fine (good even as that code normally doesn't even run) - but nshttphandler is still going to get initialized quite early by something else.

if https://bugzilla.mozilla.org/show_bug.cgi?id=1363586 doesn't work out, it would be possible to asynchronously initialize TFO (bypassing it while init is happening) - but that inconsistency should be avoided if possible

Comment 8

[Florian Quèze [:florian]]

(In reply to Patrick McManus [:mcmanus] from comment #7)
> Comment on attachment 8866164 [details]
> Bug 1363421 - lazy load HTTP protocol handler to improve start-up
> performance.
> 
> https://reviewboard.mozilla.org/r/137764/#review141062
> 
> this patch is fine (good even as that code normally doesn't even run) - but
> nshttphandler is still going to get initialized quite early by something
> else.

Do you think it has to be initialized before the first window appears on screen? I would expect the first http request to be when we load the user's home page or start restoring a session, and I think that happens after we have a window.

Comment 9

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

Attachment: Bug 1363421 - Part 2, delay the initialization of UserAgentOverrides.jsm until first nsHttpChannel is created.

UserAgentOverrides.js is introduced to initialize UserAgentOverrides.jsm at profile-after-change
because preference will be read during the init.
Uninitialize will be triggered at profile-change-net-teardown because no network traffice after
this point.

Review commit: https://reviewboard.mozilla.org/r/138336/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/138336/

Comment 10

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

Comment on attachment 8866164 [details]
Bug 1363421 - Part 1, lazy load HTTP protocol handler to improve start-up performance.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/137764/diff/1-2/

Comment 11

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

Found a good configuration to redo @ehsan's work in bug 1351980 to avoid loading UserAgentOverrides.jsm in browser initialization path.

I choose profile-after-change and profile-change-net-teardown this time and try result looks promising.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=54eb88a37e15435f5828c32b65a94c2b05dc5192

Comment 12

[Patrick McManus [:mcmanus]]

(In reply to Florian Quèze [:florian] [:flo] from comment #8)
> (In reply to Patrick McManus [:mcmanus] from comment #7)
> > Comment on attachment 8866164 [details]
> > Bug 1363421 - lazy load HTTP protocol handler to improve start-up
> > performance.
> > 
> > https://reviewboard.mozilla.org/r/137764/#review141062
> > 
> > this patch is fine (good even as that code normally doesn't even run) - but
> > nshttphandler is still going to get initialized quite early by something
> > else.
> 
> Do you think it has to be initialized before the first window appears on
> screen? I would expect the first http request to be when we load the user's
> home page or start restoring a session, and I think that happens after we
> have a window.

I'm always surprised :) (but I don't have a lot of direct control over when a url is requested - I'm happy to do it lazily, I'm just saying I'm always surprised something comes in early so its also good to make it quick-as-possible on main thread.)

Comment 13

[Patrick McManus [:mcmanus]]

Comment on attachment 8866718 [details]
Bug 1363421 - Part 2, delay the initialization of UserAgentOverrides.jsm until first nsHttpChannel is created.

https://reviewboard.mozilla.org/r/138336/#review141574

Comment 14

[Florian Quèze [:florian]]

(In reply to Patrick McManus [:mcmanus] from comment #12)

> > Do you think it has to be initialized before the first window appears on
> > screen? I would expect the first http request to be when we load the user's
> > home page or start restoring a session, and I think that happens after we
> > have a window.
> 
> I'm always surprised :) (but I don't have a lot of direct control over when
> a url is requested - I'm happy to do it lazily, I'm just saying I'm always
> surprised something comes in early so its also good to make it
> quick-as-possible on main thread.)

If we wanted, we could ensure no HTTP request is started before the first window appears on screen. I think all it would take is debug-only code asserting if the first window doesn't exist yet at the time this code is initialized.

Comment 15

[Florian Quèze [:florian]]

(In reply to Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz) from comment #11)
> Found a good configuration to redo @ehsan's work in bug 1351980 to avoid
> loading UserAgentOverrides.jsm in browser initialization path.
> 
> I choose profile-after-change

profile-after-change still seems very early, and I don't see how attachment 8866718 [details] makes the load of UserAgentOverrides.jsm lazy.

Would there be a way to delay loading this until we actually need the user agent? I guess that would be when doing the first http request.

Comment 16

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

(In reply to Florian Quèze [:florian] [:flo] from comment #15)
> (In reply to Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz) from comment
> #11)
> > Found a good configuration to redo @ehsan's work in bug 1351980 to avoid
> > loading UserAgentOverrides.jsm in browser initialization path.
> > 
> > I choose profile-after-change
> 
> profile-after-change still seems very early, and I don't see how attachment
> 8866718 [details] makes the load of UserAgentOverrides.jsm lazy.
> 
> Would there be a way to delay loading this until we actually need the user
> agent? I guess that would be when doing the first http request.

my bad, lazy loading is not the correct term.
This patch is to delay the UserAgentOverrides.jsm until profile-after-change.

I tried delay the initialization until nsHttpHandler is created, however the try result looks bad. There might be some more dependency that is hidden in the code. Dont' want to spent too much time on it since it is not cost-efficient after bug 1363586 is resolved.

IMO, lazy loading DEFAULT_UA + delay UserAgentOverrides init is the safe and clean middle ground we can get before we do anything drastically in the UA override code.

Comment 17

[Florian Quèze [:florian]]

(In reply to Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz) from comment #16)

> I tried delay the initialization until nsHttpHandler is created, however the
> try result looks bad. There might be some more dependency that is hidden in
> the code.

Could you please share the link to this try push?

I'm curious as in the next few weeks I expect to push more on avoiding loading any JS module or component that isn't strictly necessary before the first window is shown.

Comment 18

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

(In reply to Florian Quèze [:florian] [:flo] from comment #14)
> (In reply to Patrick McManus [:mcmanus] from comment #12)
> 
> > > Do you think it has to be initialized before the first window appears on
> > > screen? I would expect the first http request to be when we load the user's
> > > home page or start restoring a session, and I think that happens after we
> > > have a window.
> > 
> > I'm always surprised :) (but I don't have a lot of direct control over when
> > a url is requested - I'm happy to do it lazily, I'm just saying I'm always
> > surprised something comes in early so its also good to make it
> > quick-as-possible on main thread.)
> 
> If we wanted, we could ensure no HTTP request is started before the first
> window appears on screen. I think all it would take is debug-only code
> asserting if the first window doesn't exist yet at the time this code is
> initialized.

Maybe a dumb question, is it guaranteed that add-on are initialized after first window appears on screen? Add-on might sync configuration from network at early stage.
I'm also wondering how early network-access-required gecko activities, e.g. PAC file loading, auto updating, etc., can be.

Comment 19

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

(In reply to Florian Quèze [:florian] [:flo] from comment #17)
> (In reply to Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz) from comment
> #16)
> 
> > I tried delay the initialization until nsHttpHandler is created, however the
> > try result looks bad. There might be some more dependency that is hidden in
> > the code.
> 
> Could you please share the link to this try push?
> 
> I'm curious as in the next few weeks I expect to push more on avoiding
> loading any JS module or component that isn't strictly necessary before the
> first window is shown.

The test results shows UA override is broken on Fennec.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=828c3bcbf7e637190fbdb0f73d6c3219faaf265c&selectedJob=98279578

Comment 20

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

(In reply to Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz) from comment #19)
> 
> The test results shows UA override is broken on Fennec.
> https://treeherder.mozilla.org/#/
> jobs?repo=try&revision=828c3bcbf7e637190fbdb0f73d6c3219faaf265c&selectedJob=9
> 8279578

mochitest chunk 5 or 9 (both e10s and non-e10s) also shows UA overrides is broken on all platforms.

Comment 21

[Florian Quèze [:florian]]

(In reply to Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz) from comment #19)

> The test results shows UA override is broken on Fennec.
> https://treeherder.mozilla.org/#/
> jobs?repo=try&revision=828c3bcbf7e637190fbdb0f73d6c3219faaf265c&selectedJob=9
> 8279578

Looks like you wanted to call this.init() in the constructor at https://hg.mozilla.org/try/rev/24790866f0ab266a3cdac8cc5f4cf94db97d1804#l5.18

Comment 22

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

(In reply to Florian Quèze [:florian] [:flo] from comment #21)
> (In reply to Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz) from comment
> #19)
> 
> > The test results shows UA override is broken on Fennec.
> > https://treeherder.mozilla.org/#/
> > jobs?repo=try&revision=828c3bcbf7e637190fbdb0f73d6c3219faaf265c&selectedJob=9
> > 8279578
> 
> Looks like you wanted to call this.init() in the constructor at
> https://hg.mozilla.org/try/rev/24790866f0ab266a3cdac8cc5f4cf94db97d1804#l5.18

Yeah I figured that out just few minutes ago as well.
Try result for the fixed version is here: https://treeherder.mozilla.org/#/jobs?repo=try&revision=2af755b6e08aae17c2088c8770302deed55a420a

Desktop might be ok now, however it might not be ok for Fennec. Looks like there is still an unavoidable reentrance of GetService on nsHttpHandler object on the init path.

The cycle is:

get_service(nshttphandler) -> nsHttpHandler::Init
  -> get_service(useragentoverride.js) -> UserAgentOverrides.init
    -> UserAgentUpdate.init -> UserAgentUpdate._applySavedUpdate -> UserAgentUpdate._applyUpdate
      -> UserAgentOverrides.getUserAgentFromOverride -> UserAgentOverrides.DEFAULT_UA
        -> get_service(nshttphandler)


UserAgentUpdate._applySavedUpdate uses promise to call _applyUpdate, but not sure if it can guarantee that it will not happened on the same C++ call stack.

Comment 23

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

Comment on attachment 8866718 [details]
Bug 1363421 - Part 2, delay the initialization of UserAgentOverrides.jsm until first nsHttpChannel is created.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/138336/diff/1-2/

Comment 24

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

Comment on attachment 8866718 [details]
Bug 1363421 - Part 2, delay the initialization of UserAgentOverrides.jsm until first nsHttpChannel is created.

This is probably the best I can do, delaying the initialization of UserAgentOverrides.jsm until nsHttpHandler is created.
Try result in comment #22 looks good.

Comment 25

[Patrick McManus [:mcmanus]]

Comment on attachment 8866718 [details]
Bug 1363421 - Part 2, delay the initialization of UserAgentOverrides.jsm until first nsHttpChannel is created.

https://reviewboard.mozilla.org/r/138336/#review142162

Comment 26

[Patrick McManus [:mcmanus]]

(In reply to Florian Quèze [:florian] [:flo] from comment #8)
> 
> Do you think it has to be initialized before the first window appears on
> screen? I would expect the first http request to be when we load the user's
> home page or start restoring a session, and I think that happens after we
> have a window.

I think we should judge that case by case honestly. Networks have inherent latency and the notion of transferring some elements that we might use to draw that home page in parallel with getting a window up isn't a crazy thought - at least in principle they aren't fighting for a lot of the same resources.

Comment 27

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/8a9e10fae26c
Part 1, lazy load HTTP protocol handler to improve start-up performance. r=mcmanus
https://hg.mozilla.org/integration/autoland/rev/722236d77865
Part 2, delay the initialization of UserAgentOverrides.jsm until nsHttpHandler is created. r=mcmanus

Comment 28

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

This caused windows xpcshell failures like https://treeherder.mozilla.org/logviewer.html#?job_id=98845094&repo=autoland&lineNumber=14630

Backed out in https://hg.mozilla.org/integration/autoland/rev/39581b9d0093

Comment 29

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

(In reply to Wes Kocher (:KWierso) from comment #28)
> This caused windows xpcshell failures like
> https://treeherder.mozilla.org/logviewer.
> html#?job_id=98845094&repo=autoland&lineNumber=14630
> 
> Backed out in https://hg.mozilla.org/integration/autoland/rev/39581b9d0093

Looking in the assertion stack:
18:52:05     INFO -  PID 10148 | #61: mozilla::net::nsHttpHandler::Init() [netwerk/protocol/http/nsHttpHandler.cpp:494]
18:52:05     INFO -  PID 10148 | #62: mozilla::net::nsHttpHandlerConstructor [netwerk/build/nsNetModule.cpp:276]

Comment 30

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

And the failures don't seem to be completely permafailing, so you'd probably need to retrigger the xpcshell jobs a few times on try to make sure you've fixed this:
https://treeherder.mozilla.org/#/jobs?repo=autoland&fromchange=cede71157daf70061897b0d5d8ef723f48bf7620&noautoclassify&filter-searchStr=win%20xpc%20debug&tochange=edea8382d3f45ed2fdd38c42f210a63c139f3be2

Comment 31

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

Ok, our profiler uses nsHttpHandler to gather the information of platform/cpuos/misc while saving profiling results to file. If nsHttpHandler::Init happens to be on run on this call stack, the reentrance of profiler code will happen in JS engine while running UserAgentOverrides code and a deadlock is detected.

One lesson learned is not to touch JS code during the nsHttpHandler initialization because this component is fundamental and can be used by low-level code.

Comment 32

[Markus Stange [:mstange]]

The profiler gets three pieces of information from the HTTP protocol handler: The OS ("platform"), the OS version ("oscpu"), and the Firefox version ("misc"). For example on my machines these values are:
  platform:"Macintosh"
  oscpu:"Intel Mac OS X 10.12"
  misc:"rv:55.0"

The profiler doesn't care about the specific format of these strings, it only wants the ability to show it to the user in some place. (Currently we're not even showing it, but we want to fix that.)

We could move the source of this information to a different place where both the HTTP protocol handler and the profiler can get it from. That's probably a good idea to do anyway, because the profiler really wants the *true* information about these things, and currently the HTTP protocol handler has the ability to override it.

Comment 33

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

nsIXULRuntime.idl and nsIXULAppInfo.idl might already have the information you need, and probably the place we should move some of the code to. nsSystemInfo also have some similar information.

nsIXULRuntime.OS: "Darwin"
sysinfo.getProperty("version"): "16.4.0"
sysinfo.getProperty("arch"): "x86-64"
sysinfo.getProperty("cpuvendor"): "GenuineIntel"
nsIXULAppInfo.version: "55.0a1"

Comment 34

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

Comment on attachment 8866718 [details]
Bug 1363421 - Part 2, delay the initialization of UserAgentOverrides.jsm until first nsHttpChannel is created.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/138336/diff/2-3/

Comment 35

[Shih-Chiang Chien [:schien] (UTC+8) (use ni? plz)]

Comment on attachment 8866718 [details]
Bug 1363421 - Part 2, delay the initialization of UserAgentOverrides.jsm until first nsHttpChannel is created.

Sorry for fiddling the r? flag again on this bug.
Due to the reason in comment #31, we cannot init UA overrides during nsHttpHandler::Init. Therefore, I move the UA overrides init until the first creation of the nsHttpChannel.

summary of changes:
1. lazy loading UserAgentOverrides.jsm until the first nsHttpChannel is created.
2. add error handling if UserAgentOverrides is init before preference is ready (this is for workaround xpcshell test that uses http channel but not init gecko profile)

Comment 36

[Patrick McManus [:mcmanus]]

Comment on attachment 8866718 [details]
Bug 1363421 - Part 2, delay the initialization of UserAgentOverrides.jsm until first nsHttpChannel is created.

https://reviewboard.mozilla.org/r/138336/#review144628

Comment 37

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/06ab5407311a
Part 1, lazy load HTTP protocol handler to improve start-up performance. r=mcmanus
https://hg.mozilla.org/integration/autoland/rev/bc372bd6dff3
Part 2, delay the initialization of UserAgentOverrides.jsm until first nsHttpChannel is created. r=mcmanus

Comment 38

[Phil Ringnalda (:philor)]

https://hg.mozilla.org/mozilla-central/rev/06ab5407311a
https://hg.mozilla.org/mozilla-central/rev/bc372bd6dff3