1811750 - Performance.mark/measure/clearMarks take a long time to execute

Status: RESOLVED FIXED

(Core :: DOM: Performance APIs, defect)

Description

[henryfhchan]

Attachment: Screenshot - Firefox 109 – macOS 13.0.1 – Firefox Profiler.png

User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:109.0) Gecko/20100101 Firefox/110.0

Steps to reproduce:

Performance.mark/measure takes a long time to execute. Profiling shows that it takes up to 50% of the whole re-render when using vue with performance tracking turned on.

Comment 1

[henryfhchan]

Attachment: Call Tree

Comment 2

[henryfhchan]

Attachment: Market Chart

As per the marker chart, even though a large amount of markers are being set and unuset, it appears there are only 7 markers active at one point in time. Since vue is one of the more popular frameworks used by websites, it may be worth optimizing for it.

Comment 3

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

The Bugbug bot thinks this bug should belong to the 'Core::Performance' component, and is moving the bug to that component. Please correct in case you think the bot is wrong.

Comment 4

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

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

For more information, please visit auto_nag documentation.

Comment 5

[Frank Doty [:fdoty]]

Placing this bug into triage prior to setting severity

Comment 6

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

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

For more information, please visit auto_nag documentation.

Comment 7

[Bas Schouten (:bas.schouten)]

It would be great if you could upload the actual profile and put a link here! That will allow us to investigate more easily. As well as allow us to see the c++ portions of the stacks here.

Comment 8

[Frank Doty [:fdoty]]

Awaiting a profile to review before setting severity

Comment 9

[Alex Thayer [:alexical] (she/her)]

Closing as inactive waiting for profile.

Comment 10

[henryfhchan]

The profile I've taken may have some sensitive info. Is there someone I can directly mail this file to?

Comment 11

[Alex Thayer [:alexical] (she/her)]

Sorry for the delay! henryfhchan, could you email this to [e-mail]?

Comment 12

[henryfhchan]

Just sent, thank you!

Comment 13

[Alex Thayer [:alexical] (she/her)]

Attachment: Bug 1811750 - Eliminate redundant array filling in performance.measure r?baku

Basically we were falling off a cliff where if we had a bunch of marks recorded
with a particular name, when trying to measure we would fill an array with all
of them only to return the last one. This just replaces that by iterating in
reverse and returning the first matching mark. Arguably we should be using a
hashmap or something here, but this is a quick and trivial improvement that I
think will resolve the reported issue.

Comment 14

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/d5c4672573a9
Eliminate redundant array filling in performance.measure r=sefeng

Comment 15

[Norisz Fay [:noriszfay]]

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

Comment 16

[Alex Thayer [:alexical] (she/her)]

Henry, could you give this a try on the latest version of Nightly? I'm not sure if the patch resolved the performance problem you observed since I don't have a specific example page, but based on your profile I think it should.

Comment 17

[henryfhchan]

I'm still seeing clearPerformanceMark take a huge chunk of time on 124.0a1 (2024-01-26) (64-bit) (a412d893c38f632f34b44a9c5b3fd8cc30bb87be). I'll send you the updated stack trace.

Comment 18

[henryfhchan]

• Performance.measure() has a drastic improvement such that it no longer appears in the profile. However, Performance.clearMarks() still takes up quite a significant chunk of time. This was tested on 124.0a1 (2024-01-26) (64-bit) on macOS mbp with commit a412d893c38f632f34b44a9c5b3fd8cc30bb87be.

An updated profile has been sent. Many thanks for your assistance!

Comment 19

[Daniel Holbert [:dholbert]]

Hi Alex -- YouTube seems to be running into this in ESR 115, possibly due to a recent change on their side to use the associated APIs more aggressively (or with redundant names?). They might work around it, but for now this is pretty painful for ESR users.

Here are two profiles that I just captured in ESR115, which show massive time (40 seconds / 85 seconds respectively) spent in Performance.measure():
https://share.firefox.dev/3AIlAUQ
https://share.firefox.dev/3AEXrOV

...vs. Firefox 128 release which spends barely any time (228 samples i.e. 0.228 seconds, over the whole profile) in Performance.measure
https://share.firefox.dev/3T3kHwr

Given how targeted the patch is and the potential perf wins, maybe worth nominating for uplifting to ESR?

Comment 20

[Daniel Holbert [:dholbert]]

(We've got word from YouTube folks that they're rolling back the change that made them trip over this, so that reduces the pressure here a bit, but still worth considering for uplift if it's a safe change that avoids a pitfall that sites are sometimes tripping over.)

Comment 21

[Alex Thayer [:alexical] (she/her)]

Comment on attachment 9376160 [details]
Bug 1811750 - Eliminate redundant array filling in performance.measure r?baku

ESR Uplift Approval Request

• If this is not a sec:{high,crit} bug, please state case for ESR consideration: This was producing substantial slowdowns on YouTube with a recent change they made. They rolled back their change, but this could be affecting other sites similarly.
• User impact if declined: Slowness on sites which make heavy use of performance.measure
• Fix Landed on Version: 124
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): It's an incredibly small patch which has been live for many months now, and all it does is remove purely redundant work which makes no behavioral difference other than slowing the browser down.

Comment 22

[Alex Thayer [:alexical] (she/her)]

Resolving the bug and creating follow-ups for additional work, to simplify tracking.

Comment 23

[Pascal Chevrel:pascalc]

Comment on attachment 9376160 [details]
Bug 1811750 - Eliminate redundant array filling in performance.measure r?baku

Uplift approved for ESR 115. I am checking with QA if we have time to respin and revalidate our 115.15.0 build with this patch before we ship it next Tuesday.

Comment 24

[Pulsebot]

https://hg.mozilla.org/releases/mozilla-esr115/rev/a305eaf86d61

Comment 25

[Ryan VanderMeulen [:RyanVM]]

This fix will ship in 115.16esr.