Bug 1883705 - Logging is broken due to mix of k8s.io/klog v1 and v2
Summary: Logging is broken due to mix of k8s.io/klog v1 and v2
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: OpenShift Container Platform
Classification: Red Hat
Component: Cluster Version Operator
Version: 4.6
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: ---
: 4.6.0
Assignee: W. Trevor King
QA Contact: Yang Yang
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2020-09-29 23:01 UTC by W. Trevor King
Modified: 2020-10-27 16:46 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of: 1883461
Environment:
Last Closed: 2020-10-27 16:46:29 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github openshift cluster-version-operator pull 462 0 None closed Bug 1883705: *: Move to klog v2 2021-01-17 09:08:10 UTC
Red Hat Product Errata RHBA-2020:4196 0 None None None 2020-10-27 16:46:51 UTC

Description W. Trevor King 2020-09-29 23:01:04 UTC
+++ This bug was initially created as a clone of Bug #1883461 +++

k8s.io/klog moved to v2 in client-go and frieds. The operator does not use v2 yet and hence, we lose one half of the logging output (v2).

--- Additional comment from Stefan Schimanski on 2020-09-29 11:09:06 UTC ---

I did some tests using openshift-apiserver that uses kube component-base to add klog command line flags:

$ ./openshift-apiserver start --config asfd --v=4
I0929 13:04:18.354425   53628 cmd.go:57] v1 klog
I0929 13:04:18.354506   53628 cmd.go:58] v2 klog
I0929 13:04:18.354512   53628 cmd.go:61] v2 V(2) klog
I0929 13:04:18.354515   53628 cmd.go:64] v2 V(4) klog

So this means that we DO NOT set verbosity for v1 klog, and hence lose all the klogv1.V(2).Infof output.

Comment 3 Yang Yang 2020-10-10 08:13:31 UTC
Hi Trevor,

I'm trying to verify it. I'll appreciate it if you can let me know how can I test the logs from CVO side. Thanks a lot.

Comment 4 Yang Yang 2020-10-10 08:41:00 UTC
Please ignore comment #3.

I'm verifying it on 4.6.0-0.nightly-2020-10-09-153352.

# oc rsh -n openshift-cluster-version cluster-version-operator-7fc4df4694-k66rr

sh-4.4# cluster-version-operator version
ClusterVersionOperator 4.6.0-202010061132.p0-2c9d4a2

sh-4.4# cluster-version-operator image  
F1010 08:33:40.535246      45 image.go:28] missing command line argument short-name
goroutine 1 [running]:
k8s.io/klog/v2.stacks(0xc0000cc001, 0xc00051a000, 0x54, 0xa8)
	/go/src/github.com/openshift/cluster-version-operator/vendor/k8s.io/klog/v2/klog.go:996 +0xb9
k8s.io/klog/v2.(*loggingT).output(0x26b07c0, 0xc000000003, 0x0, 0x0, 0xc0000fa070, 0x25f795c, 0x8, 0x1c, 0x0)
	/go/src/github.com/openshift/cluster-version-operator/vendor/k8s.io/klog/v2/klog.go:945 +0x191
k8s.io/klog/v2.(*loggingT).printf(0x26b07c0, 0xc000000003, 0x0, 0x0, 0x1a094f5, 0x28, 0x0, 0x0, 0x0)
	/go/src/github.com/openshift/cluster-version-operator/vendor/k8s.io/klog/v2/klog.go:733 +0x17a
k8s.io/klog/v2.Fatalf(...)
	/go/src/github.com/openshift/cluster-version-operator/vendor/k8s.io/klog/v2/klog.go:1463
main.runImageCmd(0x269cf40, 0x26e2460, 0x0, 0x0)
	/go/src/github.com/openshift/cluster-version-operator/cmd/image.go:28 +0x192
github.com/spf13/cobra.(*Command).execute(0x269cf40, 0x26e2460, 0x0, 0x0, 0x269cf40, 0x26e2460)
	/go/src/github.com/openshift/cluster-version-operator/vendor/github.com/spf13/cobra/command.go:846 +0x2c2
github.com/spf13/cobra.(*Command).ExecuteC(0x269d1e0, 0x168233e, 0x269d1e0, 0xc000343f40)
	/go/src/github.com/openshift/cluster-version-operator/vendor/github.com/spf13/cobra/command.go:950 +0x375
github.com/spf13/cobra.(*Command).Execute(...)
	/go/src/github.com/openshift/cluster-version-operator/vendor/github.com/spf13/cobra/command.go:887
main.main()
	/go/src/github.com/openshift/cluster-version-operator/cmd/main.go:26 +0x53

goroutine 19 [chan receive]:
k8s.io/klog/v2.(*loggingT).flushDaemon(0x26b07c0)
	/go/src/github.com/openshift/cluster-version-operator/vendor/k8s.io/klog/v2/klog.go:1131 +0x8b
created by k8s.io/klog/v2.init.0
	/go/src/github.com/openshift/cluster-version-operator/vendor/k8s.io/klog/v2/klog.go:416 +0xd8


We can see klog/v2 in the log messages, hence moving it to verified state.

Comment 6 errata-xmlrpc 2020-10-27 16:46:29 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (OpenShift Container Platform 4.6 GA Images), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2020:4196


Note You need to log in before you can comment on or make changes to this bug.