Homogenize logs

[sebgl]

Things are in a rather strange state currently:

• we use log.Info() most of the times (log level: 0)
• sometimes, we use log.V(3) or log.V(4)
• we don't have any flag parsing on -vvvv to adapt the level of log getting printed out
• the controller-runtime log package pre-configures a zap logger compatible with the loggr interface, which only accepts 2 options: development or not
• if development mode is true, we use the debug level (V(1)) and logs encoded for a better output on the terminal
• if development is false, we use the info level (V(0)) and logs encoded as JSON
• using V(3) or V(4) has no effect.

Recommendations from the controller-runtime team seems to be: stick to INFO for production and V(1).Info (debug) for development. See this doc and this issue.

I think we should either:

1. comply with what controller-runtime is doing: keep current settings and use only info and debug levels
2. configure our own logger (zap or something else), with log levels parsed from flags (-vvv)

I would personally vote for option 1 (simpler).

[thbkrkr]

It could also be the opportunity to homogenize the log messages. Sometimes there are parametrized messages, sometimes messages use key-values but with keys not always in snakecase.

https://github.com/elastic/stack-operators/blob/ade7bdaa23ff02f41ebcaf16bfddf3777a9ce3cc/stack-operator/pkg/controller/common/reconciler/reconciler.go#L81

https://github.com/elastic/stack-operators/blob/7aa3852f8d56feb7a823ab263c11707828fe1f3e/stack-operator/pkg/controller/elasticsearch/driver/default.go#L199-L203

https://github.com/elastic/stack-operators/blob/156792da3f65c8dd829d96e36c30f20f311b93d4/stack-operator/cmd/keystore-updater/main.go#L132

https://github.com/elastic/stack-operators/blob/7aa3852f8d56feb7a823ab263c11707828fe1f3e/stack-operator/pkg/controller/elasticsearch/driver/default.go#L186-L191

Should be the only one in camelcase (fixed in 0213ef9).

[barkbay]

To be honest I was not familiar with "structured logging" as it is done in the controller-runtime 😳 Much more simpler that what I have seen before.
I like the idea to have a simple rule and stick with V(0) and V(1)

My only concern would be to be able the turn on the debug level easily on a specific environment (c.f. --v Level with K8S components) without having to enable some "development" features that could compromise the security of a production environment.

FWIW it's a +1 for option 1, may be we can "extract" some ideas from https://github.com/kubernetes-sigs/controller-runtime/blob/master/TMP-LOGGING.md in a contributing guide ?

[pebrc]

I think I am also for option 1 (just use 2 levels)

The only other thing to consider maybe is that currently iirc debug level is tied to our --development mode flag.

Is it worth having the option to turn on the verbose mode in production as well when things don't go according to plan?

[pebrc]

We discussed this issue today during the status meeting. Some notes:

• We still think that the two level debug/info are enough
• We want to be able to switch the log level independently from dev mode (we are currently conflating log level and other dev specific things here e.g. port forwarding)
• We want the ability to switch format between JSON and non-structured independently from DEBUG level (V(1))

[anyasabo]

We want the ability to switch format between JSON and non-structured independently from DEBUG level (V(1))

Do we still think this is necessary? It looks like doing this through kubebuilder is a little bit more involved and I'm not sure what the use case is. I think we would end up mostly re-implementing this function but exposing the knobs we want:
https://github.com/kubernetes-sigs/controller-runtime/blob/v0.1.12/pkg/runtime/log/log.go#L43

If not I think we can close this issue as the other bullets are checked off now