Modify output method of loggingT to handle Logger/InfoLogger correctly

[vanou]

What this PR does / why we need it:
This commit modifies output method of loggingT to handle l.logr or argument log correctly, if set.

In this commit l.logr is checked first, because if loggingT.logr, which is only receiver value of output method currently, is set, it should be used unconditionally as comment of logr field of loggingT says.

Till this commit applies, output method is only used with global variable logging as receiver and logging.logr/Verbose.logr as argument log.
To maintain backward compatibility, in this commit, output method only checks whether argument s is errorLog or not when l.logr is not nil.

Which issue(s) this PR fixes:
None

Special notes for your reviewer:
None

Release note:
None

[k8s-ci-robot]

[APPROVALNOTIFIER] This PR is NOT APPROVED

This pull-request has been approved by: vanou
To complete the pull request process, please assign lavalamp
You can assign the PR to them by writing /assign @lavalamp in a comment when ready.

The full list of commands accepted by this bot can be found here.

Details

Needs approval from an approver in each of these files:

• OWNERS

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

[vanou]

Sorry @neolit123 . I have made test function. However it becomes little big.

If you review it, it's very thankful.

[neolit123]

the above branching looks mostly correct to me, but i pinged the #klog channel of k8s slack for more reviewers.

[vanou]

Thanks!

[munnerz]

It should technically never be possible to get into a state where log == nil, l.logr != nil and s == errorLog right? Because there is no Error method on an InfoLogger. I ask because otherwise there is a risk we drop errors here 😄

This logic looks right to me :) just trying to validate my own assumptions!

[vanou]

Thanks @munnerz .

Yes, that is underlying idea of this line. Ideally, it should not happen.

[munnerz]

Makes sense. If l.logr == nil, log != nil and s is not infoLog, it seems like log messages will be silently dropped. I'm not sure if this is a feasible situation to be in, but with the previous code we'd always log unconditionally if log != nil. Is there a reason for the s == infoLog check on this line?

[vanou]

Yes, as you said, if l.logr == nil, log != nil and s is not infoLog, log messages will be dropped.
I read logr package's README and thought it's good approach that klog only handles infoLog or errorLog when logr.InfoLogger or logr.Logger is used. Because user of logr.InfoLogger & logr.Logger only expects Info or Error, I think.
So, future development of klog should care about this logr's idea.

As I wrote in klog_test.go, currently this commit doesn't hurt klog package's code. And there is no public method/function with which user can specify severity value of output method.

[munnerz]

Because user of logr.InfoLogger & logr.Logger only expects Info or Error, I think.

There are log levels in between (e.g. warning) that do not have direct equivalents in a logr world (as logr only has levels). The thinking is to treat any un-levelled log message that specifies a non-info level severity as an Info message and pass along the severity as a 'key/value' in the log line (i.e. severity=warn) (except for Errors, which are always passed to the root Logger via the Error method). The reason this severity k/v pair wasn't added when SetLogger was originally added can be seen here: #20 (comment)

Mostly there wasn't clear consensus as to what 'keys' should be used and what the onus is on implementors of the logr interface wrt setting these keys so other consumers can consume them reliably 😄

[vanou]

I understand why k/v isn't added. It's hard problem, until some set of standard keys is established.

Thanks!

[munnerz]

In this commit l.logr is checked first, because if loggingT.logr, which is only receiver value of output method currently, is set, it should be used unconditionally as comment of logr field of loggingT says.

I'm not actually sure if this has been interpreted correctly:

	// If set, all output will be redirected unconditionally to the provided logr.Logger
	logr logr.Logger

The wording here was to explain that if SetLogger has been called, all output will be sent to this logger.
If the log argument to output is provided, it indicates that the call-site has 'scoped' that particular message (i.e. through a call to V).

For example, here:

klog/klog.go

Lines 1223 to 1245 in d2e1629

	// Info is equivalent to the global Info function, guarded by the value of v.
	// See the documentation of V for usage.
	func (v Verbose) Info(args ...interface{}) {
	if v.enabled {
	logging.print(infoLog, v.logr, args...)
	}
	}
	// Infoln is equivalent to the global Infoln function, guarded by the value of v.
	// See the documentation of V for usage.
	func (v Verbose) Infoln(args ...interface{}) {
	if v.enabled {
	logging.println(infoLog, v.logr, args...)
	}
	}
	// Infof is equivalent to the global Infof function, guarded by the value of v.
	// See the documentation of V for usage.
	func (v Verbose) Infof(format string, args ...interface{}) {
	if v.enabled {
	logging.printf(infoLog, v.logr, format, args...)
	}
	}

The second argument (v.logr) is a levelled logger, created in newVerbose here:

klog/klog.go

Line 1170 in d2e1629

return Verbose{b, logging.logr.V(int(level))}

.

With your change, the logging.logr will be used instead of the passed down, levelled logger that should be used.

This method should:

1. always log to the argument log if it is provided
2. if the severity is error, the struct member Logger is used instead of log, because log is an InfoLogger and so does not have an Error method
3. otherwise, print to log.Info (or l.log if log isn't provided)

What's the actual incorrect behaviour you're seeing that has lead to this PR? I think I'm struggling to see the motivation for it now I've dug in more.. 😅

[vanou]

Thanks @munnerz .

klog/klog.go

Line 1170 in d2e1629

return Verbose{b, logging.logr.V(int(level))}

I missed this path. So this commit doesn't make sense. Sorry for taking your time.

My motivation is to make importer of klog be able to handle multiple logr.InfoLogger/logr.Logger implementations. My colleague wants to implement some kind of structured logging and it's possible that his idea conflicts with others' (e.g. his approach produces many lines of log so it's cost is not acceptable others. So want to apply his idea only part of k8s code, say, apiserver).
To do this I want to make type loggingT public type and modify klog code glued to logging global variable.

[vanou]

/close