Default logger for the SDK

[lilic]

Setting log level and adding verbose flag would be useful as it'd be nice to give some visibility to the user about what is happening.

[AlexNPavel]

This is definitely something that could be very useful for users. At the moment, I don't believe we're using a logging library for the commands that supports different levels. There are a couple of options that we could use like logrus or glog. We then need to go through all the logging and print statements in commands (maybe other parts of the project as well) and set a log type. This would be quite a big undertaking, but probably worth it int the long run. We should probably discuss this more in the team slack or weekly syncs and post updates here when we decide how to tackle this.

[AlexNPavel]

At the moment, there are various parts of the project already using logrus, so that may be the better option

[shawn-hurley]

I would vote that the project moves to logr which is used by controller runtime, and uses either zap or glog as the actual logger and controller runtime uses zap I believe.

Also, currently it seems that the operator-sdk is using env vars for most of these options and I would like to see these exposed as a command line flag. WDYT?

[CSdread]

I vote for logrus, it is very mature, and is the preferred for our company due to its feature set. I also would like to see both env vars and command line flags supported for all options. Could be nice to even specify as a yaml/json configuration file. I am a -1 on glog as I find it is not built with idiomatic practices of good go code

[lilic]

At the moment, there are various parts of the project already using logrus, so that may be the better option

I vote for logrus

I agree with logrus. While logr does look intersting, I would disagree in using glog, as upstream is also trying to move away from me as well. zap sounds good for performence but maybe logrus which we already use could be the better choice for now.

[hasbro17]

@shawn-hurley The main benefit of using logr(with zap) is that the logs will be consistent with the controller-runtime's logs if you turn on those logs with logf.SetLogger(logf.ZapLogger(false)).

I have no experience with zap or logr so I might not be using it correctly but I took a stab at it to compare the experience with logrus.

import logf "sigs.k8s.io/controller-runtime/pkg/runtime/log"
...
         // Development config (stacktraces on warnings, no sampling)
	zapLogr := logf.ZapLogger(true).WithName("main")
	zapLogr.Info("test info")
	zapLogr.Error(errors.New("my custom error"), "my sample error message")
	zapLogr.V(0).Info("test V(0)")
	zapLogr.V(1).Info("test V(1)")
        zapLogr.V(2).Info("test V(2)")

shows:

2018-10-11T15:03:53.846-0700	INFO	main	manager/main.go:34	test info
2018-10-11T15:03:53.846-0700	ERROR	main	manager/main.go:35	my sample error message	{"error": "my custom error"}
github.com/example-inc/memcached-operator/vendor/github.com/go-logr/zapr.(*zapLogger).Error
	/Users/haseeb/work/go-space/src/github.com/example-inc/memcached-operator/vendor/github.com/go-logr/zapr/zapr.go:128
main.main
	/Users/haseeb/work/go-space/src/github.com/example-inc/memcached-operator/cmd/manager/main.go:35
runtime.main
	/usr/local/go/src/runtime/proc.go:198
2018-10-11T15:03:53.846-0700	INFO	main	manager/main.go:36	test V(0)
2018-10-11T15:03:53.846-0700	DEBUG	main	manager/main.go:37	test V(1)

zapLogr.V(2).Info("test V(2)") wasn't printed out. Not sure how to enable that.

And if I use logf.ZapLogger(true) or production mode:

import logf "sigs.k8s.io/controller-runtime/pkg/runtime/log"
...
         // Development config (stacktraces on errors, sampling)
	zapLogr := logf.ZapLogger(true).WithName("main")

it shows:

{"level":"info","ts":1539295698.2198892,"logger":"main","caller":"manager/main.go:34","msg":"test info"}
{"level":"error","ts":1539295698.2199519,"logger":"main","caller":"manager/main.go:35","msg":"my sample error message","error":"my custom error","stacktrace":"github.com/example-inc/memcached-operator/vendor/github.com/go-logr/zapr.(*zapLogger).Error\n\t/Users/haseeb/work/go-space/src/github.com/example-inc/memcached-operator/vendor/github.com/go-logr/zapr/zapr.go:128\nmain.main\n\t/Users/haseeb/work/go-space/src/github.com/example-inc/memcached-operator/cmd/manager/main.go:35\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:198"}
{"level":"info","ts":1539295698.2199934,"logger":"main","caller":"manager/main.go:36","msg":"test V(0)"}

And logrus for comparison:

	logrus.SetFormatter(&logrus.TextFormatter{
		FullTimestamp: true,
	})
	logrus.SetLevel(logrus.DebugLevel)
	logger := logrus.WithFields(logrus.Fields{"component": "main"})
	logger.Info("test info")
	logger.Print("test print")
	logger.Errorf("my custom error: %v", errors.New("my sample error message"))
	logger.Debug("test debug")
	logger.Warn("test warning")
	logger.Fatal("test fatal")

gives us:

INFO[2018-10-11T15:36:09-07:00] test info                                     component=main
INFO[2018-10-11T15:36:09-07:00] test print                                    component=main
ERRO[2018-10-11T15:36:09-07:00] my custom error: my sample error message      component=main
DEBU[2018-10-11T15:36:09-07:00] test debug                                    component=main
WARN[2018-10-11T15:36:09-07:00] test warning                                  component=main
FATA[2018-10-11T15:36:09-07:00] test fatal                                    component=main

From a usability perspective do you think logr's interface is more intuitive or useful than logrus?
Enough so that we recommend that as our default prescribed logger in the templates?

Right now in the refactor branch we've stepped back from using logrus since I didn't want to presume what kind of logger should be used and would rather leave it up to the user. At least until we can decide.
https://github.com/operator-framework/operator-sdk/blob/refactor/controller-runtime/pkg/scaffold/cmd.go#L53-L57

[shawn-hurley]

I think what we may want to consider, is implementing a logrus backend for logr.

logr appears to me to be nothing more than a standard interface for logging. If we choose to use the logr interface then

1. users could implement their own backends for whichever logger they want all we need to do is expose something like this.

2. This could could be filtered down to controller-runtime so our logs look the same as their logs.

Here is the logr interface implementation: https://github.com/go-logr/logr/blob/master/logr.go#L120

And if you want to know how to get .V2() logging look here: https://github.com/go-logr/zapr
Specifically this line:

Levels in logr correspond to custom debug levels in Zap. Any given level in logr is represents by its inverse in Zap (zapLevel = -1*logrLevel).

For example V(2) is equivalent to log level -2 in Zap, while V(1) is equivalent to Zap's DebugLevel.

This will give users more choice, will allow folks to get logrus as a defualt (which I think looks nicer IMO) and our logs can then look exactly like controller-runtimes logs because we just set their logr as our implementation.

Does this all make sense?

[estroz]

I am partial to using logrus for various reasons, including but not limited to:

• Project maturity.
• logrus takes care of our log.Fatal*(...) usage, whereas logr doesn't like that level of control.
• We can format our log entries however we want by implementing a logrus.Formatter, allowing the SDK to copy zap format @hasbro17.

@shawn-hurley writing a logrus backend for logr would be the most reasonable solution to me if not for the latter two reasons above.