1299713 - WebRTC logging doesn't work with MOZ_LOG(_MODULES)

Status: NEW

(Core :: WebRTC, defect, P4)

Description

[Nico Grunbaum [:ng, @chew:mozilla.org]]

Attachment: ff_moz_log_test.log

Setting the log modules via MOZ_LOG or MOZ_LOG_MODULES has no effect.

On a fresh build of central @b3ec8a3373e8, on Ubuntu Linux 14.0.4.1, I tried the following (logs included as attachments), running in non-e10s mode:

# Try MOZ_LOG
(set -x && hg id && cat /home/ng/sync/build/debug.mozconfig && env -i DISPLAY=:1 MOZ_LOG=all:5 MOZ_LOG_FILE= SHELL=zsh MOZCONFIG=/home/ng/sync/build/debug.mozconfig ./mach run) >/tmp/ff_moz_log_test.log 2>&1

# Try MOZ_LOG_MODULES
(set -x && hg id && cat /home/ng/sync/build/debug.mozconfig && env -i DISPLAY=:1 NSPR_LOG_MODULES=all:5 MOZ_LOG_FILE= SHELL=zsh MOZCONFIG=/home/ng/sync/build/debug.mozconfig ./mach run) >/tmp/ff_nspr_log_modules_test.log 2>&1

# Try NSPR_LOG_MODULES
(set -x && hg id && cat /home/ng/sync/build/debug.mozconfig && env -i DISPLAY=:1 NSPR_LOG_MODULES=all:5 MOZ_LOG_FILE= SHELL=zsh MOZCONFIG=/home/ng/sync/build/debug.mozconfig ./mach run) >/tmp/ff_nspr_log_modules_test.log 2>&1

Setting them via NSPR_LOG_MODULES works as expected.


This appears to be the case on OS X as well.

Comment 1

[Nico Grunbaum [:ng, @chew:mozilla.org]]

Attachment: ff_moz_log_modules_test.log

Comment 2

[Nico Grunbaum [:ng, @chew:mozilla.org]]

Attachment: ff_nspr_log_modules_test.log

Comment 3

[Nils Ohlmeier [:drno]]

Just to make sure people who are working on this notice that this causes other engineers quite a bit of pain.

Comment 4

[Honza Bambas (:mayhemer)]

I don't think the "all" module is supported by the MOZ log back end.

Also, please understand what MOZ_LOG(_MODULES) and NSPR_LOG_MODULES exactly mean these days.  

We have two logging back ends.  The old one in NSPR that reads the NSPR_LOG_MODULES env var and only logs modules defined inside the NSPR code (very little these days).

Then there is a new one, actively maintained, residing in XPCOM.  This one is used for all of the Gecko code right now.  

This XPCOM log back end used to work with the NSPR_LOG* env var pair.  But that was found to be a mistake (bug 1248565) and hence we introduced a new env var pair (MOZ_LOG*) just for the XPCOM logging back end.  For compatibility, the XPCOM logging back end also reads NSPR_LOG* env vars if MOZ_LOG* env vars are not defined.

Later the MOZ_LOG_MODULES env var was from some reason renamed to only MOZ_LOG (bug 1275439).  MOZ_LOG_MODULES is also supported for compatibility when MOZ_LOG is not defined.


So, what you see in your 'NSPR_LOG_MODULES=all:5' log is what just and only the NSPR code is producing.  I.e. there is _nothing_ that Gecko logs with the new XPCOM log back end.  Probably not what you expect anyway.

Comment 5

[Nathan Froyd [:froydnj]]

(In reply to Nils Ohlmeier [:drno] from comment #3)
> Just to make sure people who are working on this notice that this causes
> other engineers quite a bit of pain.

Which part?  The 'all' module not working (who logs *everything* and finds it useful?), or something else?

Comment 6

[Nils Ohlmeier [:drno]]

(In reply to Nathan Froyd [:froydnj] from comment #5)
> Which part?  The 'all' module not working (who logs *everything* and finds
> it useful?), or something else?

This is what I'm aware of (and I'm assuming we are not the only once struggling with these changes):
- 2.5+ hours discussion in #media http://logs.glob.uno/?c=mozilla%23media&s=31+Aug+2016&e=2+Sep+2016&b=1#c283888
- 5 Wiki page updates going forth and back https://wiki.mozilla.org/index.php?title=Media/WebRTC/Logging&action=history

Comment 7

[Nico Grunbaum [:ng, @chew:mozilla.org]]

The only thing I have used 'all' for is figuring out what logging to look for. My use of it above was only for demonstrative convenience (or so I thought).  I have no strong opinion as to if stays or goes. I would personally be satisfied with a note that it is not available with MOZ_LOG in the docs.

The 'all' log level aside, I was mislead by the following warning:

[26265] WARNING: NSPR_LOG_MODULES is deprecated.
Please use MOZ_LOG instead.

Which seems to imply that the environment variable NSPR_LOG_MODULES can be replaced with MOZ_LOG. Though it can't for log modules that haven't moved over to the new MOZ_LOG yet. This was compounded by the fact that for a while it did work as the warning seemed to imply.

Comment 8

[Eric Rahm [:erahm]]

I don't think we want to support MOZ_LOG='all'. We could certainly add a warning and suggest using NSPR_LOG_MODULES='all' to turn on all NSPR and NSS loggers (but not gecko).

(In reply to Nils Ohlmeier [:drno] from comment #6)
> (In reply to Nathan Froyd [:froydnj] from comment #5)
> > Which part?  The 'all' module not working (who logs *everything* and finds
> > it useful?), or something else?
> 
> This is what I'm aware of (and I'm assuming we are not the only once
> struggling with these changes):
> - 2.5+ hours discussion in #media
> http://logs.glob.uno/
> ?c=mozilla%23media&s=31+Aug+2016&e=2+Sep+2016&b=1#c283888
> - 5 Wiki page updates going forth and back
> https://wiki.mozilla.org/index.php?title=Media/WebRTC/Logging&action=history

I get that WebRTC is in a bit of limbo right now, if bug 1257713 gets fixed we can finish the conversion to LazyLogModule and hopefully that will clear things up. Unfortunately that bug has stalled out.

So either we should close this bug as WONTFIX, add a warning if the all thing is particularly confusing, or rename the title of this bug if that's not the intent of the official bug report, perhaps to "WebRTC logging doesn't work with MOZ_LOG" or something like that and make it depend on bug 1257713.

Comment 9

[Eric Rahm [:erahm]]

(In reply to Nico Grunbaum [:ng] from comment #7)
> The only thing I have used 'all' for is figuring out what logging to look
> for. My use of it above was only for demonstrative convenience (or so I
> thought).  I have no strong opinion as to if stays or goes. I would
> personally be satisfied with a note that it is not available with MOZ_LOG in
> the docs.

Which logs were you trying to turn on? WebRTC/signaling stuff?

> 
> The 'all' log level aside, I was mislead by the following warning:
> 
> [26265] WARNING: NSPR_LOG_MODULES is deprecated.
> Please use MOZ_LOG instead.
> 
> Which seems to imply that the environment variable NSPR_LOG_MODULES can be
> replaced with MOZ_LOG. Though it can't for log modules that haven't moved
> over to the new MOZ_LOG yet. This was compounded by the fact that for a
> while it did work as the warning seemed to imply.

I agree this is confusing, would you mind filing a bug for that and we can remove the warning or update the text to something like "Note: Use MOZ_LOG for gecko logs"? We can bikeshed in that bug.

Comment 10

[Nico Grunbaum [:ng, @chew:mozilla.org]]

(In reply to Eric Rahm [:erahm] from comment #9)
> Which logs were you trying to turn on? WebRTC/signaling stuff?
Yep.
> I agree this is confusing, would you mind filing a bug for that and we can
> remove the warning or update the text to something like "Note: Use MOZ_LOG
> for gecko logs"? We can bikeshed in that bug.
Sure thing.

Comment 11

[Eric Rahm [:erahm]]

Okay I'm updating the title to reflect the original issue, we can table the 'all' discussion for now.

Let's also move this to WebRTC as the problem is that WebRTC still uses NSPR logging in some places (there's bug 1219468 to fix that, but that's blocked by bug 1257713).

Comment 12

[Bulk Bug Changes for mreavy's org]

Mass change P3->P4 to align with new Mozilla triage process.