1191342 - Slow add-on warning, even if my add-ons do nothing (SDK / Jetpack)

Status: RESOLVED FIXED

(Toolkit :: Performance Monitoring, defect)

Description

[Hubert Figuiere [:hub]]

I have two add-ons I wrote with Jetpack

https://addons.mozilla.org/en-US/firefox/addon/no-flash/?src=ss
https://addons.mozilla.org/en-US/firefox/addon/tweet-that/?src=ss

Both trigger the "Slow addon" warning when I restart Firefox. Despite doing nothing.

Comment 1

[David Teller [:Yoric] - still alive but not very active]

Only when you restart Firefox?

Comment 2

[Hubert Figuiere [:hub]]

I click "Ignore for now". If I don't and just close the placard, it reappear. So at least we know something is working.

Comment 3

[Hubert Figuiere [:hub]]

BTW the source code of the addons:
https://github.com/hfiguiere/no-flash/
https://github.com/hfiguiere/tweet-that

In case you want to have a look.

Comment 4

[David Teller [:Yoric] - still alive but not very active]

I suspect that something in Jetpack and/or the Add-on Manager fetches data from these add-ons, which causes the add-ons to be activated accidentally. Bug 1191327 should tell us a little more about the direction in which to look at it.

In the meantime, can you look at your about:telemetry > keyed histograms > MISBEHAVING_ADDONS_* and copy & paste the two histograms for jid1-pF9SZq2GsG9cRA (that's tweet-that) and the two histograms for jid1-cplLTTY501TB2Q@jetpack (that's no flash)?

Comment 5

[Hubert Figuiere [:hub]]

_JANK_LEVEL

jid1-cplLTTY501TB2Q@jetpack
185 samples, average = 9, sum = 1665

 8 |  0  0%
 9 |#########################  185  11%
10 |  0  0%

jid1-pF9SZq2GsG9cRA@jetpack
389 samples, average = 7, sum = 2723

6 |  0  0%
7 |#########################  389  14%
8 |  0  0%

Comment 6

[David Teller [:Yoric] - still alive but not very active]

What about MISBEHAVING_ADDONS_CPOW_DURATION?

Comment 7

[Hubert Figuiere [:hub]]

They are not in there.

Comment 8

[David Teller [:Yoric] - still alive but not very active]

Good to know. So this won't be fixed by bug 1188248 or bug 1188616.

Comment 9

[David Teller [:Yoric] - still alive but not very active]

Bug 1181175 should improve accuracy of measurements, which might help here, but that's not the real solution.

Also, I can confirm that "No Flash" triggers alerts even when Firefox is idle.

Comment 11

[David Teller [:Yoric] - still alive but not very active]

So, "No Flash" is apparently activated every few seconds with an idle Firefox.

That's the stack I get:
	Add-on activity
JSAtom* (0x11ce58f10) = JSString* (0x11ce58f10) = Latin1Char * (0x11cbe1460) = "jid1-cplLTTY501TB2Q@jetpack"

0 EventTargetParent.dispatch/<() ["resource://gre/modules/RemoteAddonsParent.jsm":562]
    this = [object Object]
    this.init = [function]
    this.redirectEventTarget = [function]
    this.getTargets = [function]
    this.addEventListener = [function]
    this.removeEventListener = [function]
    this.receiveMessage = [function]
    this.dispatch = [function]
    this._listeners = [object WeakMap]
1 Prefetcher.withPrefetching(prefetched = , cpows = [object Object], func = () => {
            if ("handleEvent" in handler) {
              handler.handleEvent(proxyEvent);
            } else {
              handler.call(eventTarget, proxyEvent);
            }
          }) ["resource://gre/modules/Prefetcher.jsm":460]
    this = [object Object]
    this.init = [function]
    this.observe = [function]
    this.prefetch = [function]
    this.cache = [object Map]
    this.generateCache = [function]
    this.withPrefetching = [function]
    this.lookupInCache = [function]
    this.ruleMap = [object Map]
    this.prefetchingEnabled = true
2 EventTargetParent.dispatch(browser = [object XULElement], type = "deactivate", capturing = false, isTrusted = true, prefetched = , cpows = [object Object]) ["resource://gre/modules/RemoteAddonsParent.jsm":560]
    this = [object Object]
    this.init = [function]
    this.redirectEventTarget = [function]
    this.getTargets = [function]
    this.addEventListener = [function]
    this.removeEventListener = [function]
    this.receiveMessage = [function]
    this.dispatch = [function]
    this._listeners = [object WeakMap]
3 EventTargetParent.receiveMessage(msg = [object Object]) ["resource://gre/modules/RemoteAddonsParent.jsm":508]
    this = [object Object]
    this.init = [function]
    this.redirectEventTarget = [function]
    this.getTargets = [function]
    this.addEventListener = [function]
    this.removeEventListener = [function]
    this.receiveMessage = [function]
    this.dispatch = [function]
    this._listeners = [object WeakMap]

Comment 12

[David Teller [:Yoric] - still alive but not very active]

I can reproduce with other jetpack add-ons, e.g. https://github.com/julienw/forms-extension.

Comment 13

[David Teller [:Yoric] - still alive but not very active]

More precisely, this stack seems to show up as soon as we focus Firefox.

Comment 14

[David Teller [:Yoric] - still alive but not very active]

Bill, any idea what can cause this?

Comment 15

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Jetpack must be registering an event handler for "deactivate" events. Since Jetpack add-ons unfortunately still use shims, the event is being synchronously passed up from the content process to the chrome process and handled there.

It looks like this is happening here:
http://mxr.mozilla.org/mozilla-central/source/addon-sdk/source/lib/sdk/windows/observer.js#37

We should fix this in Jetpack. I'm not sure who can work on it though.

Comment 16

[David Teller [:Yoric] - still alive but not very active]

Irakli, could you fix it or find someone who can? This is a blocker for the slow add-on watcher, which is apparently part of e10s.

Comment 17

[David Teller [:Yoric] - still alive but not very active]

Pinging jsantell, too.

Comment 18

[Dave Townsend [:mossop]]

The problem is that the SDK add-ons are shimmed by default even though many of the modules are e10s safe now. And there isn't any way to do what the sdk/windows/observer module does without accidentally invoking the shims (bug 1167802).

Comment 19

[David Teller [:Yoric] - still alive but not very active]

Keep in mind that this was tested with add-ons that do not use any of the features provided by the observer. I hope that we can do something at least for these add-ons.

Comment 20

[Dave Townsend [:mossop]]

(In reply to David Rajchenbach-Teller [:Yoric] (use "needinfo") from comment #19)
> Keep in mind that this was tested with add-ons that do not use any of the
> features provided by the observer. I hope that we can do something at least
> for these add-ons.

I was going off Bill's comment, note that the observer is used by many other modules, tabs and windows particularly. There are other examples like this in the SDK though. Ideally we'd have someone working on finishing making everything e10s compatible so we can turn off shims entirely for SDK add-ons...

Comment 21

[David Teller [:Yoric] - still alive but not very active]

Fair enough.

My problem is the following. It looks like the Slow Add-on Watcher is meant to be delivered as part of e10s (pending Product Management confirmation). That's pretty soon. Unfortunately, there is no way we can deliver that watcher as long as Jetpack itself causes every add-on to trigger it (which seems to be the case here, unless I have misdiagnosed the issue). So I would really, really appreciate if someone who actually knows Jetpack's code could take a stab at this.

Comment 22

[Jordan Santell [:jsantell] [@jsantell]]

Am familiar with the SDK code, but there's quite a few bugs for this out there and have been out of the loop -- is there a consensus on how to proceed? What about the solution in bug 1167802?

Comment 24

[David Teller [:Yoric] - still alive but not very active]

(ni for comment 22)

Comment 25

[Dave Townsend [:mossop]]

(In reply to Jordan Santell [:jsantell] [@jsantell] from comment #22)
> Am familiar with the SDK code, but there's quite a few bugs for this out
> there and have been out of the loop -- is there a consensus on how to
> proceed? What about the solution in bug 1167802?

The discussions in that bug are about all I remember, I'd chat with billm and see if he has better thoughts since then.

Comment 26

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

For things where we definitely don't want events from the child, I think we want to do something like https://bugzilla.mozilla.org/show_bug.cgi?id=1167802#c6.

Comment 27

[David Teller [:Yoric] - still alive but not very active]

Looking at this, I realize that there are at least two reasons for the AddonWatcher issue.
The first reason is the one highlighted in comment 11, comment 15. The other one is actually bug 1189799.

Comment 28

[David Teller [:Yoric] - still alive but not very active]

Normally, this has been fixed by bug 1200138.

Closing. Don't hesitate to reopen if the issue pops up again.

Comment 29

[David Teller [:Yoric] - still alive but not very active]

Normally, this has been fixed by bug 1200138.

Closing. Don't hesitate to reopen if the issue pops up again.