1858478 - Closing a tab in firefox view takes nearly 2 seconds

Status: RESOLVED FIXED

(Firefox :: Firefox View, defect, P1)

Description

[Jeff Muizelaar [:jrmuizel]]

Have ~1000 tabs and closing one of them using the "close tab" menu item on the open tabs page takes 1.8s:
https://share.firefox.dev/3rPScIb

Comment 1

[Jeff Muizelaar [:jrmuizel]]

It seems like a lot of the cost is localization. What are we localizing on this page and why do we do it every time a tab is closed?

Comment 2

[Sam Foster [:sfoster] (he/him)]

Isn't this bug 1857118? In firefox view, the list of open tabs includes a localized representation of the last accessed timestamp. This gets updated with each mutation of the list, which includes closing tabs. The patch on bug 1857118 fixes the issue where this happens in the background even if the firefoxview tab is hidden.
Bug 1855704 is next up to improve and consolidate how we respond to these tab events. That's probably the best place for discussion of specific tactics to avoid unnecessary work and start to optimize this experience within Firefox View. If bug 1857118 does it job, that is the only place we should experience these kind of issues. Clearly, we shouldn't need to repeatedly localize the year each and every time, for every tab. But there's an open question on whether caching/optimizing this belongs in the platform or if we should cache on the front-end (likely easier, but then we mask the underlying issue and make all the other consumers solve the problem each time.)

Comment 3

[Sam Foster [:sfoster] (he/him)]

(In reply to Jeff Muizelaar [:jrmuizel] from comment #0)

Have ~1000 tabs and closing one of them using the "close tab" menu item on the open tabs page takes 1.8s:
https://share.firefox.dev/3rPScIb

Sorry I skimmed this. You are talking specifically about closing a tab from within Firefox View. . Bug 1855704 should address some of this but isn't specifically about optimizing performance - more aligning to best practices, with the expected result including a performance improvement. So we can use this bug to dig into the other stuff.

Comment 4

[Jeff Muizelaar [:jrmuizel]]

Francesco, is the large amount of time that we see in localization: https://share.firefox.dev/3rPScIb a problem with the localization code or is it expected and should Firefox View try do things differently?

Comment 5

[Julien Wajsberg [:julienw]]

Last time I looked at this (some weeks ago), I noticed that we were using Fluent a lot just to translate the title using the full URL as a variable. Maybe this could be improved by not using the URL in the title, or lazily handle this tooltip. For AT users, I'm not sure the current value for the title is useful.

Comment 6

[Sam Foster [:sfoster] (he/him)]

Attachment: sessionstore-1000-tabs.jsonlz4

I put together some session backup files to try and get some benchmarks. I'm attaching the one with 1000 tabs. I used a top-1000 list of sites to generate tab entries. They all share the same icon, but the title and lastAccessed dates are all different to try and get something close-ish to a real scenario

To use:

• Close the browser you want to test
• Copy in the attached sessionstore-1000-tabs.jsonlz4 file into the profile directory and rename it sessionstore.jsonlz4 (don't use a valuable profile, or back up your sessionstore-backups folder if you do.)
• Start the browser. It will probably hang for a few seconds while it reads the session file and creates all those tabs
• Open Firefox View, and click on the "Open Tabs" link on the side.
• Click on the ··· button for any item in the list (I used the first), and select "Close Tab".

I added some instrumentation locally to measure the time between getting the TabClose event and the lists having completed re-rendering. I got these times for different tab counts:

# Tabs, List and measurement name, ms elapsed
10, OpenTabsInView#RecentBrowsing TabClose to updateComplete, 16.60241600000154
10, OpenTabsInView#OpenTabs TabClose to updateComplete, 34.961167000001296
100, OpenTabsInView#RecentBrowsing TabClose to updateComplete, 69.82214099999874
100, OpenTabsInView#OpenTabs TabClose to updateComplete, 212.79641399999946
1000, OpenTabsInView#RecentBrowsing TabClose to updateComplete, 364.080371
1000, OpenTabsInView#OpenTabs TabClose to updateComplete, 1645.9188900000008

Comment 7

[Sam Foster [:sfoster] (he/him)]

A couple things stand out. The OpenTabsInView#RecentBrowsing instance only shows the top 5 tab items. We still need to sort the whole list to know which are the 5 most recent, but we only render 5 list items - if this is mostly time spent in localization I wouldn't expect to see that number grow so much as the tab count grows.

Here's a profile captured following the steps in comment 6: https://share.firefox.dev/45wPXXQ
From that test I measured the following - you can see these markers in the profile:

999, OpenTabsInView#RecentBrowsing TabClose to updateComplete, 448.4267910000053
999, OpenTabsInView#OpenTabs TabClose to updateComplete, 1962.0111410000027

Comment 8

[Julien Wajsberg [:julienw]]

(In reply to Sam Foster [:sfoster] (he/him) from comment #7)

A couple things stand out. The OpenTabsInView#RecentBrowsing instance only shows the top 5 tab items. We still need to sort the whole list to know which are the 5 most recent, but we only render 5 list items - if this is mostly time spent in localization I wouldn't expect to see that number grow so much as the tab count grows.

Oh yeah, you're right, I should have said the context for my previous comment: I believe that I was running with the config to show all tabs in the lists.
It's good to profile again with the default config, thanks for doing that.

For the profile above, I still see "L10n mutations [style]" happening right after OpenTabsInView#RecentBrowsing TabClose to updateComplete, but still inside OpenTabsInView#OpenTabs TabClose to updateComplete.
I'm also surprised by the length of layout phase.

Comment 9

[Sam Foster [:sfoster] (he/him)]

I repeated the steps in comment 6 now that bug 1858692 is resolved. Again, adding some instrumentation to the fxview code I got:

1000, OpenTabsInView#RecentBrowsing TabClose to updateComplete, 362.83124800000223
1000, OpenTabsInView#OpenTabs TabClose to updateComplete, 938.6449909999938

That seems about right. Its a large improvement on the numbers we got before bug 1858692 landed. The result seems in line with the profiles we looked at earlier and the time spent localizing. And it leaves a quite a bit of work still to do.

I'm not sure what the priority of this is right now. The performance isn't great, but it is proportional to the number of tabs open and so maybe not completely unexpected. Some of the work we plan to do will address this bug as reported, other changes are more general performance optimizations for firefox view as a whole. Some will target upcoming releases, others like bug 1861483 are longer term projects.

There isn't anything particularly actionable on this bug at this point. We could either make it a meta bug to track relevant performance work, or close it. Do you have a preference :jrmuizel?

Comment 10

[Jeff Muizelaar [:jrmuizel]]

I got a new profile: https://share.firefox.dev/40vvYIe

Things are still pretty bad so we should keep this open.

In the profile above, in the update() function inside of lit, it looks like we're setting the backgroundImage property of a node a lot (once for each tab?) This seems pretty wasteful and is causing us to reload all of those images and spent a bunch of time under mozilla::css::ImageLoader::LoadImage

Comment 11

[Jeff Muizelaar [:jrmuizel]]

We're also spending considerable time under mozilla::dom::L10nMutations::AttributeChanged. Zibi, do you have an idea why we might be spending so much time there?

Comment 12

[Zibi Braniecki [:zbraniecki][:gandalf]]

Not really.

In the profile the attributes seems to be changed 990 times. No idea why.

When called, all of the work is in IsInRoots takes almost all of the time, which tries to establish whether the element is in any of the roots.
This has been added by :Pike in https://bugzilla.mozilla.org/show_bug.cgi?id=1617669 and there's probably a way to make it faster.

Comment 13

[Sarah Clements [:sclements]]

(In reply to Zibi Braniecki [:zbraniecki][:gandalf] from comment #12)

Not really.

In the profile the attributes seems to be changed 990 times. No idea why.

It sounds like this requires a follow-up bug? Its not clear to me if this is an issue on the lit side or mozilla::dom::L10nMutations::AttributeChanged as Jeff mentioned. If its the former, I can dig deeper into that.

Comment 14

[Jeff Muizelaar [:jrmuizel]]

(In reply to Sarah Clements [:sclements] from comment #13)

It sounds like this requires a follow-up bug? Its not clear to me if this is an issue on the lit side or mozilla::dom::L10nMutations::AttributeChanged as Jeff mentioned. If its the former, I can dig deeper into that.

I think it would be valuable to understand why the attributes for all the tabs elements are being set. I'm not very familiar with how lit works, is it expected that it would be setting that attribute on each element whenever the list is modified?

Comment 15

[Sarah Clements [:sclements]]

(In reply to Jeff Muizelaar [:jrmuizel] from comment #14)

(In reply to Sarah Clements [:sclements] from comment #13)

It sounds like this requires a follow-up bug? Its not clear to me if this is an issue on the lit side or mozilla::dom::L10nMutations::AttributeChanged as Jeff mentioned. If its the former, I can dig deeper into that.

I think it would be valuable to understand why the attributes for all the tabs elements are being set. I'm not very familiar with how lit works, is it expected that it would be setting that attribute on each element whenever the list is modified?

It would. Can you show me in a screenshot exactly where the 990 times the attributes for the background image are being set? I'm having trouble finding that. I have something I can try out but I need to be able to do an accurate before/after comparison.

Comment 16

[Jeff Muizelaar [:jrmuizel]]

I don't how Zibi got the 990 count, but you can look at the marker chart for the profile and search for SetNeedStyleFlush you'll markers for each of href and background-image attribute sets.

The stack for them looks like:

(root) []
XREMain::XRE_main []
nsAppShell::ProcessGeckoEvents []
Task RefreshDriver::EnsureTimerStarted::catch-up []
RefreshDriver tick []
promise callback []
js::RunScript []
AsyncFunctionNext [self-hosted:852:26]
__enqueueUpdate [chrome://global/content/vendor/lit.all.mjs:740:25]
scheduleUpdate [chrome://global/content/vendor/lit.all.mjs:780:18]
performUpdate [chrome://global/content/vendor/lit.all.mjs:800:17]
update [chrome://global/content/lit-utils.mjs:132:8]
update [chrome://global/content/vendor/lit.all.mjs:2188:10]
render [chrome://global/content/vendor/lit.all.mjs:2123:15]
_$setValue [chrome://global/content/vendor/lit.all.mjs:1691:14]
_commitTemplateResult [chrome://global/content/vendor/lit.all.mjs:1747:25]
_update [chrome://global/content/vendor/lit.all.mjs:1602:11]
_$setValue [chrome://global/content/vendor/lit.all.mjs:1904:14]
_commitValue [chrome://global/content/vendor/lit.all.mjs:1961:16]
set HTMLAnchorElement.href []

Comment 17

[Zibi Braniecki [:zbraniecki][:gandalf]]

I may have misread. Can we actually get a call count for this method in this STR?

Comment 18

[Jeff Muizelaar [:jrmuizel]]

I don't have any reason to believe that we wouldn't be setting the l10n attribute as many times as we're setting href

Comment 19

[Sarah Clements [:sclements]]

Jeff, with the virtualizer in bug 1859788 having landed are you still seeing the jank when closing a tab?

Comment 20

[Jeff Muizelaar [:jrmuizel]]

With the virtualizer it still takes 350-600ms (mostly style time) to close a tab but it's much better than it was before. It seems reasonable to close this once virtualization is on.

Comment 21

[Jonathan Sudiaman [:jsudiaman]]

bug 1868853 enables virtualization by default.