SDK log injection and uniform logging in operator-sdk binary

[estroz]

Description of the change:

1. Switch the operator-sdk binary's logger from a mix of std log and logrus to only logrus.
2. Use controller-runtime/pkg/runtime/log.SetLogger() to inject logr.Logger that users can define into their operator.
   • The SDK injects zap by default in this PR.
   • pkg/sdk/*metrics* and pkg/ansible are used by generated operators, which is why these packages don't use logrus.

Motivation for the change: Operators generated by the SDK did not have a uniform logging interface pre-v0.1.0. Now that controller-runtime is the main source of logs in a generated operator, the decision was made to expose a log injection mechanism so users can choose what logger to use and operators emit uniform, structured logs. See #503 for our detailed discussion. The operator-sdk binary similarly did not have uniform logging. logrus is a reasonable choice for the binary's logger because warnings are used frequently.

Closes #503, closes #732

[estroz]

Note: I'm removing package-level logging in favor of a more configurable setup.

[hasbro17]

Going on a bit of exposition here:

So logr levels have no concept of Warn, Fatal or anything else. It only has Info and Error.
Logr's Info logs decrease in importance as the levels(0,1,2,...) go up e.g 0 is considered standard Info, 1 could be considered Debug(less important), 2 is like more Debug(even less important).
No levels map to Warn or Fatal which are generally more important than Info and Debug.

Zap levels are the inverse. -2(More Debug) -1(Debug), 0 (Info), 1(Warning) ...
https://godoc.org/go.uber.org/zap/zapcore#Level

But since zapr just flips the logr level it will only end up using the following zap levels: 0(Info), -1(Debug), -2(More Debug) ...
https://github.com/go-logr/zapr/blob/master/zapr.go#L133-L134
https://github.com/go-logr/zapr/blob/master/zapr.go#L34-L37

So zapr's mapping is correct.

In practice because the runtime's helper uses either Development or Production configs for zapr, we can only see 2 (zap)levels of logs.

• Production => zap.Info(0) and higher
  • so only logr.V(0) => zap.V(0). Remember logr.V(-1) is illegal.
• Development => zap.Debug(-1) and higher
  • so that gives us logr.V(1) => zap.V(-1) and logr.V(0) => zap.V(0) and
    https://github.com/kubernetes-sigs/controller-runtime/blob/master/pkg/runtime/log/log.go#L39-L48

Since logr.V(2) or zap.V(-2) is a custom Debug level those logs will not show up. So logr.V(2) is pointless if we're using the runtime's ZapLogger(development bool) method.

That's why the runtime only has 2 levels of logs statements right now.
Info or logr.V(0) and Debug logr.V(1)

[hasbro17]

Unless I'm wrong, currently:
VDebug=-1 and VWarn=0
https://play.golang.org/p/JJa3L4rznIr
Making logr.V(VDebug) illegal. And Warn would just be Info.

I would prefer not to use these consts and just use logr.V(0)( which is justlogr.Info()) and logr.V(1).

And if we must have consts then they should only be VInfo=0 and VDebug=1.
Warnings or VWarn is going against the logr since there is no level for warnings and V(1) is not a warning.
Even VDebug=1 is just our alias for a less important log.

@shawn-hurley @joelanford

[lilic]

And if we must have consts then they should only be VInfo=0 and VDebug=1.
Warnings or VWarn is going against the logr since there is no level for warnings and V(1) is not a warning.

We agreed on warning to be 0 in the meeting as summed up
#503 (comment)

But yes, reading the logr docs again and:

I restrict the API to just 2 types of logs: info and error.

So should we then just go with info and error only, as it also has no concept of debug either and not assign "names" to numbers as suggested by logr docs?

[shawn-hurley]

I would prefer not to use these consts and just use logr.V(0)( which is justlogr.Info()) and logr.V(1).

👍

I think it is just easier to deal with IMO.

[estroz]

I'll remove constants and change all Warn to Info

[shawn-hurley]

LGTM! Thank you for doing the ansible stuff and cleaning it up some too!

[shawn-hurley]

I would prefer not to use these consts and just use logr.V(0)( which is justlogr.Info()) and logr.V(1).

👍

I think it is just easier to deal with IMO.

[hasbro17]

LGTM

Thanks for keeping this on track.
We might want to revisit the choice of the zapr logger implementation later but this should be good enough for now.

[hasbro17]

@estroz Forgot one last nit. This should be in doc/user/logging.md
doc/dev is for developers of the SDK.