Closed Bug 1440276 Opened 2 years ago Closed 2 years ago

Activity Stream spikes after Bookmark activity, triggering lots of main thread work

Categories

(Firefox :: New Tab Page, defect, P1)

defect

Tracking

()

RESOLVED FIXED
Firefox 60
Iteration:
60.4 - Mar 12
Tracking Status
firefox60 --- fixed

People

(Reporter: gerard-majax, Assigned: ursula)

References

(Blocks 1 open bug)

Details

Attachments

(2 files)

While profiling bug 1440260, it appears there is a lot of Activity Stream code being triggered. It might just be a side effect of this Sync issue, but the flow is hard to track.

Profile can be seen at: https://perfht.ml/2EKb15N
The chrome side shows 34% of time in onItemChanged resource://activity-stream/lib/PlacesFeed.jsm:165:
https://searchfox.org/mozilla-central/source/browser/extensions/activity-stream/lib/PlacesFeed.jsm#165

… which is all commented out?

I suppose there's the async and the ...args. And if there's a lot of these calls, maybe it can add up?
I suppose does defining the method as just `onItemChanged() {}` reduce the profiled percentage?
(In reply to Ed Lee :Mardak from comment #1)
> The chrome side shows 34% of time in onItemChanged
> resource://activity-stream/lib/PlacesFeed.jsm:165:
> https://searchfox.org/mozilla-central/source/browser/extensions/activity-
> stream/lib/PlacesFeed.jsm#165
> 
> … which is all commented out?
> 
> I suppose there's the async and the ...args. And if there's a lot of these
> calls, maybe it can add up?

I assume you are talking about https://perfht.ml/2EXYQBz which is mostly time spent garbage collecting, it's just an accident that it happened in the onItemChanged method. The reason for GC'ing here is 'ALLOC_TRIGGER' (described at https://searchfox.org/mozilla-central/rev/bd05e3853c6e982e2a35c1cc404b987b2bc914d6/js/src/gc/Scheduling.h#250-271)
Assignee: nobody → usarracini
Iteration: --- → 60.4 - Mar 12
Priority: -- → P1
So I'm thinking we do 2 things here:
1. Just remove the commented out code from onItemChanged() and make it an empty function. We're not using it, we may be able to win on removing the async and args stuff anyways and it if we need it for notifying title changes for bookmarks, we can be smarter about how we implement it.
2. As Kit mentioned in bug 1440260, we can add `skipTags: true` to the activity stream bookmarks observer and just nuke all those notifications when PlacesSyncUtils tags an item. That's what the profiles show as the big issue anyways. 

I chatted with Kit about the skipTags thing and they said that sync removes every tag (which are just bookmarks under the hood) then adds it back which results in a bunch of onItemAdded, onItemRemoved, and onItemChanged bookmark notifications that activity stream probably doesn't need to be registered to. This is at least a good place to start, and if the problem persists we can continue to investigate why this is happening.
I did some more digging into this and here's what I found:
If we add skipTags = true to our bookmarks observer in PlacesFeed.jsm, and we tag a URI (via TS_tagURI as the profile shows), then PlacesFeed does *not* receive onItemAdded, and similarly when you untag a URI with onItemRemoved. 

However, it doesn't prevent onItemChanged from firing. That's because when we modify an item via setItemLastModified in tagURI (https://searchfox.org/mozilla-central/rev/056a4057575029f58eb69ae89bc7b6c3c11e2e28/toolkit/components/places/nsTaggingService.js#157), it uses NOTIFY_OBSERVERS (https://searchfox.org/mozilla-central/rev/056a4057575029f58eb69ae89bc7b6c3c11e2e28/toolkit/components/places/nsNavBookmarks.cpp#1468-1469) rather  than NOTIFY_BOOKMARK_OBSERVERS like insert/remove uses (https://searchfox.org/mozilla-central/rev/056a4057575029f58eb69ae89bc7b6c3c11e2e28/toolkit/components/places/nsNavBookmarks.cpp#630-631). 

NOTIFY_OBSERVERS doesn't have a skipIf parameter (https://searchfox.org/mozilla-central/rev/056a4057575029f58eb69ae89bc7b6c3c11e2e28/toolkit/components/places/nsPlacesMacros.h#15) the way NOTIFY_BOOKMARKS_OBSERVERS does. Therefore even with a skipTags = true, we'll still receive onItemChanged notifications when we tag URIs.

We can either:
1. Assume that preventing onItemAdded/onItemRemoved with skipTags + changing onItemChanged to an empty function in PlacesFeed.jsm is good enough, since it will already drastically reduce the notifications that go on when we sync or
2. I can mess around in nsNavBookmarks.cpp/nsPlacesMacros.h to incorporate a skipIf for onItemChanged notifications.

Marco, is there a specific reason NOTIFY_OBSERVERS doesn't already have a skipIf parameter? Or that setItemLastModified doesn't just use NOTIFY_BOOKMARKS_OBSERVERS instead?
Flags: needinfo?(mak77)
Fwiw, onItemChanged is not async in general.
regarding the tags problem, it's right that you can skipTags if not interested, but this clearly only affects users with quite some tags. Is this the case?

(In reply to Ursula Sarracini (:ursula) from comment #6)
> However, it doesn't prevent onItemChanged from firing.
> NOTIFY_OBSERVERS doesn't have a skipIf parameter
> (https://searchfox.org/mozilla-central/rev/
> 056a4057575029f58eb69ae89bc7b6c3c11e2e28/toolkit/components/places/
> nsPlacesMacros.h#15) the way NOTIFY_BOOKMARKS_OBSERVERS does. Therefore even
> with a skipTags = true, we'll still receive onItemChanged notifications when
> we tag URIs.

Good catch, it sounds like a bug.

> 2. I can mess around in nsNavBookmarks.cpp/nsPlacesMacros.h to incorporate a
> skipIf for onItemChanged notifications.
> 
> Marco, is there a specific reason NOTIFY_OBSERVERS doesn't already have a
> skipIf parameter? Or that setItemLastModified doesn't just use
> NOTIFY_BOOKMARKS_OBSERVERS instead?

we should use NOTIFY_BOOKMARKS_OBSERVERS.
the isTagging that is currently in SetItemLastModified is only partially correct, we should skip for isTagging but also if we are changing the last modified of a tag folder (isTagging || bookmark.parentId == tagsRootId)
Flags: needinfo?(mak77)
(In reply to Marco Bonardo [::mak] from comment #7)
> Fwiw, onItemChanged is not async in general.
> regarding the tags problem, it's right that you can skipTags if not
> interested, but this clearly only affects users with quite some tags. Is
> this the case?

Yeah based on the profiles that were shared in this bug and in bug 1440260, the main problem had to do with tagging URIs during a sync so that's what we're tackling here. 


> we should use NOTIFY_BOOKMARKS_OBSERVERS.
> the isTagging that is currently in SetItemLastModified is only partially
> correct, we should skip for isTagging but also if we are changing the last
> modified of a tag folder (isTagging || bookmark.parentId == tagsRootId)

Great, thanks! I'll make these additional changes to this bug.
Comment on attachment 8954828 [details]
Bug 1440276 - Activity Stream spikes after Bookmark activity, triggering lots of main thread work

https://reviewboard.mozilla.org/r/223948/#review230254

It would be great to have a brief xpcshell test added, that invokes the tagging API and checks the skip observer is not invoked. especially when we'll refactor the API, it will stay as a reminder to not introduce such a bug.
Otherwise, please file it as a follow-up.
Attachment #8954828 - Flags: review?(mak77) → review+
Blocks: 1442387
Filed 1442387 and assigned myself for the tests. Thanks Marco!
Pushed by usarracini@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/18dd09f4f5ba
Activity Stream spikes after Bookmark activity, triggering lots of main thread work r=mak
Commits pushed to master at https://github.com/mozilla/activity-stream

https://github.com/mozilla/activity-stream/commit/ba2b25a5e1a448f7d3664b22805b22441707a01f
Fix Bug 1440276 - Activity Stream spikes after Bookmark activity, triggering lots of main thread work

https://github.com/mozilla/activity-stream/commit/ca84fb168769868407b6d96d14651ed269fe8f3a
Merge pull request #4005 from sarracini/bug_1440276

chore(mc): Backport of Bug 1440276 - Activity Stream spikes after Bookmark activity, triggering lots of main thread work
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Blocks: 1441018
No longer blocks: 1441018
Target Milestone: --- → Firefox 60
Component: Activity Streams: Newtab → New Tab Page
You need to log in before you can comment on or make changes to this bug.