Fix Cronet mapping of Android log level into Chrome LogSeverity.

Fix Cronet mapping of Android log level into Chrome LogSeverity.

See VLOG(1) and VLOG(2) logging:
TEST=adb shell setprop log.tag.ChromiumNetwork VERBOSE

See VLOG(1) logging:
TEST=adb shell setprop log.tag.ChromiumNetwork DEBUG

See NO (only FATAL) logging:
TEST=adb shell setprop log.tag.ChromiumNetwork NONE

BUG=400956
Committed: https://src.chromium.org/viewvc/chrome?view=rev&revision=288088

[mef, 2014-08-06 03:26:53]

Could you take a look? I wonder if VLOG calls in Cronet should have hard-coded
verbosity level instead of relying on context_->logging_level() like here:
https://code.google.com/p/chromium/codesearch#chromium/src/components/cronet/...

[mmenke, 2014-08-06 14:41:36]

On 2014/08/06 03:26:53, mef wrote:
> Could you take a look? I wonder if VLOG calls in Cronet should have hard-coded
> verbosity level instead of relying on context_->logging_level() like here:
>
https://code.google.com/p/chromium/codesearch#chromium/src/components/cronet/...

I'm confused.  I don't see us ever sending the logging level anywhere - we
(Incorrectly) use it for the NetLogObserver, before giving it a valid logging
level, and then we pass it directly to a VLOG call...

Two questions:  How do we send this to the logging infrastructure, to set the
global log level, am I missing something?
Also, I thought VLOG only logged stuff when logging was enabled on a per-file
basis.  Am I missing something?  How are we getting around that?

[mef, 2014-08-06 15:31:14]

On 2014/08/06 14:41:36, mmenke wrote:
> On 2014/08/06 03:26:53, mef wrote:
> > Could you take a look? I wonder if VLOG calls in Cronet should have
hard-coded
> > verbosity level instead of relying on context_->logging_level() like here:
> >
>
https://code.google.com/p/chromium/codesearch#chromium/src/components/cronet/...
> 
> I'm confused.  I don't see us ever sending the logging level anywhere - we
> (Incorrectly) use it for the NetLogObserver, before giving it a valid logging
> level, and then we pass it directly to a VLOG call...
> 
> Two questions:  How do we send this to the logging infrastructure, to set the
> global log level, am I missing something?
> Also, I thought VLOG only logged stuff when logging was enabled on a per-file
> basis.  Am I missing something?  How are we getting around that?

It seems that VlogInfo::GetVlogLevel(const base::StringPiece& file) is calling
VlogInfo::GetMaxVlogLevel(), which returns -min_loglevel, which is 0.
If we call VLOG(0), then VLOG_IS_ON(0) is true as it does <= comparison:
https://code.google.com/p/chromium/codesearch#chromium/src/base/logging.h&rcl...

If we call VLOG(1) or more, then it is off as VLOG_IS_ON(1) would be false.

So, it seems that our logging is all wrong. The correct fix would be to call
SetMinLogLevel
(https://code.google.com/p/chromium/codesearch#chromium/src/base/logging.h&rcl...)
and use hard-coded log level in VLOG calls.

Does it make sense?

[mmenke, 2014-08-06 15:36:20]

On 2014/08/06 15:31:14, mef wrote:
> On 2014/08/06 14:41:36, mmenke wrote:
> > On 2014/08/06 03:26:53, mef wrote:
> > > Could you take a look? I wonder if VLOG calls in Cronet should have
> hard-coded
> > > verbosity level instead of relying on context_->logging_level() like here:
> > >
> >
>
https://code.google.com/p/chromium/codesearch#chromium/src/components/cronet/...
> > 
> > I'm confused.  I don't see us ever sending the logging level anywhere - we
> > (Incorrectly) use it for the NetLogObserver, before giving it a valid
logging
> > level, and then we pass it directly to a VLOG call...
> > 
> > Two questions:  How do we send this to the logging infrastructure, to set
the
> > global log level, am I missing something?
> > Also, I thought VLOG only logged stuff when logging was enabled on a
per-file
> > basis.  Am I missing something?  How are we getting around that?
> 
> It seems that VlogInfo::GetVlogLevel(const base::StringPiece& file) is calling
> VlogInfo::GetMaxVlogLevel(), which returns -min_loglevel, which is 0.
> If we call VLOG(0), then VLOG_IS_ON(0) is true as it does <= comparison:
>
https://code.google.com/p/chromium/codesearch#chromium/src/base/logging.h&rcl...
> 
> If we call VLOG(1) or more, then it is off as VLOG_IS_ON(1) would be false.
> 
> So, it seems that our logging is all wrong. The correct fix would be to call
> SetMinLogLevel
>
(https://code.google.com/p/chromium/codesearch#chromium/src/base/logging.h&rcl...)
> and use hard-coded log level in VLOG calls.
> 
> Does it make sense?

Other than the fact we take in log-levels on a per-URLRequestContext level, yes.

[mef, 2014-08-06 16:07:11]

On 2014/08/06 15:36:20, mmenke wrote:
> On 2014/08/06 15:31:14, mef wrote:
> > On 2014/08/06 14:41:36, mmenke wrote:
> > > On 2014/08/06 03:26:53, mef wrote:
> > > > Could you take a look? I wonder if VLOG calls in Cronet should have
> > hard-coded
> > > > verbosity level instead of relying on context_->logging_level() like
here:
> > > >
> > >
> >
>
https://code.google.com/p/chromium/codesearch#chromium/src/components/cronet/...
> > > 
> > > I'm confused.  I don't see us ever sending the logging level anywhere - we
> > > (Incorrectly) use it for the NetLogObserver, before giving it a valid
> logging
> > > level, and then we pass it directly to a VLOG call...
> > > 
> > > Two questions:  How do we send this to the logging infrastructure, to set
> the
> > > global log level, am I missing something?
> > > Also, I thought VLOG only logged stuff when logging was enabled on a
> per-file
> > > basis.  Am I missing something?  How are we getting around that?
> > 
> > It seems that VlogInfo::GetVlogLevel(const base::StringPiece& file) is
calling
> > VlogInfo::GetMaxVlogLevel(), which returns -min_loglevel, which is 0.
> > If we call VLOG(0), then VLOG_IS_ON(0) is true as it does <= comparison:
> >
>
https://code.google.com/p/chromium/codesearch#chromium/src/base/logging.h&rcl...
> > 
> > If we call VLOG(1) or more, then it is off as VLOG_IS_ON(1) would be false.
> > 
> > So, it seems that our logging is all wrong. The correct fix would be to call
> > SetMinLogLevel
> >
>
(https://code.google.com/p/chromium/codesearch#chromium/src/base/logging.h&rcl...)
> > and use hard-coded log level in VLOG calls.
> > 
> > Does it make sense?
> 
> Other than the fact we take in log-levels on a per-URLRequestContext level,
yes.
We don't expose that to Cronet consumers and don't have to. I could make those
static methods.

Ok, so, what about logging in base/ and net/? I guess the values should be as
follows:

    private static final int LOG_NONE = 3; // LOG(FATAL), no VLOG.
    private static final int LOG_DEBUG = -1;  // LOG(FATAL...INFO), VLOG(1)
    private static final int LOG_VERBOSE = -2;  // LOG(FATAL...INFO), VLOG(2)

Specifically in Cronet use VLOG(1) for debug messages in url_request_peer and
such, and VLOG(2) for NetLogObserver.

WDYT?

[mef, 2014-08-06 21:59:25]

PTAL. 
I've changed log_level usage to SetMinLogLevel and updated constants
accordingly. 
I've tested it with Cronet Sample and it works as expected.

[mmenke, 2014-08-07 15:07:27]

LGTM

https://codereview.chromium.org/447653002/diff/20001/components/cronet/androi...
File components/cronet/android/org_chromium_net_UrlRequestContext.cc (right):

https://codereview.chromium.org/447653002/diff/20001/components/cronet/androi...
components/cronet/android/org_chromium_net_UrlRequestContext.cc:90:
logging::SetMinLogLevel(static_cast<int>(log_level));
Still a bit concerned about setting this globally, when creating every
RequestContext.

https://codereview.chromium.org/447653002/diff/20001/components/cronet/androi...
File components/cronet/android/url_request_context_peer.cc (right):

https://codereview.chromium.org/447653002/diff/20001/components/cronet/androi...
components/cronet/android/url_request_context_peer.cc:204: if (VLOG_IS_ON(2)) {
This is redundant with the VLOG(2), below

[mmenke, 2014-08-07 15:27:23]

LGTM as-is (May want to fix the double-VLOG issue, though).

For the record, we talked a bit about this, and decided the best approach is to
land this as-is and worry about cleaning up how it works in the future, as it
will be a bit more involved.

[mef, 2014-08-07 15:39:57]

thanks!

https://codereview.chromium.org/447653002/diff/20001/components/cronet/androi...
File components/cronet/android/org_chromium_net_UrlRequestContext.cc (right):

https://codereview.chromium.org/447653002/diff/20001/components/cronet/androi...
components/cronet/android/org_chromium_net_UrlRequestContext.cc:90:
logging::SetMinLogLevel(static_cast<int>(log_level));
On 2014/08/07 15:07:27, mmenke wrote:
> Still a bit concerned about setting this globally, when creating every
> RequestContext.

Added TODO.

https://codereview.chromium.org/447653002/diff/20001/components/cronet/androi...
File components/cronet/android/url_request_context_peer.cc (right):

https://codereview.chromium.org/447653002/diff/20001/components/cronet/androi...
components/cronet/android/url_request_context_peer.cc:204: if (VLOG_IS_ON(2)) {
On 2014/08/07 15:07:27, mmenke wrote:
> This is redundant with the VLOG(2), below

Done.

[mef, 2014-08-07 15:41:43]

The CQ bit was checked by mef@chromium.org

[commit-bot: I haz the power, 2014-08-07 15:43:57]

CQ is trying da patch. Follow status at
 https://chromium-status.appspot.com/cq/mef@chromium.org/447653002/40001

[commit-bot: I haz the power, 2014-08-07 17:07:25]

Change committed as 288088