Closed Bug 1353919 Opened 7 years ago Closed 7 years ago

Polish log module names in Thunderbird

Categories

(MailNews Core :: Backend, enhancement)

Product:
MailNews Core
Component:
Backend
Type:
enhancement
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED FIXED
Milestone:
Thunderbird 59.0

People

(Reporter: aceman, Assigned: aceman)

References

(
URL
)

Details

(Keywords: user-doc-needed)

Attachments

(1 file, 4 obsolete files)

1353919.patch v 1.3
34.95 KB, patch
aceman
: review+
Details | Diff | Splinter Review 
In bug 1222244 all logging was converted to mozilla::LazyLogModule. It seems to me the new log module names are case sensitive and thus even if the names haven't changed in code, we must now use exact module names in the environment variables, e.g. MOZ_LOG_MODULES=POP3:5,SMTP:5,IMAP:5 .

The patch kept module names like this:
ldap (LDAP)
nsAbOutlookDirFactoryLog (AbOutlookDirFactory)
nsAbOutlookDirectoryLog (AbOutlookDirectory)
nsAbWinHelperLog (AbWinHelper)
nsMapiAddressBookLog (MapiAddressBook)
nsWabAddressBookLog (WabAddressBook)
MsgBiff
MsgCopyService
MsgPurge
msgcompose (MsgCompose)
SMTP
IMAPOFFLINE (IMAPOffline)
MSGDB (MsgDB)
BayesianFilter
ImapAutoSync
IMAP
APPLEMAILIMPORTLOG (AppleMailImport)
IMPORT (Import)
MAILBOX (Mailbox)
Movemail
MailDirStore
POP3
MAPI
MIME
NNTP

I propose to use this chance to fix up capitalization or names of some of the modules. I put my proposals in brackets.

Even if we do not change any of the names now, all the wiki pages mentioning the module names need to be updated with the exact capitalisation.
What does anybody think?
URL: https://wiki.mozilla.org/MailNews:Log...
Keywords: user-doc-needed
Good idea.

While we're not in bustage fix stress, we should see whether we can loose some of the static declarations of LazyLogModule. I added them all to get the thing to link. Looking at the first patch of bug 1222244, they used "extern":
https://hg.mozilla.org/comm-central/rev/89caadb262baf1e4c8a300a65aff4ec40b864123#l1.13
Actually, may I suggest to make at least the documented protocol names all lower case: imap, pop3, smtp, ldap, etc.
https://wiki.mozilla.org/MailNews:Logging:
Example module and loglevel with timestamp: "ldap:5,smtp:3,timestamp"
Example module and loglevel: "imap:5"
Well if the old code wasn't case sensitive, you could just update the documentation to use the ALLCAPS version, and everything should still work. 

Maybe everything should be ALLCAPS?
why change the doc, when we can change the code instead? :)

but seriously, we should change keep behavior from the *user* perspective the same as much as possible, because experienced users won't refer to the wiki and won't know the spec has changed to upper case.
(In reply to Jorg K (GMT+2) from comment #2)
> Good idea.
> 
> While we're not in bustage fix stress, we should see whether we can loose
> some of the static declarations of LazyLogModule. I added them all to get
> the thing to link. Looking at the first patch of bug 1222244, they used
> "extern":
> https://hg.mozilla.org/comm-central/rev/
> 89caadb262baf1e4c8a300a65aff4ec40b864123#l1.13

There should probably be one proper declaration (with initialization) and all the others linking to it via 'extern' ?
So can we agree on something here?
We MUST do something as right now the module names do not match the wiki page so either code or docs are wrong. We must fix one (or both).

So the options are:
1. change all module names to match the ones on the wiki page so that users do not need to do anything
2. some names no longer match the wiki, so use this chance to change also some other names in code and update the wiki page to match the code in all cases.

Also, it seems to me these modules mentioned on wiki are no longer found in code:
DockCounts
gssapi
ldapautocomplete
negotiateauth
Eric, in https://hg.mozilla.org/try-comm-central/rev/8aec2327ae9a886deddb15456ea519efec832643 I had to make some of the LazyLogModule declarations non-static so when I wanted to reference it via 'extern' from other file. Is that correct usage?
Flags: needinfo?(erahm)
For the option 2. there are multiple proposals on how to change the names:
1A. make all log names uppercase. That would need to change everything on the wiki.
1B. make all log names lowercase. That would mostly match what is on the wiki and would be 
2A. make log names be in uppercase for protocol names (LDAP, IMAP, NNTP...) and all the rest in camelCase or similar (as in comment 0)
2B. make log names be in uppercase for protocol names (LDAP, IMAP, NNTP...) and all the rest in lowercase
No longer blocks: 1222244
Depends on: 1222244
Version: 38 → Trunk
For comparison, m-c does not seem to have any system:
https://dxr.mozilla.org/comm-central/search?q=LazyLogModule
Many names are camel case and match the file name in which they are defined.
But e.g. NTLM is uppercased.
(In reply to :aceman from comment #8)
> Eric, in
> https://hg.mozilla.org/try-comm-central/rev/
> 8aec2327ae9a886deddb15456ea519efec832643 I had to make some of the
> LazyLogModule declarations non-static so when I wanted to reference it via
> 'extern' from other file. Is that correct usage?

I don't think you really need to extern and de-duplicate them, with mozilla logging it's okay to redefine log modules with the same name, they'll all share the same backend. It gets tricky externing static/file-scoped objects as I'm not sure what the guarantees are for static initialization. ie you declare a static module in one file, you attempt to use it in another file, are we guaranteed the LazyLogModule has actually been initialized?
Flags: needinfo?(erahm)
Should we fix this for TB 59?
Flags: needinfo?(acelists)
Yes we should, but there is no decision. Should we drag in the Engineering committee, if we already have one? :)
Flags: needinfo?(acelists)
I'd say: Just do as you suggested in comment #0 and get review (from me).
Attached patch 1353919.patch (obsolete) — — Splinter Review 
This patch consolidates the log modules to these names:
AbOutlookDirectory
AbOutlookDirFactory
AbWinHelper
BayesianFilter
IMAP
IMAPAutoSync
IMAPOffline
Import
Mailbox
MailDirStore
MAPI
MAPIAddressBook
MIME
Movemail
MsgBiff
MsgCompose
MsgCopyService
MsgDB
MsgPurge
NNTP
POP3
SMTP
WABAddressBook

I have merged the Applemailimportlog into "Import" as all the other importers already used that name. I removed the duplicated boilerplate macros for the various importers that used different variable for the log module name but always called it "Import".

Each of the names is only defined once in the code and all the other references to it are using 'extern'. Hopefully it works. I have tried IMAP and POP3.
Assignee: nobody → acelists
Status: NEW → ASSIGNED
Attachment #8934016 - Flags: review?(jorgk)
Comment on attachment 8934016 [details] [diff] [review]
1353919.patch

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

::: mailnews/imap/src/nsImapProtocol.cpp
@@ -5688,5 @@
>          ", pref 0x%" PRIx64 ", failed 0x%" PRIx64 ", avail caps 0x%" PRIx64,
>          serverCaps, m_prefAuthMethods, m_failedAuthMethods, availCaps));
>    MOZ_LOG(IMAP, LogLevel::Debug, ("(GSSAPI = 0x%" PRIx64 ", CRAM = 0x%" PRIx64
>          ", NTLM = 0x%" PRIx64 ", MSN = 0x%" PRIx64 ", PLAIN = 0x%" PRIx64
> -        ",\n  LOGIN = 0x%" PRIx64 ", old-style IMAP login = 0x%" PRIx64

I removed this newline as it looked ugly in the log and no other message was split into lines like this one (and there we many other long lines output). Grepping the log file (e.g. for specific log module name) wouldn't work properly with this line as it is't prepended with the log module name and thread pid as others are.
Attached patch 1353919.patch v1.1 (obsolete) — — Splinter Review 
Forgot LDAP.

Also it seems Wayne & co have updated the wiki page to alert about the case-sensitive names since TB55.
Attachment #8934016 - Attachment is obsolete: true
Attachment #8934016 - Flags: review?(jorgk)
Attachment #8934017 - Flags: review?(jorgk)
Comment on attachment 8934017 [details] [diff] [review]
1353919.patch v1.1

Very nice effort. Perhaps for safety we should NOT extern those "shared usages". Eric said in comment #11:
===
I don't think you really need to extern and de-duplicate them, with mozilla logging it's okay to redefine log modules with the same name, they'll all share the same backend. It gets tricky externing static/file-scoped objects as I'm not sure what the guarantees are for static initialization. ie you declare a static module in one file, you attempt to use it in another file, are we guaranteed the LazyLogModule has actually been initialized?
===

It would be safer and easier just to have those duplicates (instead of "*Hopefully* it works"), no? Easier because we won't have to worry where the thing is declared. Each source file has it's own and the backend worries about the duplication. Works so far, so why change it.
Yes, I read that but I'm not sure if it is applicable here. I said that those variables that are referenced as extern in other file can't actually be declared 'static'. I had to remove the keyword from them, it is seen in the patch.

On the other hand, I'm OK with changing it back so we do not have a mess of some LogModules being static and some not (do those then get an instance for each object? Probably not, they are not object members, just some global variables in the file).
mozilla::LazyLogModule xxx("yyy");
runs the constructor and that can do whatever it deems fit. In this case perhaps open a file, etc.

The question is, what is the difference between:

Case 1:
file 1: static mozilla::LazyLogModule x1("xxx");
file 2: static mozilla::LazyLogModule x2("xxx");

and

Case 2:
file 1: mozilla::LazyLogModule x1("xxx");
file 2: extern x1;

Clearly in case 1 we get two objects and they even have different names. The backend guarantees what logging for "xxx" will end up in the same file, even if done via two separate objects. If the backend weren't smart, it would attempt to open two log files with the same name and possibly fail.

In case 2 we have one object and the worry, whether the object is initialised when using it in file 2. That brings us to the question when global objects are initialised.

I've done a lot of reading, including
https://stackoverflow.com/questions/55510/when-do-function-level-static-variables-get-allocated-initialized
https://stackoverflow.com/questions/16801491/global-object-constructor-isnt-getting-called
https://stackoverflow.com/questions/20309141/c-constructor-call-of-global-static-object-and-local-static-object-is-differ
www.nsnam.org/docs/linker-problems.doc
https://isocpp.org/wiki/faq/ctors#static-init-order
and I get the impression that all global objects should be initialised before main() is entered, so when the "compilation unit" of file 1 is initialised, all references from other files now reference the initialised global.

That said, M-C has a few examples of case 2:
https://searchfox.org/mozilla-central/search?q=LazyLogModule+gOfflineCacheUpdateLog&case=false&regexp=false&path=
https://searchfox.org/mozilla-central/search?q=LazyLogModule+gWindowsLog&case=false&regexp=false&path=
https://searchfox.org/mozilla-central/search?q=LazyLogModule+gXULTemplateLog&case=false&regexp=false&path=
https://searchfox.org/mozilla-central/search?q=LazyLogModule+gMediaDemuxerLog&path=
amongst others.

So the patch is most likely OK as it is and only creating the logging object once is possibly preferred, at least it protects against typos in the string name. Maybe it would be good to add a comment to the 'extern' lines to say:
// declared in xxx.cpp. That way I can also check that the most appropriate file contains the declaration.

And I thought that was an easy bug :-(
I've added some debug and without the patch I see:
=== main()
=== LazyLogModule CTOR ldap
=== LazyLogModule CTOR ldap
=== LazyLogModule CTOR ldap
=== LazyLogModule CTOR ldap
=== LazyLogModule CTOR ldap
=== LazyLogModule CTOR ldap
=== LazyLogModule CTOR MAPI
=== LazyLogModule CTOR MAPI
=== LazyLogModule CTOR nsAbOutlookDirFactoryLog
=== LazyLogModule CTOR nsAbOutlookDirectoryLog
=== LazyLogModule CTOR nsAbWinHelperLog
=== LazyLogModule CTOR nsMapiAddressBookLog
=== LazyLogModule CTOR nsWabAddressBookLog
=== LazyLogModule CTOR MsgBiff
=== LazyLogModule CTOR MsgCopyService
=== LazyLogModule CTOR MsgPurge
=== LazyLogModule CTOR msgcompose
=== LazyLogModule CTOR SMTP
=== LazyLogModule CTOR IMAPOFFLINE
=== LazyLogModule CTOR MSGDB
=== LazyLogModule CTOR IMAPOFFLINE
=== LazyLogModule CTOR BayesianFilter
=== LazyLogModule CTOR ImapAutoSync
=== LazyLogModule CTOR ImapAutoSync
=== LazyLogModule CTOR ImapAutoSync
=== LazyLogModule CTOR IMAP
=== LazyLogModule CTOR IMAP
=== LazyLogModule CTOR IMAP
=== LazyLogModule CTOR MAILBOX
=== LazyLogModule CTOR MailDirStore
=== LazyLogModule CTOR POP3
=== LazyLogModule CTOR POP3
=== LazyLogModule CTOR MIME
=== LazyLogModule CTOR NNTP
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
=== LazyLogModule CTOR IMPORT
followed by a lot of M-C initialisations.

With the patch I see:
=== main()
=== LazyLogModule CTOR LDAP
=== LazyLogModule CTOR LDAP
=== LazyLogModule CTOR LDAP
=== LazyLogModule CTOR LDAP
=== LazyLogModule CTOR LDAP
=== LazyLogModule CTOR LDAP
=== LazyLogModule CTOR MAPI
=== LazyLogModule CTOR AbOutlookDirFactory
=== LazyLogModule CTOR AbOutlookDirectory
=== LazyLogModule CTOR AbWinHelper
=== LazyLogModule CTOR MAPIAddressBook
=== LazyLogModule CTOR WABAddressBook
=== LazyLogModule CTOR MsgBiff
=== LazyLogModule CTOR MsgCopyService
=== LazyLogModule CTOR MsgPurge
=== LazyLogModule CTOR MsgCompose
=== LazyLogModule CTOR SMTP
=== LazyLogModule CTOR MsgDB
=== LazyLogModule CTOR IMAPOffline
=== LazyLogModule CTOR BayesianFilter
=== LazyLogModule CTOR IMAPAutoSync
=== LazyLogModule CTOR IMAP
=== LazyLogModule CTOR Mailbox
=== LazyLogModule CTOR MailDirStore
=== LazyLogModule CTOR POP3
=== LazyLogModule CTOR MIME
=== LazyLogModule CTOR NNTP
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
=== LazyLogModule CTOR Import
so some calls have been eliminated, but not all. The various LDAP calls come from ldap/xpcom/src/nsLDAPInternal.h which is most likely included in various places, same goes for the new ImportDebug.h.

So I'm really asking myself whether the 'extern' changes are worth it, since LDAP and Import still create multiple objects.

Looks like the initialisation happens in main() in mail/app/nsMailApp.cpp. I added more debug and saw that the initialisation happens in InitXPCOMGlue(), most likely in NS_LogInit(). So my theory from comment #20 that the initialisation happens by ways of C++ magic before main() is run wasn't right.

Since we don't seem to understand the initialisation process fully, we can't rule out that the 'extern' business doesn't introduce problems. So perhaps the approach of least resistance would be not to introduce 'extern' here. I'm undecided.
Thanks for the tests. It is interesting that even when Import is static, it is still initialized multiple times.
On the other hand, IMAPOffline which is NOT static, but the other reference is 'extern' is only constructed once now.
I think I should be able to merge Import and LDAP into one contruction for each by defining them only once and the .h files only having extern references.
The test was indeed painful since messing xpcom/base/Logging.h caused a 50 minute rebuild :-(

> It is interesting that even when Import is static, it is still initialized multiple times.
I'm printing the execution of the constructor of LazyLogModule. Whether static (local to the file) or not, any declaration of a variable of that class will execute the constructor, that's C++. ImportDebug.h declares a variable of that type, so any inclusion of that file produces such a (static) variable in that compilation unit for which the CTOR will run.

> ... the .h files only having extern references
That's what M-C do, see:
https://searchfox.org/mozilla-central/search?q=extern.*LazyLogModule&case=false&regexp=true&path=.h
Attached patch 1353919.patch v1.2 (obsolete) — — Splinter Review 
Can you try this?

The variable names are also a mess, but fixing that would make much more churn.
Attachment #8934017 - Attachment is obsolete: true
Attachment #8934017 - Flags: review?(jorgk)
Attached patch 1353919.patch v1.2 (rebased) (obsolete) — — Splinter Review 
Bit rot :-(
Attachment #8934279 - Attachment is obsolete: true
Comment on attachment 8934288 [details] [diff] [review]
1353919.patch v1.2 (rebased)

Now I get:
=== LazyLogModule CTOR LDAP
=== LazyLogModule CTOR MAPI
=== LazyLogModule CTOR AbOutlookDirFactory
=== LazyLogModule CTOR AbOutlookDirectory
=== LazyLogModule CTOR AbWinHelper
=== LazyLogModule CTOR MAPIAddressBook
=== LazyLogModule CTOR WABAddressBook
=== LazyLogModule CTOR MsgBiff
=== LazyLogModule CTOR MsgCopyService
=== LazyLogModule CTOR MsgPurge
=== LazyLogModule CTOR MsgCompose
=== LazyLogModule CTOR SMTP
=== LazyLogModule CTOR MsgDB
=== LazyLogModule CTOR IMAPOffline
=== LazyLogModule CTOR BayesianFilter
=== LazyLogModule CTOR IMAPAutoSync
=== LazyLogModule CTOR IMAP
=== LazyLogModule CTOR Mailbox
=== LazyLogModule CTOR MailDirStore
=== LazyLogModule CTOR POP3
=== LazyLogModule CTOR MIME
=== LazyLogModule CTOR NNTP
=== LazyLogModule CTOR Import

So that looks pretty good. I thought for the 'extern's you were going to add a comment where the thing is defined (*).

To make triple-sure that the initialisation is working, we should exercise an option that has 'extern's like IMAP or POP3 and make sure the logging from the file that uses the 'extern' is present in the log. In fact, I did with POP3 and saw:
ReleaseFolderLock haveSemaphore = TRUE
So that's from nsPop3Sink.cpp which is using an 'extern'.

r+, you may consider adding the comments mentioned in (*).
Attachment #8934288 - Flags: review+
Thanks, added the comments. Yes, I also saw the messages from POP3 sink.
Attachment #8934288 - Attachment is obsolete: true
Attachment #8934311 - Flags: review+
Keywords: checkin-needed
Pushed by mozilla@jorgk.com:
https://hg.mozilla.org/comm-central/rev/b2e0ad79b1b2
polish log module names into consistent naming style. r=jorgk
Status: ASSIGNED → RESOLVED
Closed: 7 years ago
Keywords: checkin-needed
Resolution: --- → FIXED
I've looked through the patch again before landing and it's a nice clean-up, thanks!
I've fixed https://wiki.mozilla.org/MailNews:Logging.
Target Milestone: --- → Thunderbird 59.0
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: