Notify user of addons that are slowing their browser down significantly

RESOLVED FIXED in Firefox 38

Status

()

Toolkit
Performance Monitoring
RESOLVED FIXED
3 years ago
9 months ago

People

(Reporter: billm, Assigned: blassey)

Tracking

(Depends on: 1 bug, Blocks: 2 bugs)

unspecified
mozilla38
x86_64
Linux
Points:
---
Dependency tree / graph
Bug Flags:
firefox-backlog +
qe-verify ?

Firefox Tracking Flags

(e10sm4+, firefox38 fixed, firefox39 fixed)

Details

Attachments

(1 attachment, 7 obsolete attachments)

(Reporter)

Description

3 years ago
It would be nice to identify add-ons that are causing jank because of their CPOW usage.

The code that sends CPOW messages is here:
http://mxr.mozilla.org/mozilla-central/source/js/ipc/WrapperOwner.cpp
Each time we invoke a method CallX (e.g., CallHasOwn), we're sending a sync message to the other process (typically the child). If we wrap these calls in some RAII class, we could easily count how much time we spend in them.

It's also possible to get the add-on ID causing the CPOW call at these sites. You can take any JSObject* (like the |proxy| argument to these methods) and call AddonIdOfObject(proxy). I would suggest keeping a global hashtable that maps from JSAddonId* to the total time spent doing CPOW work in that add-on. When you want to report, you can convert the add-on ID to a string with StringOfAddonId and send the data out through some XPCOM interface.
(Reporter)

Updated

3 years ago
tracking-e10s: --- → ?
(Assignee)

Updated

3 years ago
tracking-e10s: ? → +
So this is something that it might make more sense to wrap into the self support stuff of FHR rather than putting it in the add-ons UI. bsmedberg might have input here.
This bug should probably be broken into at least two pieces, measurement and reporting.

In terms of measurement, I think we should start with a telemetry probe. In particular, gfritzsche is currently working on "keyed" telemetry probes where you record a string-number pair. We could use this to record a histogram of individual CPOW call durations keyed by addon ID, which would be interesting both in terms of count and distribution.

In terms of reporting, let's see what the data shows and then we can decide whether and how we might want to warn actual users.
Depends on: 1069874
(Assignee)

Updated

3 years ago
Depends on: 1074567
(Reporter)

Comment 3

3 years ago
In the meeting today we decided to mark this m4 since it can mitigate problems with slow add-ons, which cause serious dogfooding issues right now.
tracking-e10s: + → m4+
Depends on: 1096785
(Reporter)

Updated

3 years ago
Assignee: nobody → blassey.bugs
Flags: firefox-backlog+
Created attachment 8541052 [details] [diff] [review]
check-addons.patch

I morphed this a bit to monitor addons for generally slowing performance of the browser. Bug 1097998 is putting warnings in the console for any unsafe CPOW usage, so I think that should cover the addon abusing CPOWs case.
Attachment #8541052 - Flags: feedback?(mconley)
(Assignee)

Updated

3 years ago
Attachment #8541052 - Flags: feedback?(dtownsend)
(Assignee)

Updated

3 years ago
Depends on: 1096718
Comment on attachment 8541052 [details] [diff] [review]
check-addons.patch

Review of attachment 8541052 [details] [diff] [review]:
-----------------------------------------------------------------

::: browser/base/content/browser-addonWatcher.js
@@ +27,5 @@
> +            gAddonWatcher._lastAddonTime[addonId] = addons[addonId];
> +        }
> +    },
> +    notifyAddonSlow: function(addonId) {
> +        AddonManager.getAddonByID(addonId, function(addon) {

Can we have Telemetry reporting for this?
The reporting would probably best tie into the selfsupport project (bug 1031506, with bug 1075153 being directly relevant), which would be based on that reported data.

::: browser/base/content/browser.js
@@ +218,5 @@
>  #include browser-safebrowsing.js
>  #include browser-social.js
>  #include browser-tabview.js
>  #include browser-thumbnails.js
> +#include browser-addonWatcher.js

Why not make this a JSM?
Created attachment 8541263 [details] [diff] [review]
check-addons.patch

This patch actually disables the addon when the user clicks disable and adds prefs as well as localizable strings
Attachment #8541052 - Attachment is obsolete: true
Attachment #8541052 - Flags: feedback?(mconley)
Attachment #8541052 - Flags: feedback?(dtownsend)
Attachment #8541263 - Flags: review?(mconley)
Attachment #8541263 - Flags: review?(dtownsend)
(Assignee)

Updated

3 years ago
Summary: Call out add-ons in about:addons that are doing lots of slow CPOW calls → Notify user of addons that are slowing their browser down significantly
Madhava, this probably needs some UX love. Who is best to look at it?

Here's the banner that pops up:
https://www.dropbox.com/s/tn0o6z58ax3qf3r/Screenshot%202014-12-29%2012.55.46.png?dl=0

and when you click disable it brings you to about:addons with the offending addon already disabled (but possibly with the "restart to disable" treatment if needed).
Flags: needinfo?(madhava)
Comment on attachment 8541263 [details] [diff] [review]
check-addons.patch

Review of attachment 8541263 [details] [diff] [review]:
-----------------------------------------------------------------

I think we want UX weigh in and thought around how often to show these notifications before landing even on nightly.

::: browser/base/content/browser-addonWatcher.js
@@ +1,5 @@
> +let gAddonWatcher = {
> +    _lastAddonTime: {},
> +    init: function() {
> +        // Check every minute
> +        window.setInterval(this.checkAddons, Preferences.get("browser.addon-watch.interval", 15000));

How expensive is this check? Checking every minute sounds like a lot, you could be getting a new notification every minute (also the actual code suggests it is scanning every 15 seconds). Maybe 5 minutes might be a more sensible default here.

@@ +19,5 @@
> +                    addons[compartment.addonId] = compartment.time;
> +                }
> +            }
> +        }
> +        let limit = Preferences.get("browser.addon-watch.limit", 10000);

So whether an add-on is deemed slow depends on how long between checks and the limit. A limit of 10s and an interval of 15s means an add-on must be using 66% of the time to warn. A limit of 10s and an interval of 30s means an addon only needs to use 33% of the time to warn. I think that will make it difficult to understand how to tune these prefs. It would be better instead to make the limit be the fraction of the interval, so 0.6666 (or 66 if you want to use the perhaps more human readable percentage).

@@ +21,5 @@
> +            }
> +        }
> +        let limit = Preferences.get("browser.addon-watch.limit", 10000);
> +        for (let addonId in addons) {
> +            if ((addons[addonId] - gAddonWatcher._lastAddonTime[addonId]) > limit) {

If the add-on wasn't present at the last scan this check fails. Not terrible but easy to fix.

@@ +28,5 @@
> +            gAddonWatcher._lastAddonTime[addonId] = addons[addonId];
> +        }
> +    },
> +    notifyAddonSlow: function(addonId) {
> +        AddonManager.getAddonByID(addonId, function(addon) {

Check if addon is non-null here, it might have been uninstalled between the last checks

@@ +36,5 @@
> +            if(n) {
> +                n.label = message;
> +            } else {
> +                let buttons = [{
> +                    label: 'Disable',

Move to the properties file.

@@ +39,5 @@
> +                let buttons = [{
> +                    label: 'Disable',
> +                    accessKey: 'D',
> +                    callback: function() {
> +                        if (addon) {

We should never get here if addon is null

@@ +43,5 @@
> +                        if (addon) {
> +                            addon.userDisabled = true;
> +                        }
> +                        gBrowser.selectedTab = gBrowser.addTab("about:addons");
> +                        browserWin.focus();

Don't think we need to open about:addons, just need to prompt the user to restart if necessary.

@@ +50,5 @@
> +
> +                const priority = nb.PRIORITY_WARNING_MEDIUM;
> +                nb.appendNotification(message, 'addon-slow' + addonId,
> +                                      'chrome://browser/skin/Info.png',
> +                                      priority, buttons);

I'll leave it to UX to weigh in on the specific notification mechanism here but I'm pretty sure we're going to want some way to not show a notification again even with the first patch. Unless I'm misreading if I dismiss the notification and ABP is consistently slow it's just going to show again at every check. Probably by default we only want to show once per add-on per session and then maybe offer a way to never show for an add-on.

Does this handle multiple add-ons being slow correctly or does it just show one of them?
Attachment #8541263 - Flags: review?(mconley)
Attachment #8541263 - Flags: review?(dtownsend)
Attachment #8541263 - Flags: review-
As a general question, why does this code live in browser.js? Looks like when opening four windows I would have four add-on checks running in the background? We should probably move this to a JSM to ensure it's only initialized once per Firefox instance.
(In reply to Tim Taubert [:ttaubert] from comment #9)
> As a general question, why does this code live in browser.js? Looks like
> when opening four windows I would have four add-on checks running in the
> background? We should probably move this to a JSM to ensure it's only
> initialized once per Firefox instance.

This is true too. Probably want something initialised from browserglue instead.
Passing this on to Philipp (though Stephen may have an opinion here, too).
Flags: needinfo?(philipp)
Flags: needinfo?(madhava)
Here's a bit of quick feedback:

- Let's use the word »Firefox« instead of »Browser« in the notification bar message.
- The button should say »Disable Adblock Plus«. If the add-on name is very long, we can collapse it to »Disale this Add-on«

- I'm a bit unsure about taking the user to the add-on manager after disabling, since he was probably in the course of doing something when the bar appeared. How about dropping another notification bar instead that says: »Adblock plus has been disabled. You can always re-enable it in the Add-on manager. <Take me to there>«. Ideally that notification bar would have a different icon (say, a checkmark) than the previous one.

Mildly related: it would be really nice if we could have different colors for those notification bars. Just yellow and black are kinda limiting.
Flags: needinfo?(philipp)
(In reply to Philipp Sackl [:phlsa] please use needinfo to make me respond from comment #12)
> Mildly related: it would be really nice if we could have different colors
> for those notification bars. Just yellow and black are kinda limiting.

We have three different styles of notification bar currently supported, info, warning and critical. On OX they translate to a background of #404040, #ffc703 and #980000
I'd like to see this split into two parts: The part that drives the UI, and the part that figures out what add-ons may be problematic. If we can have the later split off into something like AddonTroubleshooter.jsm/AddonDiagnostics.jsm/whatever.jsm in toolkit, it can be easily used elsewhere (and would tie in nicely with other plans for add-on diagnostics). It'd also make it far easier to test.
Created attachment 8552263 [details] [diff] [review]
check-addons.patch
Attachment #8541263 - Attachment is obsolete: true
Attachment #8552263 - Flags: review?(dtownsend)
(Assignee)

Updated

3 years ago
Blocks: 1124073
On Mossop's advice, I split the UX off into bug 1124073. The patch I've put up for review here should be enough of a UX to get this landed and tested in Nightly.
Comment on attachment 8552263 [details] [diff] [review]
check-addons.patch

Review of attachment 8552263 [details] [diff] [review]:
-----------------------------------------------------------------

This isn't right. You have a singleton AddonWatcher and every browser window calls its init method giving it a new callback to use. When we find a slow add-on it will call the callback for the most recently opened window, which may not be open anymore.

Instead init AddonWatcher from nsBrowserGlue and have it handle showing the notification in the current window (see f.e. http://mxr.mozilla.org/mozilla-central/source/browser/components/nsBrowserGlue.js#660). Should be a quick re-review with that change.

Can we test this by mocking nsICompartmentInfo?

::: browser/base/content/browser.js
@@ +938,5 @@
> +        let brandBundle = document.getElementById("bundle_brand");
> +        let brandShortName = brandBundle.getString("brandShortName");
> +        let message = gNavigatorBundle.getFormattedString("addonwatch.slow", [addon.name, brandShortName]);
> +        let notificationBox = document.getElementById("global-notificationbox");
> +        let notificationId = 'addon-slow' + addonId;

Put a : before the ID just to make this look sort of sensible

::: modules/libpref/init/all.js
@@ +4449,5 @@
>  // IndexedDB transactions to be opened as readonly or keep everything as
>  // readwrite.
>  pref("dom.mozSettings.allowForceReadOnly", false);
>  
> +pref("browser.addon-watch.interval", 15000);

Add a comment saying what units this is in

::: toolkit/modules/AddonWatcher.jsm
@@ +13,5 @@
> +
> +XPCOMUtils.defineLazyModuleGetter(this, "Preferences",
> +                                  "resource://gre/modules/Preferences.jsm");
> +XPCOMUtils.defineLazyModuleGetter(this, "AddonManager",
> +                                  "resource://gre/modules/AddonManager.jsm");

This module is unused now

@@ +20,5 @@
> +  _lastAddonTime: {},
> +  _timer: Cc["@mozilla.org/timer;1"].createInstance(Ci.nsITimer),
> +  _callback: null,
> +  _interval: 1500,
> +  _ignoreList: [],

Use a Set here

@@ +24,5 @@
> +  _ignoreList: [],
> +  init: function(callback) {
> +    this._callback = callback;
> +    this._interval = Preferences.get("browser.addon-watch.interval", 15000);
> +    this._timer.initWithCallback(this.checkAddons.bind(this), this._interval, Ci.nsITimer.TYPE_REPEATING_SLACK);

For safety don't restart the timer if this method gets called twice.

@@ +26,5 @@
> +    this._callback = callback;
> +    this._interval = Preferences.get("browser.addon-watch.interval", 15000);
> +    this._timer.initWithCallback(this.checkAddons.bind(this), this._interval, Ci.nsITimer.TYPE_REPEATING_SLACK);
> +  },
> +  checkAddons: function() {

Prefix with _, external users shouldn't be calling this.
Attachment #8552263 - Flags: review?(dtownsend) → review-
Created attachment 8556245 [details] [diff] [review]
check-addons.patch
Attachment #8552263 - Attachment is obsolete: true
Attachment #8556245 - Flags: review?(dtownsend)
Created attachment 8556246 [details] [diff] [review]
check-addons.patch
Attachment #8556245 - Attachment is obsolete: true
Attachment #8556245 - Flags: review?(dtownsend)
Attachment #8556246 - Flags: review?(dtownsend)
Comment on attachment 8556246 [details] [diff] [review]
check-addons.patch

Review of attachment 8556246 [details] [diff] [review]:
-----------------------------------------------------------------

So, tests?

::: browser/components/nsBrowserGlue.js
@@ +558,5 @@
>    },
>  
> +  _notifySlowAddon: function BG_notifySlowAddon(addonId) {
> +    let addonCallback = function(addon) {
> +      let win = RecentWindow.getMostRecentBrowserWindow();

win might be null if there are no browser windows open, bail out if so.

::: toolkit/modules/AddonWatcher.jsm
@@ +59,5 @@
> +      }
> +    }
> +  },
> +  ignoreAddonForSession: function(addonid) {
> +    this._ignoreList.push(addonid);

add, not push
Attachment #8556246 - Flags: review?(dtownsend) → review+
Comment on attachment 8556246 [details] [diff] [review]
check-addons.patch

Review of attachment 8556246 [details] [diff] [review]:
-----------------------------------------------------------------

::: browser/locales/en-US/chrome/browser/browser.properties
@@ +39,5 @@
>  addonDownloadRestart=Restart Download;Restart Downloads
>  addonDownloadRestart.accessKey=R
>  addonDownloadCancelTooltip=Cancel
>  
> +addonwatch.slow=%S is making %S run slow

"run slow" -> "run slowly", I think.

Comment 22

2 years ago
(In reply to Mike Conley (:mconley) - Needinfo me! from comment #21)
> Review of attachment 8556246 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> ::: browser/locales/en-US/chrome/browser/browser.properties
> @@ +39,5 @@
> >  addonDownloadRestart=Restart Download;Restart Downloads
> >  addonDownloadRestart.accessKey=R
> >  addonDownloadCancelTooltip=Cancel
> >  
> > +addonwatch.slow=%S is making %S run slow
> 
> "run slow" -> "run slowly", I think.

I'd like to also request slightly less absolute language, e.g.

addonwatch.slow=%S may be causing %S to run slowly

Performance problems with addons, especially on older computers with lots of addons installed, could be harder to diagnose. I would prefer to avoid people thinking that this detection is guaranteed to tell them all they need to know.
https://hg.mozilla.org/integration/fx-team/rev/f84850059d9e

(In reply to Dave Townsend [:mossop] from comment #20)
> So, tests?

I'm not really familiar with desktop testing
Backed out in https://hg.mozilla.org/integration/fx-team/rev/7c41319254b1 for browser-chrome-3 failures:

https://treeherder.mozilla.org/logviewer.html#?job_id=1839877&repo=fx-team

There's also a bunch of other failures that I can't quite pin on this, but there haven't been any other changes that could've broken things:

https://treeherder.mozilla.org/logviewer.html#?job_id=1839870&repo=fx-team
https://treeherder.mozilla.org/logviewer.html#?job_id=1839645&repo=fx-team
https://treeherder.mozilla.org/logviewer.html#?job_id=1839957&repo=fx-team


This should probably get a full try run before it lands again.
Flags: needinfo?(blassey.bugs)
(Assignee)

Updated

2 years ago
Flags: needinfo?(blassey.bugs)
Created attachment 8557380 [details] [diff] [review]
check-addons.patch

ran mochitests locally didn't hit this

https://treeherder.mozilla.org/#/jobs?repo=try&revision=17f97878e78a
Attachment #8556246 - Attachment is obsolete: true
Attachment #8557380 - Flags: review?(dtownsend)
(In reply to Brad Lassey [:blassey] (use needinfo?) from comment #25)
> Created attachment 8557380 [details] [diff] [review]
> check-addons.patch
> 
> ran mochitests locally didn't hit this
> 
> https://treeherder.mozilla.org/#/jobs?repo=try&revision=17f97878e78a

So many crashes in that run, almost all with nsCompartmentInfo::GetCompartments in the stack. That code clearly has problems.
Comment on attachment 8557380 [details] [diff] [review]
check-addons.patch

Review of attachment 8557380 [details] [diff] [review]:
-----------------------------------------------------------------

r+ for this code but we can't land it (or at least can't land it enabled) until the crashes are solved.
Attachment #8557380 - Flags: review?(dtownsend) → review+
(Reporter)

Comment 28

2 years ago
The patch in bug 1131382 will probably fix the crashes.
(Assignee)

Updated

2 years ago
Depends on: 1131382
it did https://treeherder.mozilla.org/#/jobs?repo=try&revision=e6e1ae4f009c
Backed out in https://hg.mozilla.org/integration/mozilla-inbound/rev/6ed69c4d2c15 for various failures.

https://treeherder.mozilla.org/logviewer.html#?job_id=6553985&repo=mozilla-inbound
https://treeherder.mozilla.org/logviewer.html#?job_id=6553933&repo=mozilla-inbound
https://treeherder.mozilla.org/logviewer.html#?job_id=6552252&repo=mozilla-inbound
https://treeherder.mozilla.org/logviewer.html#?job_id=6554234&repo=mozilla-inbound
Flags: needinfo?(blassey.bugs)
https://treeherder.mozilla.org/logviewer.html#?job_id=6553739&repo=mozilla-inbound was one of my favorites, where the screenshot, http://mozilla-releng-blobs.s3.amazonaws.com/blobs/mozilla-inbound/sha512/1efea6a2f99f8b6ccfa62d8cca1fcd8171b328c436a8ec36b558008fe97ebfd4a121be10e8ad73d21a8128d8c8f58a133baf6b5a0ae694af9979c848ca4e7e3a, shows you telling the test automation that it should disable the SpecialPowers extension.

Two parts of the fuller full try run you'll want to include the next time are debug, since it runs slower and tells you about leaks (of which there were plenty), and talos, since the Win7-only xperf talos run doesn't like you touching addons.sqlite without telling it that it should expect you will.
KWierso said this probably also caused bug 1083952 to flare up.
(Reporter)

Comment 33

2 years ago
We probably want this controlled by a pref so it's only enabled during the test that tests it.
(In reply to Bill McCloskey (:billm) from comment #33)
> We probably want this controlled by a pref so it's only enabled during the
> test that tests it.

Mossop didn't like that idea earlier.
Flags: needinfo?(blassey.bugs)
(In reply to Brad Lassey [:blassey] (use needinfo?) from comment #34)
> (In reply to Bill McCloskey (:billm) from comment #33)
> > We probably want this controlled by a pref so it's only enabled during the
> > test that tests it.
> 
> Mossop didn't like that idea earlier.

We can do that as a fallback, we just get better testing if it runs as it would in reality
See Also: → bug 1132498
Created attachment 8564267 [details] [diff] [review]
patch for checkin
Attachment #8564267 - Flags: review+
(Assignee)

Updated

2 years ago
Keywords: checkin-needed
try push for this https://treeherder.mozilla.org/#/jobs?repo=try&revision=e6e1ae4f009c r+ from mossop on irc
That Try run still shows the same ASAN leaks and Win7 mochitest-5 failures that this got backed out for previously.
Keywords: checkin-needed
linked to the wrong try push https://treeherder.mozilla.org/#/jobs?repo=try&revision=a58f9c5b2f96

landed https://hg.mozilla.org/integration/fx-team/rev/2439c229cace
https://hg.mozilla.org/mozilla-central/rev/2439c229cace
Status: NEW → RESOLVED
Last Resolved: 2 years ago
status-firefox38: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla38

Updated

2 years ago
Iteration: --- → 38.3 - 23 Feb
Flags: qe-verify?
http://hg.mozilla.org/mozilla-central/diff/2439c229cace/browser/locales/en-US/chrome/browser/browser.properties

addonwatch.slow=%S might be making %S run slowly
addonwatch.restart.message=To disable %S you must restart %S

Can we please use ordered arguments (%1$S, %2$S) and localization comments when adding strings like this?
Depends on: 1133554
Depends on: 1083952
Bug 1083952 started happening frequently once this relanded, so I'm guessing this is to blame.
(In reply to Andrew McCreight [:mccr8] from comment #42)
> Bug 1083952 started happening frequently once this relanded, so I'm guessing
> this is to blame.
Flags: needinfo?(blassey.bugs)

Comment 44

2 years ago
Hi, 

How can I test this? I read the comments, I have a Nightly (38.0a1 (2015-02-17)).
This is an awesome feature :D Can't wait to get rid of my slow adons!
If you're running the latest Nightly and one of your add-ons causes slowdown, a yellow bar should pop up at the bottom of the window asking if you want to disable it. I've seen this for half a dozen of my add-ons already today ;)

Comment 46

2 years ago
Might I be suspicious about what exactly this code decides to tag an add-on to make the browser to become stalled ?
It flags an add-on which made my browser feel & behave featherlight (uBlock) while it doesn't flag an add-on which clearly made my browser slow and unresponsive (ABP in my case).....

Comment 47

2 years ago
It worked :D:D
I took Nightly for a spin and nothing happened so I started using it for as default browser and it started complaining about AdBlock Edge, Wappalyzer, Scrum for Trello, Jump to tab number, Privacy Badger.
I disabled all except AdBlockEdge :D and this thing flies now!!! It's so damn fast!
(In reply to Francesco Lodolo [:flod] from comment #41)
> Can we please use ordered arguments (%1$S, %2$S) and localization comments
> when adding strings like this?

I filed bug 1133554 for this, but it actually covers a bigger issue with the "Restart Firefox" button, currently showing up as "Restart N" on m-c.
(In reply to Francesco Lodolo [:flod] from comment #48)
> (In reply to Francesco Lodolo [:flod] from comment #41)
> > Can we please use ordered arguments (%1$S, %2$S) and localization comments
> > when adding strings like this?
> 
> I filed bug 1133554 for this, but it actually covers a bigger issue with the
> "Restart Firefox" button, currently showing up as "Restart N" on m-c.

Thanks Flod. I'm a front end code newbie, so both of those things are new to me.

(In reply to Andrew McCreight [:mccr8] from comment #42)
> Bug 1083952 started happening frequently once this relanded, so I'm guessing
> this is to blame.

Andrew, the message about these leaks is pretty unhelpful. Any suggestions?
Flags: needinfo?(blassey.bugs)
(In reply to Brad Lassey [:blassey] (use needinfo?) from comment #49)
> Andrew, the message about these leaks is pretty unhelpful. Any suggestions?

An XPCWrappedNative is how we expose C++ things to JS, like when you do |Cc["@mozilla.org/timer;1"].createInstance(Ci.nsITimer)|.  Somehow one of these XPCWNs isn't being torn down correctly at shutdown.  You are probably triggering some kind of underlying platform issue, as XPCWN refcounting is a little weird.

You could try looking at what kind of things implemented in C++ you might be keeping alive, and then explicitly destroying them or freeing them or something at xpcom-shutdown.  I'd start with the timer first.  I could imagine some weird case where if it fires at the wrong time at shutdown you get in some wedged state, so maybe shut that off in shutdown.

Comment 51

2 years ago
When and where will the telemetry be available for detected slow addons? I would very much prefer a pile of data to hand out to addon developers to attempt to address issues long before this hits release.
AFAIK bug 674779 removes nsICompartment::time which we use here, so this patch may have to be fixed.
Nit: _interval: 1500 vs Preferences.get("browser.addon-watch.interval", 15000); => two different default values. It doesn't really matter, because the latter overwrites the former, but it doesn't look nice either.
(In reply to Brad Lassey [:blassey] (use needinfo?) from comment #49)
> Thanks Flod. I'm a front end code newbie, so both of those things are new to
> me.

Note also that we need to fix the strings before the end of cycle, to avoid slipping into Aurora unnecessarily with new strings.
Could you guys have at least posted somewhere that this was happening and told add-ons developers can do to mitigate?

http://mikeconley.ca/blog/2015/02/17/on-unsafe-cpow-usage-in-firefox-desktop-and-why-is-my-nightly-so-sluggish-with-e10s-enabled/

is really nice, but it never once mentions this error message.

It should be called "what Add-on developer can do to stop the 'run slowly' popup"
Backed out for causing bug 1083952.

https://hg.mozilla.org/integration/mozilla-inbound/rev/acf46fe8b054
Status: RESOLVED → REOPENED
Resolution: FIXED → ---

Comment 56

2 years ago
needinfo? for comment 51 & comment 54

We really need telemetry and more info to avoid another instance where addon developer get blamed for issues they don't know about or know how to fix.
Flags: needinfo?(blassey.bugs)
(Reporter)

Comment 57

2 years ago
Looking at the code, something seems off to me:
http://mxr.mozilla.org/mozilla-central/source/toolkit/modules/AddonWatcher.jsm#58
It seems like the correct calculation would be:
let limit = this._interval * Preferences.get("browser.addon-watch.percentage-limit", 75) / 100;
(dividing by 100 instead of multiplying by 10).

If I'm right, the fact that this is ever triggering suggests we have a bug in the compartment time accounting. If, in 120 seconds, an add-on uses more than 1200 seconds of time, then something is pretty messed up.
How do you come up with 1200 seconds? nsICompartment::time is in microseconds, so if interval is 120k and percentage-limit is 1:

120k * 1 * 10 = 1.2 Million microseconds = 1.2 seconds

120k * 1 / 100 = 0.0012 seconds

In any case, the whole calculation should get revised on top of bug 674779's changes. Then we'd have to calculate with milliseconds:

https://reviewboard.mozilla.org/r/3941/diff/0#13
(Reporter)

Comment 59

2 years ago
Oh, I forgot about the units. That really deserves a comment or something.
(In reply to Francesco Lodolo [:flod] from comment #53)
> (In reply to Brad Lassey [:blassey] (use needinfo?) from comment #49)
> > Thanks Flod. I'm a front end code newbie, so both of those things are new to
> > me.
> 
> Note also that we need to fix the strings before the end of cycle, to avoid
> slipping into Aurora unnecessarily with new strings.

Until we have the UX approved (bug 1124073) and have made sure the numbers are working and have tuned how often this shows up (it feels a little over-zealous right now) I suggest we don't let this ride the trains. What do you think Brad?
I concur that this should stay on Nightly for at least a while so we can tune it, and try to give add-on developers more information about what parts of their code need quickening.
Note that this is already getting a little press:

http://www.ghacks.net/2015/02/18/firefox-38-notifies-you-about-add-ons-that-slow-down-the-browser/
:mconley

Bug 674779 removes nsICompartment::time and instead gives us totalUserTime, totalSystemTime, ownUserTime, ownSystemTime and cpowTime (and also a visits count fwiw). see #c58.
These numbers may differ from the current measurement, so IMHO tuning it now could be a waste of resources.
Note that bug 674779 is meant for Nightly only until we have benchmarked it. My personal benchmarks indicate a ~2% slowdown on a debug build, so it is possible that we may decide to rework the code some more before we let it ride the trains.
(In reply to Dave Townsend [:mossop] from comment #60)
> (In reply to Francesco Lodolo [:flod] from comment #53)
> > (In reply to Brad Lassey [:blassey] (use needinfo?) from comment #49)
> > > Thanks Flod. I'm a front end code newbie, so both of those things are new to
> > > me.
> > 
> > Note also that we need to fix the strings before the end of cycle, to avoid
> > slipping into Aurora unnecessarily with new strings.
> 
> Until we have the UX approved (bug 1124073) and have made sure the numbers
> are working and have tuned how often this shows up (it feels a little
> over-zealous right now) I suggest we don't let this ride the trains. What do
> you think Brad?

I agree, this should probably be held to Nightly and Aurora for now.
Flags: needinfo?(blassey.bugs)
Merge of backout:
https://hg.mozilla.org/mozilla-central/rev/acf46fe8b054

Comment 67

2 years ago
How do I disable this feature permanently?  Clicking "Ignore permanently" doesn't act globally and nags me on every window.  I have a lot of extensions and I'm not going to disable any of them to pacify this feature.

And not to mention the known irony that this feature is responsible for slowing down my browser even more.

Could you please add a pref, such as "browser.addon-watch.disabled," that we can toggle true/false

Thanks
Setting "browser.addon-watch.interval" to -1 should resolve ULONG_MAX in nsiTimer, which would practically disable this feature, because ULONG_MAX is 4294967295 milliseconds = 49.7102696 days and it's very unlikely your browser is opened that long.

Comment 69

2 years ago
Could you add a better way to disable this feature when landing next? Simply having it disabled with browser.addon-watch.interval set to zero or negative would be the easiest to do without having to add another pref.
Flags: needinfo?(blassey.bugs)
Depends on: 1133481
(Assignee)

Updated

2 years ago
Flags: needinfo?(blassey.bugs)
Created attachment 8567978 [details] [diff] [review]
check-addons.patch

https://treeherder.mozilla.org/#/jobs?repo=try&revision=7314e269d662
Attachment #8557380 - Attachment is obsolete: true
Attachment #8564267 - Attachment is obsolete: true
Attachment #8567978 - Flags: review?(dtownsend)

Updated

2 years ago
Iteration: 38.3 - 23 Feb → 39.1 - 9 Mar
Comment on attachment 8567978 [details] [diff] [review]
check-addons.patch

Review of attachment 8567978 [details] [diff] [review]:
-----------------------------------------------------------------

This looks good. Can you write up a blog post about this so we have something initial to point to.

::: toolkit/modules/AddonWatcher.jsm
@@ +49,5 @@
> +      this._timer = null;
> +    }
> +  },
> +  _checkAddons: function() {
> +    Cu.reportError("check addons");

Remove this
Attachment #8567978 - Flags: review?(dtownsend) → review+
Benjamin, does it make sense to add telemetry for slow add-ons or is this something self-support will be handling separately?
Flags: needinfo?(benjamin)
Duplicate of this bug: 1133554
Comment on attachment 8567978 [details] [diff] [review]
check-addons.patch

Review of attachment 8567978 [details] [diff] [review]:
-----------------------------------------------------------------

::: browser/locales/en-US/chrome/browser/browser.properties
@@ +39,5 @@
>  addonDownloadRestart=Restart Download;Restart Downloads
>  addonDownloadRestart.accessKey=R
>  addonDownloadCancelTooltip=Cancel
>  
> +addonwatch.slow=%1$S might be making %2$S run slowly

Can you add comments at least where there are 2 variables, explaining the replacements?
https://hg.mozilla.org/integration/mozilla-inbound/rev/683ba9ea96a3
https://hg.mozilla.org/mozilla-central/rev/683ba9ea96a3
Status: REOPENED → RESOLVED
Last Resolved: 2 years ago2 years ago
status-firefox39: --- → fixed
Resolution: --- → FIXED
(In reply to Dave Townsend [:mossop] from comment #72)
> Benjamin, does it make sense to add telemetry for slow add-ons or is this
> something self-support will be handling separately?

Yes, uploading this through Telemetry is planned. Filed as bug 1136923.
Blocks: 1136923
Flags: needinfo?(benjamin)
Blocks: 1136935
Blocks: 1136936

Comment 78

2 years ago
Can someone point me to an explanation of how this measures slowdown? Saw discussion above, but couldn't find a source for more specifics.

[I maintain an extension that was flagged, but I'm only seeing CPU spikes when the extension is doing its work (when DOM changes on a specific webpage). If that's the case, then maybe I need to speed that up... if that's not the case, I'd love to find where the bottlenecks are.]

Thanks! :)
Brad posted some more details here: http://blog.lassey.us/2015/02/25/detecting-slow-add-ons/

Let's take any further discussion here to newsgroups or new bug reports if there are specific issues.

Updated

2 years ago
Depends on: 1137366

Updated

2 years ago
Blocks: 1137369
Depends on: 1137792
Blocks: 1138606

Updated

2 years ago
Duplicate of this bug: 610097

Comment 81

2 years ago
Should I report as a bug having this pop up when I have mutliprocess turned off?

And is there a way to reset this if you've told it to Ignore Permanently?

Comment 82

2 years ago
(In reply to Terrell Kelley from comment #81)
>And is there a way to reset this if you've told it to Ignore Permanently?

I guess you could wipe/edit the about:config string: browser.addon-watch.ignore?
(In reply to Terrell Kelley from comment #81)
> Should I report as a bug having this pop up when I have mutliprocess turned
> off?

This feature is unrelated to multiprocess so no it is not a bug it is expected that we detect slow add-ons even in single process.

Updated

2 years ago
Duplicate of this bug: 1108748
Component: JavaScript Engine → Performance Monitoring
Product: Core → Toolkit
Depends on: 1153198

Comment 85

2 years ago
I disabled this function via "browser.addon-watch.interval" = -1 and "browser.addon-watch.percentage-limit" = -1.
This worked until one of the earlier nightly 45 versions.
Yesterday I updated to the newest nightly 45.0a1 and the values seem to be ignored - the warning bar is showing again.
Can anyone reproduce this? 
How can I disable it now?
Ah, right, the AddonWatcher has been fully reimplemented. I believe that setting "browser.addon-watch.deactivate-after-idle-ms" to 0 should be good.

Updated

a year ago
Duplicate of this bug: 597282

Updated

9 months ago
Depends on: 1309946
You need to log in before you can comment on or make changes to this bug.