The 8472 Reporter
	Description • 9 years ago

I'm seeing the following in my profile with ~1600 tabs (most of them lazy-loaded):

54,570 (100.0%) -- observer-service-suspect
├───5,167 (09.47%) ── referent(topic=memory-pressure)
├───3,487 (06.39%) ── referent(topic=xpcom-shutdown)
├───3,387 (06.21%) ── referent(topic=before-first-paint)
├───1,726 (03.16%) ── referent(topic=chrome-flush-skin-caches)
├───1,723 (03.16%) ── referent(topic=agent-sheet-added)
├───1,723 (03.16%) ── referent(topic=agent-sheet-removed)
├───1,723 (03.16%) ── referent(topic=author-sheet-added)
├───1,723 (03.16%) ── referent(topic=author-sheet-removed)
├───1,723 (03.16%) ── referent(topic=user-sheet-added)
├───1,723 (03.16%) ── referent(topic=user-sheet-removed)
├───1,701 (03.12%) ── referent(topic=network:offline-status-changed)
├───1,700 (03.12%) ── referent(topic=dom-storage2-changed)
├───1,695 (03.11%) ── referent(topic=sdk:loader:destroy)
├───1,693 (03.10%) ── referent(topic=app-theme-changed)
├───1,692 (03.10%) ── referent(topic=browser:purge-domain-data)
├───1,692 (03.10%) ── referent(topic=earlyformsubmit)
├───1,691 (03.10%) ── referent(topic=audio-playback)
├───1,691 (03.10%) ── referent(topic=audiochannel-activity-alarm)
├───1,691 (03.10%) ── referent(topic=audiochannel-activity-content)
├───1,691 (03.10%) ── referent(topic=audiochannel-activity-normal)
├───1,691 (03.10%) ── referent(topic=audiochannel-activity-notification)
├───1,691 (03.10%) ── referent(topic=audiochannel-activity-publicnotification)
├───1,691 (03.10%) ── referent(topic=audiochannel-activity-ringer)
├───1,691 (03.10%) ── referent(topic=audiochannel-activity-telephony)
├───1,691 (03.10%) ── referent(topic=author-style-disabled-changed)
├───1,691 (03.10%) ── referent(topic=invalidformsubmit)
├───1,691 (03.10%) ── referent(topic=keyword-uri-fixup)
└───1,691 (03.10%) ── referent(topic=style-sheet-applicable-state-changed)




For example the topic "earlyformsubmit" is registered by the framescript chrome://satchel/content/formSubmitListener.js


Since the observer service has to notify each callback this results in O(n) runtime each time some tab triggers the observer service even though almost all callbacks bail out early and only one of the frame scripts actually handles it.

By registering them in a process script or JSM and resolving back to a tab-specific callback with a hash map or by walking the doc tree up to the frame message manager where needed this could be reduced to O(1).

	The 8472 Reporter
	Comment 1 • 9 years ago

It also affects memory usage, the frame scripts for lazy-loaded tabs weigh about 2-3 times as much as the about:blank windows on a clean profile. Additional addons can increase this further.

	:Gijs (he/him)
	Comment 2 • 8 years ago

Seems like this should be a meta bug with individual bugs for the individual observers in question.

The8472, can you provide an updated "highscore list", so to speak? :-)

	The 8472 Reporter
	Comment 3 • 8 years ago

clean profile, 1000 blank tabs:



14,456 (100.0%) -- observer-service-suspect
├───1,110 (07.68%) ── referent(topic=memory-pressure)
├───1,072 (07.42%) ── referent(topic=service-worker-get-client)
├───1,019 (07.05%) ── referent(topic=network:offline-status-changed)
├───1,017 (07.04%) ── referent(topic=browser:purge-session-history)
├───1,014 (07.01%) ── referent(topic=app-theme-changed)
├───1,014 (07.01%) ── referent(topic=dom-storage2-changed)
├───1,008 (06.97%) ── referent(topic=browser:purge-domain-data)
├───1,008 (06.97%) ── referent(topic=earlyformsubmit)
├───1,007 (06.97%) ── referent(topic=audio-playback)
├───1,006 (06.96%) ── referent(topic=dom-window-destroyed)
├───1,006 (06.96%) ── referent(topic=invalidformsubmit)
├───1,005 (06.95%) ── referent(topic=author-style-disabled-changed)
├───1,005 (06.95%) ── referent(topic=keyword-uri-fixup)
├───1,005 (06.95%) ── referent(topic=style-sheet-applicable-state-changed)
└─────160 (01.11%) ── referent(topic=xpcom-shutdown)


real profile with ~1500 tabs and several addons:


28,001 (100.0%) -- observer-service-suspect
├───6,135 (21.91%) ── referent(topic=sdk:loader:destroy)
├───1,716 (06.13%) ── referent(topic=memory-pressure)
├───1,661 (05.93%) ── referent(topic=service-worker-get-client)
├───1,550 (05.54%) ── referent(topic=browser:purge-session-history)
├───1,527 (05.45%) ── referent(topic=app-theme-changed)
├───1,526 (05.45%) ── referent(topic=network:offline-status-changed)
├───1,521 (05.43%) ── referent(topic=dom-storage2-changed)
├───1,514 (05.41%) ── referent(topic=earlyformsubmit)
├───1,513 (05.40%) ── referent(topic=audio-playback)
├───1,511 (05.40%) ── referent(topic=browser:purge-domain-data)
├───1,510 (05.39%) ── referent(topic=dom-window-destroyed)
├───1,509 (05.39%) ── referent(topic=invalidformsubmit)
├───1,508 (05.39%) ── referent(topic=author-style-disabled-changed)
├───1,508 (05.39%) ── referent(topic=keyword-uri-fixup)
├───1,508 (05.39%) ── referent(topic=style-sheet-applicable-state-changed)
└─────284 (01.01%) ── referent(topic=xpcom-shutdown)



Both are taken from the parent process.

	:Gijs (he/him)
	Comment 4 • 8 years ago

I'll look at filing bugs for this hopefully later this week.

	:Gijs (he/him)
	Comment 5 • 8 years ago

So, based on the 'real profile' list (the other list has no entries unique to itself, AFAICT)

> ├───6,135 (21.91%) ── referent(topic=sdk:loader:destroy)

Filed bug 1250469.

> ├───1,716 (06.13%) ── referent(topic=memory-pressure)

This lives on nsDocShell(well, and in a number of more specific places), so AFAICT it's not unique to e10s, and I don't know that there's a sensible way to deduplicate them that actually helps - all docshells presumably need to do stuff when there's memory pressure.

> ├───1,661 (05.93%) ── referent(topic=service-worker-get-client)

This lives on nsDocument, so it's also not restricted to e10s. It's not clear to me that/how this could be deduplicated. It looks like it's used to get a list of documents for a service worker based on some identifier for the service worker, but from the code it looks like there could be more than 1 such document. I still think there might be something that could be improved here, so I filed bug 1250502.

> ├───1,550 (05.54%) ── referent(topic=browser:purge-session-history)

Filed bug 1250472.

> ├───1,527 (05.45%) ── referent(topic=app-theme-changed)

This lives on nsDocument as well, so also not e10s-specific. However, these are only useful for privileged documents, and you don't have 1500 privileged documents (though... if we load about:newtab in all those unloaded tabs (do we load about:blank? I forget...), maybe you do and this won't help much...). Filed bug 1250503 to improve this.

Just noticed that there's also imgLoader that registers for these. I don't know how the number of those scales compared to the number of images/documents, and they do all care about the notification, so that seems less problematic (ie we could change the location of the O(n) iteration but it'd still be O(n) for however many imgLoaders we've got).

> ├───1,526 (05.45%) ── referent(topic=network:offline-status-changed)

I actually don't know what is registering these 1500 odd observers. :-\

Looking at:
https://dxr.mozilla.org/mozilla-central/search?q=network%3Aoffline-status-changed+-path%3Atest+-path%3Aobj-x86+-path%3Aidl&redirect=false&case=false

almost everything is a service or otherwise a singleton. Dropping off the "network:" I found a few more cases, and network seems to define a generic C++ OfflineObserver wrapper, but it's not clear how that scales and/or that that can really be O(1) anyway.

> ├───1,514 (05.41%) ── referent(topic=earlyformsubmit)

Filed bug 1250473.


> ├───1,509 (05.39%) ── referent(topic=invalidformsubmit)

Filed bug 1250487.

> ├───1,521 (05.43%) ── referent(topic=dom-storage2-changed)
> ├───1,513 (05.40%) ── referent(topic=audio-playback)
> ├───1,511 (05.40%) ── referent(topic=browser:purge-domain-data)
> ├───1,510 (05.39%) ── referent(topic=dom-window-destroyed)
> ├───1,508 (05.39%) ── referent(topic=author-style-disabled-changed)
> ├───1,508 (05.39%) ── referent(topic=keyword-uri-fixup)
> ├───1,508 (05.39%) ── referent(topic=style-sheet-applicable-state-changed)
> └─────284 (01.01%) ── referent(topic=xpcom-shutdown)

I'll look at these another time; leaving needinfo.

	:Gijs (he/him)
	Comment 6 • 7 years ago

New list, 204-or-so tabs:


4,195 (100.0%) -- observer-service-suspect
├────571 (13.61%) ── referent(topic=xpcom-shutdown)
├────324 (07.72%) ── referent(topic=memory-pressure)
├────214 (05.10%) ── referent(topic=browser:purge-session-history)
├────214 (05.10%) ── referent(topic=network:offline-status-changed)
├────210 (05.01%) ── referent(topic=dom-private-storage2-changed)
├────210 (05.01%) ── referent(topic=dom-storage2-changed)
├────207 (04.93%) ── referent(topic=browser:purge-domain-data)
├────205 (04.89%) ── referent(topic=decoder-doctor-notification)
├────205 (04.89%) ── referent(topic=earlyformsubmit)
├────204 (04.86%) ── referent(topic=audio-playback)
├────204 (04.86%) ── referent(topic=AudioFocusChanged)
├────204 (04.86%) ── referent(topic=author-style-disabled-changed)
├────204 (04.86%) ── referent(topic=dom-window-destroyed)
├────204 (04.86%) ── referent(topic=invalidformsubmit)
├────204 (04.86%) ── referent(topic=keyword-uri-fixup)
├────204 (04.86%) ── referent(topic=MediaControl)
├────204 (04.86%) ── referent(topic=style-sheet-applicable-state-changed)
└────203 (04.84%) ── referent(topic=service-worker-get-client)

	:Gijs (he/him)
	Comment 7 • 7 years ago

I believe I've now filed bugs for all the remaining items I see showing up on this list myself and in the later comments from the reporter.

I'm a bit confused by the list itself, though, and what I see when I check the observer notifications in the debugger. In particular, comment #0 lists:

├───3,387 (06.21%) ── referent(topic=before-first-paint)
├───1,726 (03.16%) ── referent(topic=chrome-flush-skin-caches)

I don't see these in my lists (and they didn't appear in the reporter's lists since comment #0), but I do see them when I add a C++ breakpoint.

chrome-flush-skin-caches will go away when we stop supporting complete themes, as the new-style themes won't be bothered by this caching anymore.

I'll file another bug for before-first-paint, I guess.