There are still bugs (e.g. bug 1388696) claiming the folder database eviction in msgDBCacheManager::checkCachedDBs() may work incorrectly. I propose to improve the debug output from the DB cache manager and simplify the eviction logic.

This improves the logging output by summaring how many DBs are pinned in a window, how many are already partly close and how many are still open, how many we need to close. It simplifies the eviction logic e.g. by not running .queryElementAt() (with internal queryInterface), IsFolderOpenInWindow() and .databaseOpen on some DBs twice, but already grouping which DBs are the ones for potential closing (normal, unpinned, not already closed) the the first pass.

Comment on attachment 8904350 [details] [diff] [review] 1396655.patch Review of attachment 8904350 [details] [diff] [review]: ----------------------------------------------------------------- ::: mailnews/base/util/msgDBCacheManager.js @@ +157,5 @@ > // more than maxOpenDBs folders to stay open after this loop. > + let dbsToClose = dbs.length - Math.max(maxOpenDBs - pinnedDBs, 0); > + log.info("Need to close " + dbsToClose + " DBs"); > + // Order databases by lowest lastUsedTime (oldest) at the end. > + dbs.sort((a, b) => b.lastUseTime - a.lastUseTime); This shouldn't change behaviour compared to the original sort, but in this new algorithm we pop from the end of the array so the array must be sorted with lowest values last. The original was intended to have lowest values first. However, the original sort was: dbs.sort((a, b) => a.lastUseTime > b.lastUseTime); This may have worked in some way, however the compareFunction in the sort returning boolean (a>b) looks certainly bogus and is against the spec: https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Array/sort The compareFunction should return and integer. So this part could fix a bug.

Thanks for looking at this. I've been wanting to get back to these issues. What is a "partly closed" database? What is "pinned"? And (so I can target user feedback) what type of scenarios will this algorithm change help - both cases where too few databases are getting closed (and we see memory bloat), and cases where databases are being closed too aggressively? I think we have users reporting both.

"Partly closed" mean that we cut the connection to the database (db.folder.msgDatabase = null) but the DB is still hanging in the cache for some reason (we don't know why it happens). The algorithm skips those as if they are already closed. I called "pinned" those DBs of folders that are open in some window. I can reword that if needed. The algorithm change shouldn't help any scenarios, it mostly improves the debugging output and simplifies the loops. Unless the the sorting algorithm before the fix ordered the DBs incorrectly and e.g. closed the most recently used DBs first (instead of the least recent ones). That could fix something. The sorting appeared to work correctly (that is why it was there) right now, but it could be luck. I think the syntax was illegal so the sort order could vary or end up undefined. So this resembles the second case you mention "and cases where databases are being closed too aggressively". I don't think the algorithm closes "too few databases" in any case. It closes the right amount, they just may hang in the cache for some time due to the "partly closed" state as described above.

Comment on attachment 8904350 [details] [diff] [review] 1396655.patch Review of attachment 8904350 [details] [diff] [review]: ----------------------------------------------------------------- I think this is an excellent clean-up effort. The original code got the DBs twice (gDbService.openDBs) and checked IsFolderOpenInWindow(db.folder) twice, inefficiency ahoy! Since this is (semi-)complicated stuff, I think you need to add more comments and improve the variable names. Looking forward to v2 :-) And sorry about the delay in review, I'm still beating my co-reviewer to it ;-) ::: mailnews/base/util/msgDBCacheManager.js @@ +121,5 @@ > let closeThreshold = (Date.now() - idleLimit) * 1000; > + let cachedDBs = this._dbService.openDBs; > + log.info("Periodic check of cached folder databases (DBs), count=" + cachedDBs.length); > + let uncachedDBs = 0; > + let pinnedDBs = 0; I'm not so happy with those variable names. Also, we need a comment to explain them here, so the reader can check the definition against the code. pinnedDB is one "pinned to a window". Also, 'DBs' suggests an array of them. Why not: // Count databases connected to a folder which is open in a window. numOpenInWindow = 0; What about uncachedDBs? Here you count the ones which have !db.folder.databaseOpen and the ones where you close due to no window and timeout and set: db.folder.msgDatabase = null; Looking at nsMsgDBFolder.cpp they will be the ones with !db.folder.databaseOpen, so it's OK to count them in the same variable. How about: numXXX, hmm, I can't think of a good name right now. Aren't they a little bit like zombies? The database still has a folder, but the folder claims that it has no database? @@ +157,5 @@ > // more than maxOpenDBs folders to stay open after this loop. > + let dbsToClose = dbs.length - Math.max(maxOpenDBs - pinnedDBs, 0); > + log.info("Need to close " + dbsToClose + " DBs"); > + // Order databases by lowest lastUsedTime (oldest) at the end. > + dbs.sort((a, b) => b.lastUseTime - a.lastUseTime); No need to sort if dbsToClose <= 0.

(In reply to Jorg K (GMT+2) from comment #5) > // Count databases connected to a folder which is open in a window. Better: // Count databases whose folder is open in a window.

(In reply to Jorg K (GMT+2) from comment #5) > ::: mailnews/base/util/msgDBCacheManager.js > @@ +121,5 @@ > > let closeThreshold = (Date.now() - idleLimit) * 1000; > > + let cachedDBs = this._dbService.openDBs; > > + log.info("Periodic check of cached folder databases (DBs), count=" + cachedDBs.length); > > + let uncachedDBs = 0; > > + let pinnedDBs = 0; > > I'm not so happy with those variable names. Also, we need a comment to OK, will do. > Aren't they a little bit like zombies? The database still has a folder, but > the folder claims that it has no database? Yes, they are zombies we can't explain yet. Setting the link to a DB to null should release the DB but it doesn't always. It may or may not be related the to assertion about leaving open databases at TB shutdown you are hunting elsewhere. We just know that opening some new TB window (or dialog) suddenly makes these zombies go away. So some link is cut at that moment (maybe like folderpane being defocused) allowing those to be destroyed.

Comment on attachment 8906268 [details] [diff] [review] 1396655.patch v1.1 Review of attachment 8906268 [details] [diff] [review]: ----------------------------------------------------------------- Nice. ::: mailnews/base/util/msgDBCacheManager.js @@ +160,2 @@ > // Close some DBs so that we do not have more than maxOpenDBs. > + // However, we skipped DBs for a folders that are open in a window Nit: grammar "a folders". @@ +163,5 @@ > // more than maxOpenDBs folders to stay open after this loop. > + log.info("Need to close " + dbsToClose + " more DBs"); > + // Order databases by lowest lastUseTime (oldest) at the end. > + dbs.sort((a, b) => b.lastUseTime - a.lastUseTime); > + for (;dbsToClose > 0; dbsToClose--) { Nit: I prefer the while you had before. Then we don't get into the discussion of whether it should be: for ( ; dbsToClose > 0; dbsToClose--) {

(In reply to Jorg K (GMT+2) from comment #9) > Nit: I prefer the while you had before. Then we don't get into the > discussion of whether it should be: > for ( ; dbsToClose > 0; dbsToClose--) { No problem, I just found for() takes one less line ;)

Comment on attachment 8906293 [details] [diff] [review] 1396655.patch v1.2 Thanks for addressing the nits.

Comment on attachment 8906293 [details] [diff] [review] 1396655.patch v1.2 Review of attachment 8906293 [details] [diff] [review]: ----------------------------------------------------------------- LGTM, and sorry for the slow review.

Pushed by mozilla@jorgk.com: https://hg.mozilla.org/comm-central/rev/2c194c1a63a9 Cleanup folder DB cache eviction logic and the debugging output. r=jorgk,rkent

Ever since this landed, I get shutdown crashes where the last thing I see on the console is this: [7708, Main Thread] WARNING: some msg dbs left open: '!m_dbCache.Length()', file c:/mozilla-source/comm-central/mailnews/db/msgdb/src/nsMsgDatabase.cpp, line 84 db left open Note that "open" is followed by a space and the cursor hangs there. Have you seen that, too?

Sometimes I get that, but rarely. But I think we also got this before the patch. But is NS_WARNING_ASSERTION() supposed to crash the app? Doesn't look like that per the comment in it (bug dxr is old by 2 weeks now). The code following it intends to list the open databases. The stack trace is strange, as if it stops in a printf()-like function.

(In reply to Jorg K (GMT+2) from comment #15) > [7708, Main Thread] WARNING: some msg dbs left open: '!m_dbCache.Length()', > file c:/mozilla-source/comm-central/mailnews/db/msgdb/src/nsMsgDatabase.cpp, > line 84 > db left open Sorry, I didn't notice this last line. So it doesn't crash on the NS_WARNING_ASSERSION but our printf code: printf("db left open %s\n", (const char *) pMessageDB->m_dbName.get()); I can look at that, maybe the name is nullptr at that time.

Jorg, do you still observe this crash in any way?

No, not these days since these days it crashes on bug 1437323 :-(

Comment on attachment 8906293 [details] [diff] [review] 1396655.patch v1.2 [Approval Request Comment] Risk to taking this patch (and alternatives if risky): probably none, riding on c-c since TB 58. Reason: To get better debugging from ESR users not jumping to 60 immediately. Reports like bug 1240722 still exist.

Comment on attachment 8906293 [details] [diff] [review] 1396655.patch v1.2 I think you mean ers52

TB 52.8 ESR: https://hg.mozilla.org/releases/comm-esr52/rev/950c1b4d04ab8e8f14860f9b6c06d9cbdbcbcb67