787557 - Thunderbird 15 inactive msg db close change prevents FolderLoaded events when folders are updated

Status: RESOLVED FIXED

(MailNews Core :: Database, defect)

Description

[Jonathan Kamens]

A change was introduced in Thunderbird 15 (see bug 723248) to close inactive message databases. This change causes what I'm fairly certain is an unanticipated and unintended change in behavior which breaks some code, including my Send Later 3 addon (which has 25,000 users).

In a nutshell, if you call updateFolder on a local folder (e.g., under Local Folders or a local folder associated with a POP3 mailbox), and the database for this folder has been closed by the new code for closing inactive folders, then a FolderLoaded event is not generated when the database is reloaded.

Since the timeout for closing inactive folders is only 3 seconds (David Bienvenu said he thought it was something like 5 minutes, but as far as I can tell from reading the code, the timeout is set to 3000 milliseconds), it's pretty much guaranteed that folders will be closed all the time, and many FolderLoaded events expected by various code will not happen.

Not only is this behavior different from releases prior to TB15, it is also different between different mailbox types. IMAP folders generate FolderLoaded events every time; it's just POP3 folders that don't. This inconsistency seems wrong.

The simplest fix, which I think is probably also the correct fix, is to generate a FolderLoaded event whenever a closed message database is opened, not just when an open message database is updated. The code that would need to change for this fix is nsMsgLocalMailFolder::UpdateFolder in mailnews/local/src/nsLocalMailFolder.cpp.

I am requesting tracking for TB 16, 17 and 18 because this is a regression. Should I also be requesitng tracking for Seamonkey?

Comment 1

[[e-mail]]

(In reply to Jonathan Kamens)
> I am requesting tracking for TB 16, 17 and 18 because this is a regression.
> Should I also be requesitng tracking for Seamonkey?

Only if by some miracle you get tracking-thunderbird15; otherwise because this is core code then we should pick it up automatically.

Comment 2

[Kent James (:rkent)]

Attachment: unit test to demonstrate the issue

The db cache manager just nulls the database in the folder. I can show the problem by just doing that in a unit test.

The actual db cache manager checks every minute to see if it needs to remove dbs - but then removes dbs older than 3 seconds. There are some unit problems there.

Comment 3

[Kent James (:rkent)]

Attachment: Add the event

This issue has been around since the dawn of time AFAICT, which makes me very nervous to fix it. The db cache manager only made it more apparent. But core code and extensions null the database for different reasons, so there should have been earlier manifestations of it.

Comment 4

[[e-mail]]

Is there any way of demonstrating the effect of this change in the default UI?

Comment 5

[Kent James (:rkent)]

> Is there any way of demonstrating the effect of this change in the default
> UI?

I don't know - but I suspect there are effects. There are other listeners available though (such as the db listeners), and I suspect that the view gets its changes from those. I'm really surprised that there are not more issues, as this seems to be a really fundamental missing notification.

It's actually been only recently that I have figured out (I think) that a FolderLoaded event is supposed to be the event that is given when a valid database is available after nsIMsgFolder.updateFolder(). If you accept that definition, then the unit test is sufficient to prove the correctness.

Comment 6

[Jonathan Kamens]

(In reply to Kent James (:rkent) from comment #5)
> It's actually been only recently that I have figured out (I think) that a
> FolderLoaded event is supposed to be the event that is given when a valid
> database is available after nsIMsgFolder.updateFolder().

Indeed, this is exactly how my add-on uses FolderLoaded -- it calls updateFolder and has a listener waiting for the subsequent FolderLoaded event that is generated.

Comment 7

[[e-mail]]

Comment on attachment 663617 [details] [diff] [review]
Add the event

Sorry for taking so long to get back to this.

I wonder whether putting this in GetDatabaseWithReparse is the right fix for this; all the other callers of NotifyFolderEvent(mFolderLoadedAtom) in all of the message folder subclasses seem to call this in UpdateFolder itself (for when the folder didn't actually need to be updated).

So perhaps the block where UpdateFolder calls GetDatabaseWithReparse should check for a successful database open and notify if that is the case?

Comment 8

[Kent James (:rkent)]

Just a quick update on this.

I updated this to incorporate Neil's comments, but I am still fighting a leak in the unit test because a DB is left in the cache. I suspect that the leak is unrelated to the fixes that I did, but is a sign of a deeper issue that I am investigating. I hate to hold this bug hostage to that issue, but DB issues are really important so the underlying problem could be important. Plus I hate to land a leaky unit test.

Comment 9

[Kent James (:rkent)]

I removed my core patches, and modified the unit test so that it still nulls the msgdatabase, but does not fail. That test also generates a leak, reported as:

TEST-INFO | (xpcshell/head.js) | 0 check(s) todo
js> quit()

WARNING: nsExceptionService ignoring thread destruction after shutdown: file c:/tb/2-central/src/mozilla/xpcom/base/nsEx
ceptionService.cpp, line 166
JS Component Loader: ERROR c:\tb\2-central\src\mozilla\testing\xpcshell\head.js:112
                     TypeError: _pendingTimers is undefined
WARNING: Leaking the RDF Service.: file c:/tb/2-central/src/mozilla/rdf/build/nsRDFModule.cpp, line 165
WARNING: some msg dbs left open: '!m_dbCache->Length()', file c:/tb/2-central/src/mailnews/db/msgdb/src/nsMsgDatabase.cp
p, line 913
db left open c:\users\kent\appdata\local\temp\thunderbird\xpcshellprofile\mailtest\Mail\Local Folders\Inbox.msf
nsStringStats
 => mAllocCount:           4420
 => mReallocCount:          711
 => mFreeCount:            4412  --  LEAKED 8 !!!
 => mShareCount:          10173
 => mAdoptCount:            299
 => mAdoptFreeCount:        298  --  LEAKED 1 !!!

So I don't think that the leak I am seeing is a result of my patch, but is a real leak in the core code. I'm doing this with the inbox, which is a special folder that does not normally have its msgdatabase nulled. So I will modify the unit test to use a different folder, and see if that makes a difference.

Comment 10

[Kent James (:rkent)]

Attachment: Incorporate review, test using subfolder with no POP3

Here is the patch incorporating review comments. I'm simplified the test, using a file copy instead of POP3pump, and using a non-inbox folder. The test still fails without the core fix, and succeeds with it - but it still leaves a db open at the end and therefore leaks.

I've tried various combinations of the code, and convinced myself that the leak is unrelated to the change I am doing. So at this point I am proposing that we not hold the folderLoaded fix hostage to the leak, and land this with a spinoff bug to fix the leak.

Finding and fixing the leak is probably 10 hours of work of work for me with ref counter, and that is assuming that the leak is occurring in C++ code. If the leak is js related, then it could be even harder to find.

Comment 11

[Kent James (:rkent)]

Comment on attachment 671479 [details] [diff] [review]
Incorporate review, test using subfolder with no POP3

[Approval Request Comment]

User impact if declined: extension problems detecting folder upload
Testing completed (on m-c, etc.): landed 10/22/2012, needs a few days still
Risk to taking this patch (and alternatives if risky): small, but new event notification could cause unforeseen issues.
String or UUID changes made by this patch: none

Checked in http://hg.mozilla.org/comm-central/rev/fac26d58edde

Comment 12

[Lukas Blakk [:lsblakk] use ?needinfo]

Comment on attachment 671479 [details] [diff] [review]
Incorporate review, test using subfolder with no POP3

Seems like you want approval-comm-aurora here, not mozilla-aurora.

Comment 13

[Kent James (:rkent)]

Comment on attachment 671479 [details] [diff] [review]
Incorporate review, test using subfolder with no POP3

Oops, right this should have been approval-comm-beta

Comment 14

[Mark Banner (:standard8)]

https://hg.mozilla.org/releases/comm-aurora/rev/f4632d2022b9
https://hg.mozilla.org/releases/comm-beta/rev/226f79ce0697