(In reply to Magnus Melin [:mkmelin] from comment #10) > Comment on attachment 9188190 [details] [diff] [review] > Try counting the database pointer left in the cache due to early XPCOM > shutdown and avoid accessing them later. > > Review of attachment 9188190 [details] [diff] [review]: > ----------------------------------------------------------------- > > Sorry but I don't think this is something we should do. It also adds far too > much debug type spew here. It could be a useful local-debugging patch > perhaps. I can take out the printf() by surrounding it in #ifdef. I think the patch in one form or the other would be necessary. REASON #1. This is necessary to run DEBUG version of ASAN build C-C TB successfully to completion during local mochitest. REASON #2. This solves or exposes why the dreaded "some db msgs left open" message at TB shutdown that puzzled developers for some time (at least four years). Please see Bug 1342858 WARNING: some msg dbs left open: '!m_dbCache.Length()' - for last folder that was open in the window and a message was viewed in it? REASON #3: It is not THAT verbose in contrast to the current situation and actually gives enough information to let developers off the hook by giving information in relation to REASON #2. Log BEFORE version ``` ... 44:34.94 GECKO(809035) [809035, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/dom/events/DOMEventTargetHelper.cpp:291 44:35.02 GECKO(809035) [809035, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/dom/events/DOMEventTargetHelper.cpp:291 *** 44:35.38 GECKO(809035) [809035, Main Thread] WARNING: some msg dbs left open: '!m_dbCache.Length()', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/db/msgdb/src/nsMsgDatabase.cpp:80 44:35.73 GECKO(809035) [809035, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsCycleCollector.cpp:3359 44:35.84 GECKO(809035) [809035, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/modules/libpref/Preferences.cpp:4287 ``` With the log line marked with "***", some developers got really confused why the "dbs left open" message and it does not print even the database name. The reason of not printing the name was trying to print the name crashed the build. But the patch here solves the crash issue and we can safely print the name now. We also know the reason why it was not removed from the cache. The issue of not closing the msg dbs will persist until the order of XPCOM subsystem shutdowns will be taken care of.) Log AFTER version ``` 247:05.42 GECKO(622036) [622036, Main Thread] WARNING: some msg dbs left open: '!m_dbCache.Length() || m_dbCache.Length() <= unremoved_db_from_cache_due_to_unavailable_XPCOM', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/db/msgdb/src/nsMsgDatabase.cpp:88 +++ 247:05.42 GECKO(622036) m_dbCache.Length() = 1, unremoved_db_from_cache_due_to_unavailable_XPCOM=0 +A+ 247:05.42 GECKO(622036) db left open pMessageDB=0x6140000e7a40, p->m_dbFile=0x610000571e40, /COMM-CENTRAL/TMP-DIR/tmpw1j8jkkn.mozrunner/Mail/Local Folders/Sample.msf +B+ 247:05.42 GECKO(622036) ~nsMsgDatabase(): closing database /COMM-CENTRAL/TMP-DIR/tmpw1j8jkkn.mozrunner/Mail/Local Folders/Sample.msf +C+ 247:05.42 GECKO(622036) Not calling RemoveFromCache(this), this = 0x6140000e7a40 247:06.31 GECKO(622036) [622036, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsCycleCollector.cpp:3359 ``` The messages are printed only at TB's shutdown time. They are not numerous. Also, the current patch is for exposing the issue clearly including why and the underlying cause of XPCOM shutdown issue. I can simplify the line marked with *A* by eliminating pointer values as follows. ``` 247:05.42 GECKO(622036) db left open /COMM-CENTRAL/TMP-DIR/tmpw1j8jkkn.mozrunner/Mail/Local Folders/Sample.msf ``` I can modify *C* by eliminating the pointer value as follows. ``` 247:05.42 GECKO(622036) Not calling RemoveFromCache(this) due unavailable XPCOM service. ``` That would make the log look like: ``` 247:05.42 GECKO(622036) [622036, Main Thread] WARNING: some msg dbs left open: '!m_dbCache.Length() || m_dbCache.Length() <= unremoved_db_from_cache_due_to_unavailable_XPCOM', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/db/msgdb/src/nsMsgDatabase.cpp:88 247:05.42 GECKO(622036) m_dbCache.Length() = 1, unremoved_db_from_cache_due_to_unavailable_XPCOM=0 247:05.42 GECKO(622036) db left open /COMM-CENTRAL/TMP-DIR/tmpw1j8jkkn.mozrunner/Mail/Local Folders/Sample.msf +B+ 247:05.42 GECKO(622036) ~nsMsgDatabase(): closing database /COMM-CENTRAL/TMP-DIR/tmpw1j8jkkn.mozrunner/Mail/Local Folders/Sample.msf 247:05.42 GECKO(622036) Not calling RemoveFromCache(this) due unavailable XPCOM service. 247:06.31 GECKO(622036) [622036, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsCycleCollector.cpp:3359 ``` I will the opinion of couple of developers in bug 1342858.
Bug 1677202 Comment 11 Edit History
Note: The actual edited comment in the bug view page will always show the original commenter’s name and original timestamp.
(In reply to Magnus Melin [:mkmelin] from comment #10) > Comment on attachment 9188190 [details] [diff] [review] > Try counting the database pointer left in the cache due to early XPCOM > shutdown and avoid accessing them later. > > Review of attachment 9188190 [details] [diff] [review]: > ----------------------------------------------------------------- > > Sorry but I don't think this is something we should do. It also adds far too > much debug type spew here. It could be a useful local-debugging patch > perhaps. I can take out the printf() by surrounding it in #ifdef. I think the patch in one form or the other would be necessary. REASON #1. This is necessary to run DEBUG version of ASAN build C-C TB successfully to completion during local mochitest. REASON #2. This solves or exposes why the dreaded "some db msgs left open" message at TB shutdown that puzzled developers for some time (at least four years). Please see Bug 1342858 WARNING: some msg dbs left open: '!m_dbCache.Length()' - for last folder that was open in the window and a message was viewed in it? REASON #3: It is not THAT verbose in contrast to the current situation and actually gives enough information to let developers off the hook by giving information in relation to REASON #2. Log BEFORE version ``` ... 44:34.94 GECKO(809035) [809035, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/dom/events/DOMEventTargetHelper.cpp:291 44:35.02 GECKO(809035) [809035, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/dom/events/DOMEventTargetHelper.cpp:291 *** 44:35.38 GECKO(809035) [809035, Main Thread] WARNING: some msg dbs left open: '!m_dbCache.Length()', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/db/msgdb/src/nsMsgDatabase.cpp:80 44:35.73 GECKO(809035) [809035, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsCycleCollector.cpp:3359 44:35.84 GECKO(809035) [809035, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/modules/libpref/Preferences.cpp:4287 ``` With the log line marked with "***", some developers got really confused why the "dbs left open" message and it does not print even the database name. The reason of not printing the name was trying to print the name crashed the build. But the patch here solves the crash issue and we can safely print the name now. We also know the reason why it was not removed from the cache. The issue of not closing the msg dbs will persist until the order of XPCOM subsystem shutdowns will be taken care of.) Log AFTER version ``` 247:05.42 GECKO(622036) [622036, Main Thread] WARNING: some msg dbs left open: '!m_dbCache.Length() || m_dbCache.Length() <= unremoved_db_from_cache_due_to_unavailable_XPCOM', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/db/msgdb/src/nsMsgDatabase.cpp:88 +++ 247:05.42 GECKO(622036) m_dbCache.Length() = 1, unremoved_db_from_cache_due_to_unavailable_XPCOM=0 +A+ 247:05.42 GECKO(622036) db left open pMessageDB=0x6140000e7a40, p->m_dbFile=0x610000571e40, /COMM-CENTRAL/TMP-DIR/tmpw1j8jkkn.mozrunner/Mail/Local Folders/Sample.msf +B+ 247:05.42 GECKO(622036) ~nsMsgDatabase(): closing database /COMM-CENTRAL/TMP-DIR/tmpw1j8jkkn.mozrunner/Mail/Local Folders/Sample.msf +C+ 247:05.42 GECKO(622036) Not calling RemoveFromCache(this), this = 0x6140000e7a40 247:06.31 GECKO(622036) [622036, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsCycleCollector.cpp:3359 ``` The messages are printed only at TB's shutdown time. They are not numerous. Also, the current patch is for exposing the issue clearly including why and the underlying cause of XPCOM shutdown issue. I can simplify the line marked with *A* by eliminating pointer values as follows. ``` 247:05.42 GECKO(622036) db left open /COMM-CENTRAL/TMP-DIR/tmpw1j8jkkn.mozrunner/Mail/Local Folders/Sample.msf ``` I can modify *C* by eliminating the pointer value as follows. ``` 247:05.42 GECKO(622036) Not calling RemoveFromCache(this) due unavailable XPCOM service. ``` That would make the log look like: ``` 247:05.42 GECKO(622036) [622036, Main Thread] WARNING: some msg dbs left open: '!m_dbCache.Length() || m_dbCache.Length() <= unremoved_db_from_cache_due_to_unavailable_XPCOM', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/db/msgdb/src/nsMsgDatabase.cpp:88 247:05.42 GECKO(622036) m_dbCache.Length() = 1, unremoved_db_from_cache_due_to_unavailable_XPCOM=0 247:05.42 GECKO(622036) db left open /COMM-CENTRAL/TMP-DIR/tmpw1j8jkkn.mozrunner/Mail/Local Folders/Sample.msf +B+ 247:05.42 GECKO(622036) ~nsMsgDatabase(): closing database /COMM-CENTRAL/TMP-DIR/tmpw1j8jkkn.mozrunner/Mail/Local Folders/Sample.msf 247:05.42 GECKO(622036) Not calling RemoveFromCache(this) due unavailable XPCOM service. 247:06.31 GECKO(622036) [622036, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsCycleCollector.cpp:3359 ``` I will court the opinion of couple of developers in bug 1342858.
(In reply to Magnus Melin [:mkmelin] from comment #10) > Comment on attachment 9188190 [details] [diff] [review] > Try counting the database pointer left in the cache due to early XPCOM > shutdown and avoid accessing them later. > > Review of attachment 9188190 [details] [diff] [review]: > ----------------------------------------------------------------- > > Sorry but I don't think this is something we should do. It also adds far too > much debug type spew here. It could be a useful local-debugging patch > perhaps. I can take out the printf() by surrounding it in #ifdef. I think the patch in one form or the other would be necessary. REASON #1. This is necessary to run DEBUG version of ASAN build C-C TB successfully to completion during local mochitest. REASON #2. This solves or exposes why the dreaded "some db msgs left open" message at TB shutdown that puzzled developers for some time (at least four years). Please see Bug 1342858 WARNING: some msg dbs left open: '!m_dbCache.Length()' - for last folder that was open in the window and a message was viewed in it? REASON #3: It is not THAT verbose in contrast to the current situation and actually gives enough information to let developers off the hook by giving information in relation to REASON #2. Log BEFORE version ``` ... 44:34.94 GECKO(809035) [809035, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/dom/events/DOMEventTargetHelper.cpp:291 44:35.02 GECKO(809035) [809035, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/dom/events/DOMEventTargetHelper.cpp:291 *** 44:35.38 GECKO(809035) [809035, Main Thread] WARNING: some msg dbs left open: '!m_dbCache.Length()', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/db/msgdb/src/nsMsgDatabase.cpp:80 44:35.73 GECKO(809035) [809035, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsCycleCollector.cpp:3359 44:35.84 GECKO(809035) [809035, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/modules/libpref/Preferences.cpp:4287 ``` With the log line marked with "***", some developers got really confused why the "dbs left open" message and it does not print even the database name if it is the official build even if DEBUG is set. The reason of not printing the name was trying to print the name crashed the build. But the patch here solves the crash issue and we can safely print the name now. We also know the reason why it was not removed from the cache. The issue of not closing the msg dbs will persist until the order of XPCOM subsystem shutdowns will be taken care of.) Log AFTER version ``` 247:05.42 GECKO(622036) [622036, Main Thread] WARNING: some msg dbs left open: '!m_dbCache.Length() || m_dbCache.Length() <= unremoved_db_from_cache_due_to_unavailable_XPCOM', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/db/msgdb/src/nsMsgDatabase.cpp:88 +++ 247:05.42 GECKO(622036) m_dbCache.Length() = 1, unremoved_db_from_cache_due_to_unavailable_XPCOM=0 +A+ 247:05.42 GECKO(622036) db left open pMessageDB=0x6140000e7a40, p->m_dbFile=0x610000571e40, /COMM-CENTRAL/TMP-DIR/tmpw1j8jkkn.mozrunner/Mail/Local Folders/Sample.msf +B+ 247:05.42 GECKO(622036) ~nsMsgDatabase(): closing database /COMM-CENTRAL/TMP-DIR/tmpw1j8jkkn.mozrunner/Mail/Local Folders/Sample.msf +C+ 247:05.42 GECKO(622036) Not calling RemoveFromCache(this), this = 0x6140000e7a40 247:06.31 GECKO(622036) [622036, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsCycleCollector.cpp:3359 ``` The messages are printed only at TB's shutdown time. They are not numerous. Also, the current patch is for exposing the issue clearly including why and the underlying cause of XPCOM shutdown issue. I can simplify the line marked with *A* by eliminating pointer values as follows. ``` 247:05.42 GECKO(622036) db left open /COMM-CENTRAL/TMP-DIR/tmpw1j8jkkn.mozrunner/Mail/Local Folders/Sample.msf ``` I can modify *C* by eliminating the pointer value as follows. ``` 247:05.42 GECKO(622036) Not calling RemoveFromCache(this) due unavailable XPCOM service. ``` That would make the log look like: ``` 247:05.42 GECKO(622036) [622036, Main Thread] WARNING: some msg dbs left open: '!m_dbCache.Length() || m_dbCache.Length() <= unremoved_db_from_cache_due_to_unavailable_XPCOM', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/comm/mailnews/db/msgdb/src/nsMsgDatabase.cpp:88 247:05.42 GECKO(622036) m_dbCache.Length() = 1, unremoved_db_from_cache_due_to_unavailable_XPCOM=0 247:05.42 GECKO(622036) db left open /COMM-CENTRAL/TMP-DIR/tmpw1j8jkkn.mozrunner/Mail/Local Folders/Sample.msf +B+ 247:05.42 GECKO(622036) ~nsMsgDatabase(): closing database /COMM-CENTRAL/TMP-DIR/tmpw1j8jkkn.mozrunner/Mail/Local Folders/Sample.msf 247:05.42 GECKO(622036) Not calling RemoveFromCache(this) due unavailable XPCOM service. 247:06.31 GECKO(622036) [622036, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /NEW-SSD/NREF-COMM-CENTRAL/mozilla/xpcom/base/nsCycleCollector.cpp:3359 ``` I will court the opinion of couple of developers in bug 1342858.