721319 - PlacesUtils.removeLazyBookmarkObserver() doesn't always remove observers, causes browser window to leak

Status: VERIFIED FIXED

(Toolkit :: Places, defect)

Description

[Wladimir Palant]

Attachment: Restartless test extension

I noticed that my restartless extensions leak memory under certain conditions. After reducing the problem it seems to be a platform issue. Steps to reproduce:

1. Install the attached test extension. The relevant code is in main.js, its bootstrap.js file is only boilerplate.
2. Open a new browser window. The extension will attach a dummy event handler to the document of this window.
3. Close the new window again.
4. Disable or remove the test extension.
5. Go to about:memory?verbose and click "Minimize memory usage".

Expected results:

A search for testtest on about:memory doesn't turn up anything - the event handler registered in the browser window was released when this window was closed. Consequently, the extension's compartment could be released properly.

Actual results:

A compartment for bootstrap.js of the test extension is still listed. Something is still holding its event handler even though the browser window where that event handler was registered is already closed.

For some reason, the test extension's compartment gets released after opening and closing another browser window - this doesn't happen with the real-world extensions however. Also, attaching an event listener on the window doesn't cause the issue - it has to be on the document or one of the XUL nodes. Obvious work-around: remove event listeners when the window unloads (ugly).

Comment 1

[Wladimir Palant]

Forgot to mention: tested in Mozilla/5.0 (Windows NT 6.1; WOW64; rv:12.0a1) Gecko/20120125 Firefox/12.0a1

Comment 2

[Olli Pettay [:smaug][[e-mail]]]

Is this a regression?

Comment 3

[Wladimir Palant]

At least not a recent one - I tested in Firefox 9.0.1 and it is affected in exactly the same way.

Comment 4

[Olli Pettay [:smaug][[e-mail]]]

So, a reason why adding listeners to the window object doesn't leak is that we clear
the event listener manager of window explicitly when the window is closed.
But I don't still understand why something would leak when adding listener to DOM nodes.
Are we missing some cycle collection edge?
Though, I'm not at all familiar with restartless addons. In which context is the main.js 
executed.

Comment 5

[Phoenix]

I'm curious, could it be the root reason for Bug 713216 and Bug 710170?

Comment 6

[Wladimir Palant]

(In reply to Olli Pettay [:smaug] from comment #4)
> Though, I'm not at all familiar with restartless addons. In which context is
> the main.js executed.

It is loaded into the context of bootstrap.js via subscript loader. And bootstrap.js is running inside a sandbox created by the add-on manager (which is why it is being displayed as a separate compartment). From what I recall the add-on manager creates these sandboxes when the extension is initialized and releases them when it is shut down (disabled or uninstalled). So normally this compartment can be garbage collected once the extension is disabled - unless some external references to it remain.

Comment 7

[Olli Pettay [:smaug][[e-mail]]]

Btw, I assume similar problem could happen with userData/userDataHandlers

Comment 8

[Olli Pettay [:smaug][[e-mail]]]

Actually, I can't reproduce this. After open/close and disabling the addon
few calls to minimize mem usage and/or cc/gc removes the compartment.

Comment 9

[Wladimir Palant]

I just tried again - strangely, the issue is indeed not reproducible on the first run with a new profile. However, when I started the browser again with the same profile (extension present but disabled) I got the same zombie compartment again and it doesn't get removed no matter how often I click the buttons.

Comment 10

[Olli Pettay [:smaug][[e-mail]]]

What? You get a zombie compartment just when starting with a disabled addon?
That sounds like a bug somewhere in addon handling.

Comment 11

[Olli Pettay [:smaug][[e-mail]]]

And can't reproduce zombie compartment after restart, even if I enable the addon and
open/close a window and disable addon.

Comment 12

[Wladimir Palant]

(In reply to Olli Pettay [:smaug] from comment #10)
> What? You get a zombie compartment just when starting with a disabled addon?

Sorry, not what I meant. I meant that the steps to reproduce work after a restart. There seems to be some strange dependency here: if I first go to the "get add-ons" tab of the add-ons manager (something that always happens on a new profile) then enabling the test extension, opening/closing a new window and disabling it again doesn't produce a zombie compartment. If I get to the "extensions" tab directly then the same steps produce a zombie compartment that won't go away. Trying to figure out what's so special about the "get add-ons" tab (opening it after the first zombie compartment is there won't do anything - repeating the steps still produces new zombie compartments).

Comment 13

[Wladimir Palant]

(In reply to Wladimir Palant from comment #12)
> Trying to figure out what's so special about
> the "get add-ons" tab (opening it after the first zombie compartment is
> there won't do anything - repeating the steps still produces new zombie
> compartments).

There was apparently some interference with the proxy script I was using - the new profile took it over from the system configuration. After configuring a direct connection the compartment is now always being released the first time I go through the steps, however if I repeat them without restarting the browser I get a zombie compartment.

Comment 14

[Andrew McCreight [:mccr8]]

This sounds vaguely similar to bug 691537, but the steps to reproduce don't sound like they are the same.

Comment 15

[Wladimir Palant]

(In reply to Andrew McCreight [:mccr8] from comment #14)
> This sounds vaguely similar to bug 691537, but the steps to reproduce don't
> sound like they are the same.

I don't think so - there is no indication that the add-on manager is doing something wrong here. It is quite definitely tied to event listeners.

Comment 16

[Olli Pettay [:smaug][[e-mail]]]

event listeners don't really have anything special. Other code uses the same mechanism
for cycle collection.

I wish I could reproduce this. So far no luck.

Comment 17

[Andrew McCreight [:mccr8]]

Could you give us a cycle collector log when the zombie compartment is present?  Maybe that will give us some insight into what is happening.  The directions are here: https://wiki.mozilla.org/Performance:Leak_Tools#Cycle_collector_heap_dump

Comment 18

[Wladimir Palant]

Attachment: Cycle collector log

I tried to make sure that this log is as small as possible, it was captured only with the browser window open and about:blank as the only tab. If I read it correctly, it still lists four ChromeWindow objects which should be two too many. After starting the browser I went through the enable extension / open browser window / close browser window / disable extension cycle twice, then went to about:memory and opened the Scratchpad window to enter the script that would create the log on a timer.

Comment 19

[Wladimir Palant]

Attachment: Script used to capture the log

Comment 20

[Justin Lebar (not reading bugmail)]

Kyle, can you triage this and put the right MemShrink priority on it?  We recall you saying something about it at last week's meeting.

Comment 21

[Kyle Huey (Exited; not receiving bugmail, old account, do not use)]

(In reply to Justin Lebar [:jlebar] from comment #20)
> Kyle, can you triage this and put the right MemShrink priority on it?  We
> recall you saying something about it at last week's meeting.

I can look into it, but it'll probably be at least a week.

Comment 22

[Wladimir Palant]

Attachment: Restartless test extension

Attached better test extension, all the functions have names now so that they are easier to find in the CC log.

Comment 23

[Wladimir Palant]

Attachment: Cycle collector log

Attached new cycle collector log, created with about:ccdump extension running in its own window (opened via openDialog("about:ccdump")).

The log clearly shows that function test_foobarListener (0xfde7f80) leaked. It's being held by a proxy object (0xfde1e70) which is in turn referenced by another proxy (0xfdf6a60) that is referenced by an nsIDOMEventListener wrapper (0x7f913c8) in another compartment. The strange thing: according to this log the entire browser.xul document leaked, about:memory wasn't showing this compartment however.

Comment 24

[Olli Pettay [:smaug][[e-mail]]]

There is only one compartment for chrome.

Comment 25

[Wladimir Palant]

Attachment: Reduced cycle collector log

I used a simple Python script to reduce the log to the direct or indirect owners of test_foobarListener function (0xfde7f80). Apparently, the root preventing everything from being garbage collected is an nsINavBookmarkObserver implementation.

Comment 26

[Wladimir Palant]

The nsINavBookmarkObserver in question is this one: http://hg.mozilla.org/mozilla-central/file/5e756e59a794/browser/base/content/browser-places.js#l968

Comment 27

[Wladimir Palant]

This seems to be a bug in PlacesUtils.jsm, particularly in PlacesUtils.removeLazyBookmarkObserver(). It uses the following check when removing an observer:

> if (this._bookmarksServiceObserversQueue.length == 0) {
>   this.bookmarks.removeObserver(aObserver, false);

Supposedly, the length of the queue should always be 0 once the bookmarks service is ready. I checked it in the browser leaking memory - the queue contains one element even though the bookmarks service is ready, that's why the observer isn't being removed and causes the browser window to leak. The observer in the queue is also a PlacesStarButton instance - the one from the first browser window I guess.

I guess this bug needs to be renamed and recategorized.

Comment 28

[Wladimir Palant]

I am using the default homepage (about:home), this might be important here. Also, if I force the bookmarks service to initialize (e.g. by opening the Bookmarks menu) I can reproduce the issue immediately rather than the second time I try it.

Comment 29

[Marco Bonardo [:mak]]

thanks for investigating the issue, will look into it.

Comment 30

[Wladimir Palant]

The logic in PlacesUtils is wrong. After looking into it, the "bookmarks-service-ready" notification is being sent out the first time a bookmark changes (via PlacesCategoryStarter.js component), not when the bookmarks service is instantiated. Which means that the bookmarks service can be instantiated (e.g. because the Bookmarks menu has been opened) but the "bookmarks-service-ready" notification hasn't been sent out yet (no bookmarks changed). In this situation addLazyBookmarkObserver() will add observers to the bookmarks service (because it goes by service instantiation) while removeLazyBookmarkObserver() will still attempt to remove them from the queue (because it sees an observer in the queue). The simplest solution is probably to drop checking whether the service has been instantiated - queue the observers until "bookmarks-service-ready" notification is received and only after that start adding observers to the bookmarks service.

Comment 31

[Marco Bonardo [:mak]]

Your analysis is pretty good, though it misses the reason it's checking the service instantiation, that is the fact the notification may have happened before PlacesUtils was listening. Though I can fix that and rely on your suggestion; this notification is a specific thing for PlacesUtils so I can just call its observe method and that ensures it is aware of the status.

Comment 32

[Marco Bonardo [:mak]]

Attachment: patch v1.0

This should do it, the test exactly hits this case.

Comment 33

[Dietrich Ayala (:dietrich)]

Comment on attachment 600153 [details] [diff] [review]
patch v1.0

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

change looks ok, thanks.

Comment 34

[Wladimir Palant]

Comment on attachment 600153 [details] [diff] [review]
patch v1.0

Looks good to me and removes some unnecessary overhead as well.

Comment 35

[Marco Bonardo [:mak]]

thanks!
https://hg.mozilla.org/integration/mozilla-inbound/rev/2e3e8d2339a8

Comment 36

[Marco Bonardo [:mak]]

https://hg.mozilla.org/mozilla-central/rev/2e3e8d2339a8

Comment 37

[Wladimir Palant]

The issue described in comment 0 is no longer present in Mozilla/5.0 (Windows NT 6.1; WOW64; rv:13.0) Gecko/20120227 Firefox/13.0a1.

Comment 38

[Ed Morley [:emorley]]

Thanks Wladimir :-)