Closed Bug 1440260 Opened 2 years ago Closed 2 years ago

Huge performance regression, main thread constantly busy, UI blocking

Categories

(Firefox :: Sync, defect)

defect
Not set

Tracking

()

RESOLVED DUPLICATE of bug 1426103

People

(Reporter: gerard-majax, Unassigned)

References

(Depends on 1 open bug)

Details

Since a few days, I've spotted that my Nightly was becoming barely usage, eating a lot of CPU, and the UI freezing quite a lot. Blaming WebRender and my OpenCL hacking at first, profiling gives a different story: https://perfht.ml/2EL1SGh

There's a lot of main thread activity, taking long time, and time is consumed around TS_tagURI/TS_untagURI, which seems to originate from https://searchfox.org/mozilla-central/source/toolkit/components/places/nsNavBookmarks.cpp#568 according to the stack.

Looking at the pushlog shows several bug landed recently around there: https://hg.mozilla.org/mozilla-central/log/tip/toolkit/components/places/nsNavBookmarks.cpp
"Barely usable", and not "barely usage". Sorry, it's hard to type correctly when your inputs takes 5 seconds to appear ...
I'm assuming you're not doing anything with bookmarks themselves. Looking at the stack there's various references to "syncBookmarkToPlacesBookmark" and "tagItem" (in PlacesSyncUtils). So I suspect this is something to do with Sync running in the background.

Hence I'm going to move this across to the sync component for initial diagnosis.
Component: Places → Sync
Product: Toolkit → Firefox
You're assuming correctly :)
Ok, it stopped. After hours.
It looks like a lot of the CPU time here is spent in activity stream code, both on the main thread and on one of the content processes: https://perfht.ml/2EKb15N
Flags: needinfo?(edilee)
We didn't start converting tags to async yet, but it's on our radar.
the tag change inited by Sync, as indicated by Florian, fires onItemChanged, that is managed by Activity stream here.
Depends on: 424160
I noted in bug 1440276 comment 1 that the largest activity-stream % is in an empty function. Standard8 commented out the functionality for performance reasons, but I guess the async results in a lot of dummy Promises and the ...args could add up especially if there's a lot of tags triggering `onItemChanged`…?
Flags: needinfo?(edilee)
Thanks for the report and for sending the log files via email. The logs show that for some operational reason (eg, a server dieing), you were allocated to a new storage server which forces all your bookmarks to be re-uploaded. It took a few syncs for that to complete - there are just over 10k bookmarks, and once Firefox was restarted during the sync and in another there seemed to be a transient network error. It looks like it eventually succeeded and things got back to normal.

We are doing alot of work around a large number of bookmarks in bug 1426103 and related bugs, so for now I'm going to close this as a dupe of that.

Sorry for the inconvenience.
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → DUPLICATE
Duplicate of bug: 1426103
Thanks for the heads-up. I'm a surprised, though, by the number of 10k bookmarks, because I actually don't use that feature.
(In reply to Alexandre LISSY :gerard-majax from comment #10)
> Thanks for the heads-up. I'm a surprised, though, by the number of 10k
> bookmarks, because I actually don't use that feature.

Do you see them in the bookmarks sidebar/panel?
(In reply to Mark Hammond [:markh] from comment #11)
> (In reply to Alexandre LISSY :gerard-majax from comment #10)
> > Thanks for the heads-up. I'm a surprised, though, by the number of 10k
> > bookmarks, because I actually don't use that feature.
> 
> Do you see them in the bookmarks sidebar/panel?

Yes, checking that, I see 10925 bookmarks in the "Others" section. A lot of them are tagged with "f1, shared" and some are duplicated: I see several instances with 200+ dupes.
You need to log in before you can comment on or make changes to this bug.