Incorrect information about VLOG in logging.h on Android?

[Carlos Knippschild]

In the documentation about VLOG in logging.h it is stated that:

These always log at the INFO log level (when they log at all).

Trying to interpret this for the Android case, my understanding was that VLOG(<any number>) will always log at the logcat INFO level, as long as VLOG is enabled for the level/module. But after not seeing the output I was expecting I did some filtering and found out that:

* My module's VLOG(2) calls were output at VERBOSE level. Example:

02-22 16:01:38.422: V/chromium(8607): [VERBOSE2:recent_tab_helper.cc(405)] Last_n snapshot succeeded for: https://en.m.wikipedia.org/wiki/2015_in_American_television

* My module's VLOG(2) calls were output at INFO level. Example:

02-22 16:51:57.537: I/chromium(9941): [INFO:recent_tab_helper.cc(197)] Navigated to: https://en.m.wikipedia.org/wiki/2015_in_American_television

So is this really unexpected or the documentation is just outdated? I wanted to confirm this with someone in the knows of logging before creating a patch to fix either of them.

[Andrew Grieve]

I don't know the answer, but did you mean to say VLOG(2) in both examples?

--
--
Chromium Developers mailing list: chromi...@chromium.org
View archives, change email options, or unsubscribe:
http://groups.google.com/a/chromium.org/group/chromium-dev

[Ian Clelland]

I'm guessing that the second example was actually VLOG(0).

Despite the docs, I think VLOG should really just be used with positive numbers. VLOG(0) is equivalent to LOG(INFO); only positive numbers end up logging with the "VERBOSE" tag.

You can see in logging.cc (https://cs.chromium.org/chromium/src/base/logging.cc?dr=CSs&l=672) that on Android, we attempt to match the severity level of the message to one of the log levels in Log.java. If you've called VLOG with a parameter > 0, severity_ will be < 0, and it will be mapped to ANDROID_LOG_VERBOSE. If you call VLOG(0), though, severity_ will = 0, which is INFO, and get mapped to ANDROID_LOG_INFO.

For fun, you could even try VLOG(-3), which I suspect would output FATAL messages.

[Torne (Richard Coles)]

VLOG(0) and DVLOG(0) should indeed never be used. I started writing a presubmit to ban these years ago but never got around to finishing it and I don't think I still have it any more. If someone wants to write a presubmit to forbid it and then go fix all the existing cases to be LOG(INFO) instead, that'd be really helpful.

[Carlos Knippschild]

@Andrew: The 2nd example was supposed to be VLOG(0). Thanks for clarifying that for me Ian.

@Ian: That logic is somewhat confusing and doesn't match the comments in logging.h. I think either behavior or docs should be updated.

@Torne: could you elaborate on why those should not be used? My use case: I what to add debug logs to the code and commit that so that I don't have to add it again and again, every time I have to debug that code. I'm specifically using DVLOG, where I expect all costs associated with it to be gone in release builds because of the ongoing concerns with Android's binary size. I can't see any alternatives to this if these become deprecated.

[Torne (Richard Coles)]

Because the point of VLOG is that it's not enabled by default and you have to pass --v to turn it on, but if you use VLOG(0) then it's enabled by default because that's the same thing as LOG(INFO). You should use VLOG(1) or higher. 0 is not valid.

[Carlos Knippschild]

Now I understood you're concern is with the "severity" level only, not with the macros themselves. I am using >= 1 values.