488587 - Function registered as FUEL preference listener not always called

Status: RESOLVED WONTFIX

(Core :: Preferences: Backend, defect, P2)

Description

[custom.firefox.lady [:tawn]]

User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.1b3) Gecko/20090305 Firefox/3.1b3
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.1b3) Gecko/20090305 Firefox/3.1b3

FUEL-type pref listener -- for example, set via Application.prefs.get("extensions.{myExtID}.myExtPref")
    .events.addListener("change", myFunctionToCallOnPrefChange) -- stops being called after a varying number of pref changes. 

Reproducible: Always

Steps to Reproduce:
These exact steps are for on Windows, other OS should be similar.
1.Download attached testcase file. Rename it to .xpi and install it as extension, restarting fx as requested to finish installation.
2.Click Tools > Error console. (for easy viewing, drag it so it will stay visible)
3.Click Tools > Add-ons
4.Click to open the 'Options' for the 'FUEL Test' add-on.
5.Toggle the option off.
6.Click 'OK'.
7.Repeat from step 5. 
Actual Results:  
After a varying number of pref (option) changes, listener stops being called. (Each appearance of the message 'Pref changed' in the Error Console means the listener has been called. You will know bug has been triggered when further 'Pref changed' messages stop appearing.) Sometimes the listener does not even get called the first time.

Expected Results:  
As you repeat steps 5-7, every time you perform step 6, the message 'Pref changed' should appear in the Error Console indicating the registered listener was called.

This bug does *not* occur on fx 3.0.x.

Also tested on Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.2a1pre) Gecko/20090415 Minefield/3.6a1pre. The issue still occurs there.

It also reproduces on Linux according to report at: 
http://forums.mozillazine.org/viewtopic.php?f=19&t=1197245

Once the bug is triggered, additional changes to the pref will also fail to call listener.

If you have difficulty reproducing this, restart fx and try again. Sometimes it occurs much more quickly than others. (0-6 cycles of steps 5-7 were typical for me; Linux tester reported 0-100)

Result of bug being triggered is that user now needs to restart fx before extension's pref change appears to take effect. Because it works /sometimes/ it is less likely to be noticed by extension's author.

Comment 1

[custom.firefox.lady [:tawn]]

Attachment: Testcase for FUEL listener bug

Rename as FUELtestExtension.xpi to install as an extension for testing.

Comment 2

[custom.firefox.lady [:tawn]]

I believe the cause of this really needs to be found. Because of its erratic nature, I think it is possible it may be causing other issues elsewhere.

Comment 3

[custom.firefox.lady [:tawn]]

Works: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.1b3pre) Gecko/20090127 Shiretoko/3.1b3pre

Broken: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.1b3pre) Gecko/20090128 Shiretoko/3.1b3pre

Comment 4

[Chris Pinard]

I'm experiencing this same issue. I'm not using FUEL, but I am using the preferences-service/ nsIPrefBranch2/ addObserver mechanisms which underlie FUEL's preference listener, which I suspect is therefore where the root of the problem lies.

More details, including steps for duplicating the problem, can be found at http://forums.mozillazine.org/viewtopic.php?f=19&t=1329365 . In addition to my experience and this bug's, two other users of my extension bumped the maxVersion on theirs and got the same results.

Comment 5

[Shawn Wilsher :sdwilsh]

Given comment 4, this looks like it's a preference service bug.  Can anyone get reliable steps to reproduce here?  It'll make it a lot easier to actually identify what the problem is.

Comment 6

[Dave Townsend [:mossop]]

The most common error that causes this kind of behaviour with the pref service is not maintaining a reference to the prefbranch that you add an observer too. When that is no longer referenced it eventually gets garbage collected and will no longer notify.

Comment 7

[Shawn Wilsher :sdwilsh]

Is FUEL doing this?

Comment 8

[Dave Townsend [:mossop]]

(In reply to comment #7)
> Is FUEL doing this?

At first glance it doesn't look like it, but I can't figure out immediately whether Application is a singleton or not. I more suspect the comment in comment 4 was doing that so this wouldn't necessarily be a preferences backend problem.

Comment 9

[Mark Finkle (:mfinkle) (use needinfo?)]

Application is a singleton. The PreferenceBranc class is holding the nsIPrefBranch during it's lifetime too.

Comment 10

[custom.firefox.lady [:tawn]]

Appears to be related to something that happens in the background shortly after Firefox 3.5 is started. At some point (less than 1 minute on my system) this observer stops notifying. (instantApply on Linux explains why Linux user could get through more pref change repetitions in same period of time.)

Updated Steps to Reproduce:

1.Download attached testcase file. Rename it to .xpi and install it as
extension, restarting fx as requested to finish installation.
2.Click Tools > Error console. (for easy viewing, drag it so it will stay
visible)
3. Wait several minutes.
4.Click Tools > Add-ons
5.Click to open the 'Options' for the 'FUEL Test' add-on.
6.Toggle the option.
7.Click 'OK'. (this step unnecessary if browser.preferences.instantApply is set to true)

Actual Results:
Registered listener does not get called so message does not appear.

Expected Results:  
After step 7, the message 'Pref changed' should appear in the Error Console indicating the registered listener was called.


Unlike comment #4, if I change my code to use nsIPrefBranch2 / addObserver instead of the FUEL-based listener, I do not encounter this issue (tested > 3hr).

Comment 11

[Shawn Wilsher :sdwilsh]

This is bad for add-ons who depend on this API.  Requesting blocking.

Comment 12

[Rob Campbell [:rc] (:robcee)]

I was able to reproduce this with the attached XPI. Loaded it, checked that toggling the checkbox dumped some messages to the Error console then left the browser for a couple of hours. On return the checkbox no longer produced the messages.

Based on these comments and the ones in the linked mozillaZine thread, I'm inclined to believe it's a flaw in the prefs service. I've got some spare cycles this week so I can take a look.

Comment 13

[Mike Beltzner [:beltzner, not reading bugmail]]

Any chance that this is at all related to bug 524995?

Comment 14

[Shawn Wilsher :sdwilsh]

(In reply to comment #13)
> Any chance that this is at all related to bug 524995?
No - this was filed originally against the 1.9.1 branch, and bug 487059, which bug 524995 is reverting, never landed on 1.9.1

Comment 15

[Rob Campbell [:rc] (:robcee)]

I'm not sure how much time I'm going to have to work on this after all. I got side-tracked by some Firebug triage and am still digging out from it. I'll see if I can get anywhere with this this afternoon, but if someone else has a good idea of where this lives, feel free to have a go at it.

Comment 16

[Mike Shaver (:shaver -- probably not reading bugmail closely)]

Not a regression, and there are workarounds (like use the pref service directly) that are suitable.  Unblocking, we can get it in 3.7.

Comment 17

[Shawn Wilsher :sdwilsh]

(In reply to comment #16)
> Not a regression, and there are workarounds (like use the pref service
> directly) that are suitable.  Unblocking, we can get it in 3.7.
Hopefully we'll actually fix it then instead of letting it sit until the last minute and then minus it because it's not a regression.  FUEL is supposed to be the preferred way for folks to do stuff and it's not supposed to break (not that the pref service is an unfrozen API...).  We should be making sure it works right always if we actually want people to use it.

Comment 18

[Mike Shaver (:shaver -- probably not reading bugmail closely)]

Well, I would personally not have made it a blocker at all -- it's not clear to me how we would say "we cannot ship 3.6 without this fixed", given what's in the bug.  The issues are, as with all of these:

- would we ship without the change; and
- is it the most valuable thing for a given person (robcee, yourself, mfinkle, etc.) to be working on right now?

Not everything makes the cut, because my magic wand is out of charges.  Similarly for 1.9.3 -- I don't think we can say with a straight face that this is a stop-ship issue, though we would certainly take a patch for it.

Comment 19

[custom.firefox.lady [:tawn]]

(In reply to comment #16)

Sorry if I misunderstood the definition of 'regression'. This was my first bug report at bugzilla.

The issue IMO is not the ease/difficulty of the workaround (I've long since updated my addon), but that if an author inserts the FUEL code, restarts fx to apply the newly inserted code, and immediately changes the pref to test, it works. (Author thinks everything's fine; add-on user doesn't change the pref within (in my case) 1 minute of starting fx, bam, it doesn't work.) If this will not be fixed soon, could we please have a link to this bug added to the FUEL documentation at:
 https://developer.mozilla.org/en/Toolkit_API/extIPreferenceBranch ?

Comment 20

[Mike Shaver (:shaver -- probably not reading bugmail closely)]

Linking to this bug from there is a great idea -- please go ahead and edit such a reference in.  Thanks!

Comment 21

[Michael Kraft [:morac]]

I actually put some logging lines in fuelApplication.js and it appears that the PreferenceBranch.observe simply stops being called on the "nsPref:changed" topic notification.  The notification goes out to other components and add-ons, but not FUEL.

I originally thought this happened because I was accidentally registering the pref events prior to the profile-after-change, but the test case here registers on the first window load. 

What's interesting though is that if I dump out the "nsPref:changed" notifications in PreferenceBranch.observe, they will continue to occur as long as nothing adds an preference event listener.  Once a preference event listener is added, the notification will cease shortly after the listener callback function is called.

Comment 22

[Serge Gautherie (:sgautherie)]

As a (wild) guess, let's see if this is related++ to bug 533355 (or bug 533290)...

Comment 23

[Serge Gautherie (:sgautherie)]

Did bug 533355 check-in fix this bug?

Comment 24

[custom.firefox.lady [:tawn]]

Still broken in:
Mozilla/5.0 (Windows; U; Windows NT 6.1; en-US; rv:1.9.3a1pre) Gecko/20091216 Minefield/3.7a1pre ID:20091216045436

Comment 25

[custom.firefox.lady [:tawn]]

Attachment: New Testcase with compatibility update

Old testcase applies to builds before new Add-ons Manager landing; this new testcase to later builds.

Comment 26

[custom.firefox.lady [:tawn]]

The original testcase is no longer compatible since the landing of the new Add-ons Manager. I created a new testcase updated to be compatible, but the bug no longer reproduces. 
Could the change to FUEL mentioned at 
http://www.oxymoronical.com/blog/2010/03/How-were-breaking-some-extensions-in-the-near-future
have fixed this bug? (Builds with the old Add-ons Manager requiring old testcase show bug; builds with the new Add-ons Manager requiring new testcase do not.)

Comment 27

[Marco Bonardo [:mak] (Away Apr 25 - May 5)]

FUEL is being removed in bug 1090880, so this is now wontfix.

Comment 28

[custom.firefox.lady [:tawn]]

As I mentioned in comment 26 in 2010, the bug no longer reproduced, so technically it probably should have been resolved WORKSFORME, but whatever...

Comment 29

[Marco Bonardo [:mak] (Away Apr 25 - May 5)]

yeah sorry, at this point doesn't matter much :)