linkerd
/
linkerd2
mirror of https://github.com/linkerd/linkerd2.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Improve klog (client-go logs) handling (#11632) 

* Improve klog (client-go logs) handling

Currently log entries in the go-based controllers originated in the client-go library are only visible if the controller’s log level is `debug`. If the log level is lower (`info`, `warn`, `error`), we lose possibly important information. If the log level is `debug` we receive a lot of entries, mostly irrelevant.

client-go uses [klog](https://github.com/kubernetes/klog) for its logs, which relies on [logr](https://github.com/go-logr/logr) as its backend, which is just an interface allowing different implementations, one of which is logrus, which we use in our controllers. So in this change we bring the [logrusr](https://github.com/bombsimon/logrusr) library which implements logrus for logr.

The verbosity level for klog is also tweaked a little bit, according to k8s [logging conventions](https://github.com/kubernetes/community/blob/master/contributors/devel/sig-instrumentation/logging.md).

Also, given that logging output is now handled completely by logrus, some of the klog config flags are no longer required.

As an example of the new behavior in the proxy-injector logs, when removing the RBAC to list pods, we now see the complaints coming from client-go, which were invisible before at `info` level:

```console
time="2023-11-17T20:58:30Z" level=info msg="running version dev-94ad50cd-alpeb"
time="2023-11-17T20:58:30Z" level=info msg="starting admin server on :9995"
time="2023-11-17T20:58:30Z" level=info msg="listening at :8443"
time="2023-11-17T20:58:30Z" level=info msg="waiting for caches to sync"
time="2023-11-17T20:58:30Z" level=info msg="pkg/mod/k8s.io/client-go@v0.28.3/tools/cache/reflector.go:229: failed to list *v1.PartialObjectMetadata: pods is forbidden: User \"system:serviceaccount:linkerd:linkerd-proxy-injector\" cannot list resource \"pods\" in API group \"\" at the cluster scope"
time="2023-11-17T20:58:30Z" level=error msg="pkg/mod/k8s.io/client-go@v0.28.3/tools/cache/reflector.go:229: Failed to watch *v1.PartialObjectMetadata: failed to list *v1.PartialObjectMetadata: pods is forbidden: User \"system:serviceaccount:linkerd:linkerd-proxy-injector\" cannot list resource \"pods\" in API group \"\" at the cluster scope" error="<nil>"
time="2023-11-17T20:58:32Z" level=info msg="pkg/mod/k8s.io/client-go@v0.28.3/tools/cache/reflector.go:229: failed to list *v1.PartialObjectMetadata: pods is forbidden: User \"system:serviceaccount:linkerd:linkerd-proxy-injector\" cannot list resource \"pods\" in API group \"\" at the cluster scope"
time="2023-11-17T20:58:32Z" level=error msg="pkg/mod/k8s.io/client-go@v0.28.3/tools/cache/reflector.go:229: Failed to watch *v1.PartialObjectMetadata: failed to list *v1.PartialObjectMetadata: pods is forbidden: User \"system:serviceaccount:linkerd:linkerd-proxy-injector\" cannot list resource \"pods\" in API group \"\" at the cluster scope" error="<nil>"
time="2023-11-17T20:58:34Z" level=info msg="pkg/mod/k8s.io/client-go@v0.28.3/tools/cache/reflector.go:229: failed to list *v1.PartialObjectMetadata: pods is forbidden: User \"system:serviceaccount:linkerd:linkerd-proxy-injector\" cannot list resource \"pods\" in API group \"\" at the cluster scope"
time="2023-11-17T20:58:34Z" level=error msg="pkg/mod/k8s.io/client-go@v0.28.3/tools/cache/reflector.go:229: Failed to watch *v1.PartialObjectMetadata: failed to list *v1.PartialObjectMetadata: pods is forbidden: User \"system:serviceaccount:linkerd:linkerd-proxy-injector\" cannot list resource \"pods\" in API group \"\" at the cluster scope" error="<nil>"

time="2023-11-17T20:58:40Z" level=info msg="pkg/mod/k8s.io/client-go@v0.28.3/tools/cache/reflector.go:229: failed to list *v1.PartialObjectMetadata: pods is forbidden: User \"system:serviceaccount:linkerd:linkerd-proxy-injector\" cannot list resource \"pods\" in API group \"\" at the cluster scope"
time="2023-11-17T20:58:40Z" level=error msg="pkg/mod/k8s.io/client-go@v0.28.3/tools/cache/reflector.go:229: Failed to watch *v1.PartialObjectMetadata: failed to list *v1.PartialObjectMetadata: pods is forbidden: User \"system:serviceaccount:linkerd:linkerd-proxy-injector\" cannot list resource \"pods\" in API group \"\" at the cluster scope" error="<nil>"
time="2023-11-17T20:58:48Z" level=info msg="pkg/mod/k8s.io/client-go@v0.28.3/tools/cache/reflector.go:229: failed to list *v1.PartialObjectMetadata: pods is forbidden: User \"system:serviceaccount:linkerd:linkerd-proxy-injector\" cannot list resource \"pods\" in API group \"\" at the cluster scope"
time="2023-11-17T20:58:48Z" level=error msg="pkg/mod/k8s.io/client-go@v0.28.3/tools/cache/reflector.go:229: Failed to watch *v1.PartialObjectMetadata: failed to list *v1.PartialObjectMetadata: pods is forbidden: User \"system:serviceaccount:linkerd:linkerd-proxy-injector\" cannot list resource \"pods\" in API group \"\" at the cluster scope" error="<nil>"
time="2023-11-17T20:59:05Z" level=info msg="pkg/mod/k8s.io/client-go@v0.28.3/tools/cache/reflector.go:229: failed to list *v1.PartialObjectMetadata: pods is forbidden: User \"system:serviceaccount:linkerd:linkerd-proxy-injector\" cannot list resource \"pods\" in API group \"\" at the cluster scope"
time="2023-11-17T20:59:05Z" level=error msg="pkg/mod/k8s.io/client-go@v0.28.3/tools/cache/reflector.go:229: Failed to watch *v1.PartialObjectMetadata: failed to list *v1.PartialObjectMetadata: pods is forbidden: User \"system:serviceaccount:linkerd:linkerd-proxy-injector\" cannot list resource \"pods\" in API group \"\" at the cluster scope" error="<nil>"
time="2023-11-17T20:59:30Z" level=fatal msg="failed to sync caches"
```
This commit is contained in:
Alejandro Pedraza 2023-11-28 09:25:13 -05:00 committed by GitHub
parent e6c040381e
commit b438ec41b9
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 27 additions and 15 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
go.mod
View File

@ -54,6 +54,7 @@ require (
require (
github.com/AdaLogics/go-fuzz-headers v0.0.0-20230811130428-ced1acdcaa24
github.com/bombsimon/logrusr/v4 v4.1.0
github.com/prometheus/client_model v0.5.0
gopkg.in/yaml.v2 v2.4.0
k8s.io/utils v0.0.0-20230505201702-9f6742963106

2
go.sum
View File

@ -53,6 +53,8 @@ github.com/beorn7/perks v0.0.0-20180321164747-3a771d992973/go.mod h1:Dwedo/Wpr24
github.com/beorn7/perks v1.0.0/go.mod h1:KWe93zE9D1o94FZ5RNwFwVgaQK1VOXiVxmqh+CedLV8=
github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM=
github.com/beorn7/perks v1.0.1/go.mod h1:G2ZrVWU2WbWT9wwq4/hrbKbnv/1ERSJQ0ibhJ6rlkpw=
github.com/bombsimon/logrusr/v4 v4.1.0 h1:uZNPbwusB0eUXlO8hIUwStE6Lr5bLN6IgYgG+75kuh4=
github.com/bombsimon/logrusr/v4 v4.1.0/go.mod h1:pjfHC5e59CvjTBIU3V3sGhFWFAnsnhOR03TRc6im0l8=
github.com/briandowns/spinner v0.0.0-20190212173954-5cf08d0ac778 h1:Dmz6bJXocvwkw7BOz4jpyVZReGrkjs+fBDWKn5tBES4=
github.com/briandowns/spinner v0.0.0-20190212173954-5cf08d0ac778/go.mod h1:hw/JEQBIE+c/BLI4aKM8UU8v+ZqrD3h7HC27kKt8JQU=
github.com/bshuster-repo/logrus-logstash-hook v1.0.0 h1:e+C0SB5R1pu//O4MQ3f9cFuPGoOVeF2fE4Og9otCc70=

39
pkg/flags/flags.go
View File

@ -6,6 +6,8 @@ import (
"os"
"github.com/linkerd/linkerd2/pkg/version"
"github.com/bombsimon/logrusr/v4"
log "github.com/sirupsen/logrus"
"github.com/spf13/pflag"
"helm.sh/helm/v3/pkg/cli/values"
@ -28,11 +30,6 @@ const (
// func calls flag.Parse(), so it should be called after all other flags have
// been configured.
func ConfigureAndParse(cmd *flag.FlagSet, args []string) {
klog.InitFlags(nil)
flag.Set("stderrthreshold", "FATAL")
flag.Set("logtostderr", "false")
flag.Set("log_file", "/dev/null")
flag.Set("v", "0")
logLevel := cmd.String("log-level", log.InfoLevel.String(),
"log level, must be one of: panic, fatal, error, warn, info, debug, trace")
logFormat := cmd.String("log-format", "plain",
@ -44,9 +41,11 @@ func ConfigureAndParse(cmd *flag.FlagSet, args []string) {
//nolint:errcheck
cmd.Parse(args)
// set log timestamps
log.SetFormatter(getFormatter(*logFormat))
klog.InitFlags(nil)
klog.SetLogger(logrusr.New(log.StandardLogger()))
setLogLevel(*logLevel)
maybePrintVersionAndExit(*printVersion)
}
@ -66,16 +65,26 @@ func setLogLevel(logLevel string) {
}
log.SetLevel(level)
if level >= log.DebugLevel {
flag.Set("stderrthreshold", "INFO")
flag.Set("logtostderr", "true")
// Loosely based on k8s logging conventions, except for 'tracing' that we
// bump to 10 (we can see in client-go source code that level is actually
// used) and `debug` to 6 (given that at level 7 and higher auth tokens get
// logged)
// https://github.com/kubernetes/community/blob/master/contributors/devel/sig-instrumentation/logging.md
switch level {
case log.PanicLevel:
flag.Set("v", "0")
case log.FatalLevel:
flag.Set("v", "0")
case log.ErrorLevel:
flag.Set("v", "0")
case log.WarnLevel:
flag.Set("v", "0")
case log.InfoLevel:
flag.Set("v", "2")
case log.DebugLevel:
flag.Set("v", "6")
// pipe klog entries to logrus
klog.SetOutput(log.StandardLogger().Writer())
}
if level >= log.TraceLevel {
flag.Set("v", "12") // At 7 and higher, authorization tokens get logged.
case log.TraceLevel:
flag.Set("v", "10")
}
}