Controller-pod log time format is not human readable

[astraw99]

What broke? What's expected?

Using the latest kubebuilder cli, quick start a new project based on the official document.
After make deploy IMG=xxx/xxx:tag, the controller-pod log time is just long numbers (1.6656692709539523e+09):

1.6656692709539523e+09  INFO    controller-runtime.metrics      Metrics server is starting to listen    {"addr": "127.0.0.1:8080"}
1.665669270954326e+09   INFO    setup   starting manager
1.6656692709546785e+09  INFO    Starting server {"path": "/metrics", "kind": "metrics", "addr": "127.0.0.1:8080"}
1.6656692709546802e+09  INFO    Starting server {"kind": "health probe", "addr": "[::]:8081"}
I1013 13:54:30.954681       1 leaderelection.go:248] attempting to acquire leader lease demo/demo-controller-manager...
I1013 13:54:30.961182       1 leaderelection.go:258] successfully acquired lease demo/demo-controller-manager
1.6656692709613848e+09  INFO    Starting EventSource    {"controller": "demo", "controllerGroup": "demo.domain.com", "controllerKind": "Demo", "source": "kind source: *v1beta1.Demo"}
1.66566927096143e+09    INFO    Starting Controller     {"controller": "demo", "controllerGroup": "demo.domain.com", "controllerKind": "Demo"}
1.6656692709612472e+09  DEBUG   events  demo-controller-manager-5fdd9c945d-6dgmr_0bba29ee-109a-4ced-add9-d773c4ff839f became leader     {"type": "Normal", "object": {"kind":"Lease","namespace":"demo","name":"demo-controller-manager","uid":"dc9449e9-d589-4c2e-a0ab-5835f4ab96a4","apiVersion":"coordination.k8s.io/v1","resourceVersion":"130007662"}, "reason": "LeaderElection"}
1.665669271061787e+09   INFO    Starting workers        {"controller": "demo", "controllerGroup": "demo.domain.com", "controllerKind": "Demo", "worker count": 1}

Should make it human readable like:

I1013 13:54:30.954681       1 leaderelection.go:248] attempting to acquire leader lease demo/demo-controller-manager...
I1013 13:54:30.961182       1 leaderelection.go:258] successfully acquired lease demo/demo-controller-manager

Reproducing this issue

Just quick start a new project based on the official document, then will reproduce this issue.

KubeBuilder (CLI) Version

Version: main.version{KubeBuilderVersion:"3.7.0", KubernetesVendor:"1.24.1", GitCommit:"3bfc84ec8767fa760d1771ce7a0cb05a9a8f6286", BuildDate:"2022-09-20T17:21:57Z", GoOs:"darwin", GoArch:"amd64"}

PROJECT version

No response

Plugin versions

No response

Other versions

No response

Extra Labels

No response

[camilamacedo86]

HI @astraw99,

Kubebuilder adopts the log provided by Controller-Runtime.
See that you can change the format or lib as please in your scaffold:

From main.go (default kubebuilder scaffold)

opts := zap.Options{
		Development: true,
	}
	opts.BindFlags(flag.CommandLine)
	flag.Parse()

Therefore, if the logs provided by the controller-runtime are not good and the best this discussion must be raised in the controller-runtime project. Also, it is required to discuss why controller-runtime did not adopt klog instead.

• Logging should be streamlined #291
• Setting Logger Does Not Propagate To Client-Go #1420 (comment)
• Unsafe assumptions and leaked goroutine in logging #1655 (comment)

Then, if/when the controller runtime changes its implementation we can change the code scaffolded by default in Kubebuilder. In this way I'd like to suggest:

• a) Open an issue in the Controller-Runtime proposing to change the default lib to klog - Done (this one)
• b) Open a PR to solve the above issue in the controller runtime (Open: https://github.com/kubernetes-sigs/controller-runtime/pull/2021/files)
• c) Raise the topic in the slack channel controller-runtime under kubernetes org
• d) Create a Pool and see if its community and maintainers agree with the change

Then, after the change is made in controller-runtime when we bump its new version on Kubebuilder the default scaffold should be changed to follow up.

So, I am moving this one to the controller-runtime project.

[alvaroaleman]

Controller-Runtime exposes an interface for the logger in which you IIRC can put klog if you so please:

controller-runtime/alias.go

Line 130 in 8ad090e

// to another logr.Logger. You *must* call SetLogger to

There is a flag for the time encoding somewhere if you use the provided zap logger.

[astraw99]

Got it, raised a new PR kubernetes-sigs/kubebuilder#3033 to set the default logger.
@camilamacedo86 @alvaroaleman PTAL thanks.